Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

version 181008: mlr crashes, then hardlocks system #603

Closed
nightmorph opened this issue Oct 15, 2018 · 76 comments
Closed

version 181008: mlr crashes, then hardlocks system #603

nightmorph opened this issue Oct 15, 2018 · 76 comments
Labels

Comments

@nightmorph
Copy link

@nightmorph nightmorph commented Oct 15, 2018

norns OS version 181008 (updated from 180707. this bug is not present in 180707.)

the latest version of mlr keeps crashing during normal play, repeatedly taking down the entire norns OS with it. sometimes it's just a "soft" crash, in which the screen and controls are still responsive, so system->reset audio might fix it. in that case, another crash will result very shortly after reloading mlr, reloading samples, and beginning to play.

but most of the time, mlr crashes so hard that it completely locks up norns; it's no longer possible to reset the audio engine or use any of the onscreen menus/controls. only the bottom reset button reboots into a working system.

steps to reproduce:

  1. startup norns, launch mlr
  2. select sample page, load 2 samples into mlr. format: .wav, 48khz, 32bit. sample1 length: 18sec, sample2 length: 13sec.
  3. assign sample1 (18sec) to clip 1, sample1 to clip 2, sample2 (13sec) to clip 3, sample2 to clip 4.
    • these are doubled using unique slots for each, as the second copy will be playing at different speeds and directions. can't reuse the original clip slot, because re-selecting sample1 using clip 2's sample1 slot...results in the famous buffer-overrun bug, in which one clip/row's playback glitches and starts incorporating samples from other clips/rows. that's it's own bug...
  4. let clip/row 1 and 3 each play their sample forward, at normal speeds. set clip/row 2 and 4 to reverse, at different speeds like 2x.
  5. switch to the cut/play page, and begin playback anywhere. let all rows play; no need to press anymore grid keys.
  6. after 1-2 minutes of playback, mlr will crash and hardlock the norns OS in one of two ways:
    • complete crash, grid and screen frozen and unresponsive
    • complete crash, grid and screen frozen, with frozen audio repeating forever the last .wav cycle that was playing. i.e. an unpleasant buzz/tone at a constant pitch.
  • note that the audio plays correctly right up until the crash.
@tehn
Copy link
Member

@tehn tehn commented Oct 15, 2018

thanks for the detailed report, i'll get to work on it

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

updated from 170707

i assume you mean 180707?

on DSP side, changes are minimal but do affect wrapping logic for negative rates (removed some branches.) sounds like this is specifically affecting negative rates so i'll look there. odd because minimal script using softcut and reversed playback doesn't have any problems for me.

since we've switched to supernova i need to do a full rewrite incorporating the resampling anyways. sorry it's been slow, day job is too intense to even play with norns let alone work on it.

famous buffer-overrun bug

OT, but this "bug" was never clearly communicated to me. the forum discussion is a muddle. i explained elsewhere that the voice regions really should have some pre-roll and post-roll (not start at zero, and not be totally jammed up against each other) if you don't want to hear unexpected things during the crossfades. but as you say that's another issue.

@tehn
Copy link
Member

@tehn tehn commented Oct 15, 2018

famous buffer-overrun bug

voice regions have pre-roll, but i need to fix buffer loading to make sure adjacent "clips" don't get wiped out. easy fix i think.

i'm generally unsure how a bug crept in re: crashing but i'll investigate

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

i assume you mean 180707?

correct; i typed a few too many 7s. edited original report.

on DSP side, changes are minimal but do affect wrapping logic for negative rates (removed some branches.) sounds like this is specifically affecting negative rates so i'll look there. odd because minimal script using softcut and reversed playback doesn't have any problems for me.

mentioning reverse playback got me thinking, so i did some more thorough testing just now.

the same hardlock occurs at <2min of letting it just play even without setting any clips to reverse.

to reproduce: set 2 clips to play forward normal speeds, and the other 2 clips to play forward at 2x (or 4x). mlr still locks up and stops playing audio after less than 2 minutes of hands-off playback.

curiously, the screen and controls of norns itself are working, and the grid itself partially works. that is, the mode/page-select buttons work, though the status/progress lights on each grid page are frozen as they were the moment the audio died. i can even press buttons in the rec and clip pages with the expected led activity, but they don't have any affect on the audio. loading a new sample into a clip doesn't make the cut/play page respond at all.

since i can still access the norns menu, i was able to perform an audio system restart and reload the samples, though again that resulted in the same hardlock, after just 1 minute of all four clips playing. as before, each sample played at 1x and 2x forward. also as before, the norns menu and grid rec/clip pages are accessible, but inoperative.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

ok, many thanks for checking that!

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

also, i made sure to ssh into norns before re-running my tests, and discovered the following messages filling up /var/log/syslog:

$ tail -n 50 /var/log/syslog
[...]
Oct 16 02:04:32 norns jackd[313]: JackEngine::XRun: client = supernova was not finished, state = Triggered
Oct 16 02:04:32 norns jackd[313]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
Oct 16 02:04:32 norns jackd[313]: JackEngine::XRun: client = supernova was not finished, state = Triggered
Oct 16 02:04:32 norns jackd[313]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
[...]

there are dozens of these lines prior to/at the time the audio cutout, when mlr froze after 1 minute of untouched playback. again, the norns on-device controls work, the grid pages have limited response, and the system is still responsive over ssh. but mlr doesn't work; only restarting the system audio or rebooting norns lets me back in...until mlr crashes after 1 minute. i'm afraid that this is a complete blocker of a bug, as i can't find any way of stabilizing mlr long enough to get anything done.

are there any other logfiles/messages i should examine, as long as i'm logged-in?

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

since you asked, it would be very helpful for me to see the supercollider output. i think that maiden shows this if you select the appropriate REPL tab? (apologies that i can't actually remember this right now.)

if not, you can get it on the terminal:

  • stop everything: cd ~/norns && ./stop.sh
  • start sclang (from anywhere): sclang
  • open a second ssh session and start matron: cd ~/norns && ./build/matron/matron

the first session should be showing SC output.

NB: maiden won't work b/c we're bypassing the websocket wrappers. you still have a primitive lua REPL in the session running the matron process.

(i'm not on a norns right now so apologies if i made any errors there but hopefully the idea is clear)

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

oh and if you're feeling really ambitious you could go into ~/norns/sc/core/CroneEngine.sc and uncomment this line:

https://github.com/monome/norns/blob/master/sc/core/CroneEngine.sc#L71

then restart sclang (or system->reset audio).

then we'll see all the commands mlr is actually sending to the engine.

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

thanks, i got it working within REPL as expected. here's the output with CroneEngine uncommented.

(i can make my samples available via dropbox if necessary; they're 32bit 48khz .wav...i'm wondering if their format is what's breaking mlr. it looks like it thinks they're 16bit, as seen in the first debug line.)

order of operation was: load mlr, select clip page, load samples into clips 1-4 sequentially, switch to rec page, toggle 2x speed on clips 2 & 4, switch to cut/play page, press a single button in each row, let loop. mlr crashed and hardlocked in less than 20sec.

SC tab output:

[...]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/main melody.wav, 2.0, 16.0 ], 62.678412695, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 1 ], 62.681220093, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 1, 2.0 ], 62.683826497, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 1, 19.9594375 ], 62.686580769, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 1, 1.12246484375 ], 62.689191548, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 1, 0.2449296875 ], 62.691920195, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 1, 1.0 ], 62.694516442, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 
768000.0
 frames at 
96000.0
[ CroneEngine rx command, [ /command/stop, 2 ], 65.088556647, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 65.089170617, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 36.0 ], 65.091662174, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 0.25 ], 65.094166805, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.0 ], 65.096860867, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 2 ], 65.168558266, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 65.169158069, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 36.0 ], 65.171552125, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 0.25 ], 65.173994984, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.0 ], 65.174610673, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/main melody.wav, 32.0, 16.0 ], 71.689110258, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 2 ], 71.69189036, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 71.694387019, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 49.9594375 ], 71.698703763, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 1.12246484375 ], 71.702690345, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.55148046874999 ], 71.707811895, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 2, 1.0 ], 71.710600018, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 
768000.0
 frames at 
1536000.0
Jack: xrun detected - resyncing clock
[ CroneEngine rx command, [ /command/stop, 3 ], 72.873195503, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 3, 62.0 ], 72.875785445, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 3, 66.0 ], 72.878304708, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 3, 0.25 ], 72.881118821, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 3, 0.0 ], 72.88352928, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/low melody.wav, 62.0, 16.0 ], 76.009175914, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 3 ], 76.011934086, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 3, 62.0 ], 76.014461422, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 3, 75.111979166667 ], 76.017315169, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 3, 0.81949869791667 ], 76.020074696, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 3, 0.2819010416666 ], 76.022793649, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 3, 1.0 ], 76.03010013, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 
768000.0
 frames at 
2976000.0
[ CroneEngine rx command, [ /command/stop, 4 ], 76.63019863, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 76.631916837, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 96.0 ], 76.633452592, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.25 ], 76.636065449, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 4, 0.0 ], 76.638645233, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/low melody.wav, 92.0, 16.0 ], 79.569353801, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 4 ], 79.572171922, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 79.574729777, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 105.11197916667 ], 79.609050039, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.81949869791667 ], 79.611668364, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 4, 0.60335286458343 ], 79.614282679, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 1.0 ], 79.617199342, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 
768000.0
 frames at 
4416000.0
[ CroneEngine rx command, [ /command/rate, 2, 2.0 ], 83.089060224, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 2.0 ], 83.55317348, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 1, 3.12246484375 ], 135.017875799, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 1 ], 135.020554421, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 1 ], 135.021179584, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 1, 3.12246484375 ], 135.031358962, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 1 ], 135.034070918, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 1, 5.36739453125 ], 135.225828984, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 1 ], 135.22846745, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 2, 36.489859375 ], 135.671832435, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 2 ], 135.67446814, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 2 ], 135.676937384, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 3, 66.097493489583 ], 136.039669933, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 3 ], 136.042524233, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 3 ], 136.045141448, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 4, 96.097493489583 ], 137.335751717, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 4 ], 137.340620309, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 4 ], 137.343270857, a NetAddr(127.0.0.1, 8888), 57120 ]
Server 'localhost' exited with exit code 0.
server 'localhost' disconnected shared memory interface
ERROR: Server-getControlBusValue only supports local servers
CALL STACK:
	Exception:reportError
		arg this = <instance of Error>
	Nil:handleError
		arg this = nil
		arg error = <instance of Error>
	Thread:handleError
		arg this = <instance of Thread>
		arg error = <instance of Error>
	Thread:handleError
		arg this = <instance of Routine>
		arg error = <instance of Error>
	Object:throw
		arg this = <instance of Error>
	Server:getControlBusValue
		arg this = <instance of Server>
		arg busIndex = 0
	CroneAudioContext:buildVuBlob
		arg this = <instance of CroneAudioContext>
		var ret = <instance of Int8Array>
	< FunctionDef in Method Meta_Crone:initVu >  (no arguments or variables)
	Float:do
		arg this = inf
		arg function = <instance of Function>
		var i = 2719.0
	Routine:prStart
		arg this = <instance of Routine>
		arg inval = 4.966425932
^^ The preceding error dump is for ERROR: Server-getControlBusValue only supports local servers
@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

ok thanks, that's extremely helpful.

so, the actual error message ERROR: Server-getControlBusValue only supports local servers just means, in this context, that supernova crashed.

nothing is showing up as a smoking gun exactly.

but, i'm suspecting something to do with loading samples now.

buffer frames allocated is higher than i expected - almost 12 minutes. this is some stupid error on my part, incorrectly predicting the next power of two after applying hardware samplerate.)

just as a sanity check, we could try reducing the buffer duration here:

https://github.com/monome/dust/blob/master/lib/sc/Engine_SoftCut.sc#L3-L4

changing it to 300 (seconds) should give a frame count of 16777216, instead of 33554432.

(or lower - seems like mlr.lua assumes a much smaller range anyways.)

i suppose you could also try reducing the voice count back to 4: in the engine at line 3, and also in the mlr script - i think it's sufficient to change the value of TRACKS here: https://github.com/monome/dust/blob/master/scripts/tehn/mlr.lua#L31
but @tehn may have to correct me.

besides that and the phase-wrapping method, the main difference from 180707 release (a really big one) is the switch to supernova.


thanks again and i'll check this out myself shortly - blocking some dedicated time for norns development this week.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

[continuing]

i'm not sure why the higher frame count would be a problem - it's ~134 MB and i thought we had plenty of RAM to spare.

but loading a sample actually allocates a temp buffer on top of that, so i dunno. it's worth checking top at least.

(surprised that supernova wouldn't give us a warning if it failed to reserve enough RAM, but checking it now on x86, appear to be able to request absurd buffer sizes on the sclang client without a peep from the server....)

@tehn
Copy link
Member

@tehn tehn commented Oct 15, 2018

i suppose you could also try reducing the voice count back to 4: in the engine at line 3, and also in the mlr script - i think it's sufficient to change the value of TRACKS here: https://github.com/monome/dust/blob/master/scripts/tehn/mlr.lua#L31
but @tehn may have to correct me.

that is correct.

order of operation was: load mlr, select clip page, load samples into clips 1-4 sequentially, switch to rec page, toggle 2x speed on clips 2 & 4, switch to cut/play page, press a single button in each row, let loop. mlr crashed and hardlocked in less than 20sec.

i did exactly this, using my short whirl samples that are bundled in dust. 4 minutes running fine but i'll update as i see.

only difference is our files? oh, my wifi is off. i'll turn it on and good poke around with it still running

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

only difference is our files?

current hypothesis is file length could be significant...

@tehn
Copy link
Member

@tehn tehn commented Oct 15, 2018

FYI i intend to reduce the voice count of mlr to 4, but expand the "rows" and implement mute groups (as in mlrv). partially because i'd like there to be more overhead in softcut for interp recording, and also the possibility of other processing (ie if/when we make swappable aux/insert effects)

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

just as a sanity check, we could try reducing the buffer duration here:

https://github.com/monome/dust/blob/master/lib/sc/Engine_SoftCut.sc#L3-L4

changing it to 300 (seconds) should give a frame count of 16777216, instead of 33554432.

i suppose you could also try reducing the voice count back to 4: in the engine at line 3, and also in the mlr script - i think it's sufficient to change the value of TRACKS here: https://github.com/monome/dust/blob/master/scripts/tehn/mlr.lua#L31

i made these changes and re-ran the test. no joy. it hardlocked within 15sec, this time with the unpleasant buzzy audio cycling, and the norns and grid UIs are completely frozen. have to use the bottom-button-reset trick.

(again, lemme know if you want me to send my samples to you for further analysis/reproduction.)

SC output in REPL is also dead; the device locked so hard, it didn't write error messages. this is the last bit when starting play:

[ CroneEngine rx command, [ /command/fade_rec, 3, 0.1 ], 164.784605127, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/fade, 3, 0.01 ], 164.787012639, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/env_time, 3, 0.1 ], 164.787485537, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate_lag, 3, 0.0 ], 164.789876852, a NetAddr(127.0.0.1, 8888), 57120 ]
starting poll...
[ CroneEngine rx command, [ /command/rec_on, 4, 1.0 ], 164.792371183, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pre, 4, 1.0 ], 164.792802468, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pre_lag, 4, 0.05 ], 164.7956759, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/fade_pre, 4, 0.01 ], 164.797927011, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/amp, 4, 1.0 ], 164.80041379, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rec, 4, 0.0 ], 164.802988431, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rec_lag, 4, 0.05 ], 164.803706789, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/fade_rec, 4, 0.01 ], 164.806039512, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/adc_rec, 1, 4, 0.8 ], 164.808517958, a NetAddr(127.0.0.1, 8888), 57120 ]
[ PatchMatrix: level_ , 0, 3, 0.8 ]
[ CroneEngine rx command, [ /command/adc_rec, 2, 4, 0.8 ], 164.811163169, a NetAddr(127.0.0.1, 8888), 57120 ]
[ PatchMatrix: level_ , 1, 3, 0.8 ]
[ CroneEngine rx command, [ /command/play_dac, 4, 1, 1.0 ], 164.813912803, a NetAddr(127.0.0.1, 8888), 57120 ]
[ PatchMatrix: level_ , 3, 0, 1.0 ]
[ CroneEngine rx command, [ /command/play_dac, 4, 2, 1.0 ], 164.81676061, a NetAddr(127.0.0.1, 8888), 57120 ]
[ PatchMatrix: level_ , 3, 1, 1.0 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 164.819406862, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 96.0 ], 164.822005773, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_on, 4, 1.0 ], 164.824438752, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.25 ], 164.825022011, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/fade_rec, 4, 0.1 ], 164.827246613, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/fade, 4, 0.01 ], 164.828762701, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/env_time, 4, 0.1 ], 164.830111815, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate_lag, 4, 0.0 ], 164.83254792, a NetAddr(127.0.0.1, 8888), 57120 ]
starting poll...
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/main melody.wav, 2.0, 16.0 ], 180.725511594, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 1 ], 180.738686862, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 1, 2.0 ], 180.74115339, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 1, 19.9594375 ], 180.74371955, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 1, 1.12246484375 ], 180.744425879, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 1, 0.2449296875 ], 180.746783609, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 1, 1.0 ], 180.749193264, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 768000.0 frames at 96000.0
[ CroneEngine rx command, [ /command/stop, 2 ], 181.922220516, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 181.922880857, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 36.0 ], 181.925295669, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 0.25 ], 181.927885839, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.0 ], 181.930222112, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/main melody.wav, 32.0, 16.0 ], 185.365557011, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 2 ], 185.368030415, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 185.370238308, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 49.9594375 ], 185.370869067, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 1.12246484375 ], 185.373697564, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.55148046874999 ], 185.376167947, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 2, 1.0 ], 185.378563542, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 768000.0 frames at 1536000.0
[ CroneEngine rx command, [ /command/stop, 3 ], 186.445435231, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 3, 62.0 ], 186.447842753, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 3, 66.0 ], 186.450056062, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 3, 0.25 ], 186.452842998, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 3, 0.0 ], 186.453430061, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/low melody.wav, 62.0, 16.0 ], 190.635155722, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 3 ], 190.653791695, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 3, 62.0 ], 190.656550249, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 3, 75.111979166667 ], 190.658937235, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 3, 0.81949869791667 ], 190.661660679, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 3, 0.2819010416666 ], 190.664363652, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 3, 1.0 ], 190.667101943, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 768000.0 frames at 2976000.0
[ CroneEngine rx command, [ /command/stop, 4 ], 191.578768446, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 191.579329417, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 96.0 ], 191.581617163, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.25 ], 191.582190897, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 4, 0.0 ], 191.584464422, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/low melody.wav, 92.0, 16.0 ], 195.875962, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 4 ], 195.878473089, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 195.881032674, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 105.11197916667 ], 195.883740145, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.81949869791667 ], 195.886517053, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 4, 0.60335286458343 ], 195.889327976, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 1.0 ], 195.892034405, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
33554432.0
copying 768000.0 frames at 4416000.0
[ CroneEngine rx command, [ /command/rate, 2, 2.0 ], 204.177937622, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 2.0 ], 204.466159706, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 1, 6.489859375 ], 238.269121234, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 1 ], 238.269705754, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 1 ], 238.271897261, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 2, 37.61232421875 ], 238.429615409, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 2 ], 238.431985887, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 2 ], 238.432524779, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 3, 66.9169921875 ], 238.619410649, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 3 ], 238.621763623, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 3 ], 238.624023518, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 4, 97.736490885417 ], 238.797490054, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 4 ], 238.79808572, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 4 ], 238.800397962, a NetAddr(127.0.0.1, 8888), 57120 ]
@tehn
Copy link
Member

@tehn tehn commented Oct 15, 2018

ok. loaded hermit_leaves from the dust repo which is a pretty long sample.

something isn't working where the full file didn't get loaded, and then when playing further into the non-loaded area it devolved to digital noise explosion. didn't crash the engine. was able to reload mlr. and then ran easygrain to check that the file was indeed fine and not blank (true)

will get some actual debug output now

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

ok then we're probably onto something there. at minimum BufUtil needs to do its own sanity check. i'll check this out and PR tonight (for that aspect of things at least - ugen update will be along later)

@nightmorph reported buffer frame size is unchanged - are you sure the edit got saved or whatever?

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

i verified in maiden that the files were correctly updated (as i'd edited them via ssh) before restarting the audio engine and mlr, but will check again now.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

just to be clear, any time you edit any .sc files you need to restart the sclang process (/ recompile SC class lib,) one way or another, for the changes to take. (reboot, system->reset audio, restart crone systemd service, or stop and run sclang directly.)

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

verified, reloaded, and (ouch). i think i just got the same horrible digital noise-explosion that @tehn did after several seconds of untouched playback. engine also didn't seem to crash, was also able to reload mlr.

is there a chance that the script needs more time to fully read the file from disk into ram? i've encountered that issue in the er301, in which i need to give long samples time to load from the microSD card into memory. there's no visual indicator there (or in norns) of how far along the operation is, so longer files might be getting truncated, or something.

here's the SC output from REPL:

starting poll...
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/main melody.wav, 2.0, 16.0 ], 107.358651367, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 1 ], 107.371676779, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 1, 2.0 ], 107.373924139, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 1, 19.9594375 ], 107.374681717, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 1, 1.12246484375 ], 107.376821685, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 1, 0.2449296875 ], 107.377292365, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 1, 1.0 ], 107.379566716, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 16777216.0
copying 768000.0 frames at 96000.0
[ CroneEngine rx command, [ /command/stop, 2 ], 112.224085383, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 112.224704169, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 36.0 ], 112.227341718, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 0.25 ], 112.232052272, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.0 ], 112.234558989, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/main melody.wav, 32.0, 16.0 ], 117.967848356, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 2 ], 117.970268523, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 2, 32.0 ], 117.970772604, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 2, 49.9594375 ], 117.973148015, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 2, 1.12246484375 ], 117.973844196, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 2, 0.55148046874999 ], 117.976341316, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 2, 1.0 ], 117.978503684, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
16777216.0
copying 768000.0 frames at 1536000.0
[ CroneEngine rx command, [ /command/stop, 3 ], 119.164807136, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 3, 62.0 ], 119.165384672, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 3, 66.0 ], 119.165813356, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 3, 0.25 ], 119.168045191, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 3, 0.0 ], 119.168433966, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/low melody.wav, 62.0, 16.0 ], 124.177871476, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 3 ], 124.180483134, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 3, 62.0 ], 124.180844282, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 3, 75.111979166667 ], 124.182987624, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 3, 0.81949869791667 ], 124.183873511, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 3, 0.2819010416666 ], 124.186047904, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 3, 1.0 ], 124.188332798, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
16777216.0
copying 768000.0 frames at 2976000.0
[ CroneEngine rx command, [ /command/stop, 4 ], 125.097829092, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 125.098288445, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 96.0 ], 125.100498619, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.25 ], 125.100936298, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 4, 0.0 ], 125.102889418, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/read, /home/we/dust/audio/low melody.wav, 92.0, 16.0 ], 129.25694582, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 4 ], 129.25929243, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 4, 92.0 ], 129.259682429, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 4, 105.11197916667 ], 129.261953342, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant, 4, 0.81949869791667 ], 129.26361649, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/quant_offset, 4, 0.60335286458343 ], 129.266779514, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 1.0 ], 129.267437605, a NetAddr(127.0.0.1, 8888), 57120 ]
frames in dst buffer: 
16777216.0
copying 768000.0 frames at 4416000.0
[ CroneEngine rx command, [ /command/rate, 2, 2.0 ], 134.404109444, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 2.0 ], 134.628165338, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 1, 5.36739453125 ], 168.159347896, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 1 ], 168.159904951, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 1 ], 168.160300213, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 1, 5.36739453125 ], 168.351597335, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 1, 7.61232421875 ], 168.352175486, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 2, 37.61232421875 ], 168.527934353, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 2 ], 168.528410459, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 2 ], 168.530468864, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_start, 1, 2.0 ], 168.59211062, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/loop_end, 1, 19.9594375 ], 168.594349361, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 1, 6.489859375 ], 168.594946317, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 1 ], 168.596951538, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 3, 66.9169921875 ], 168.864179752, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 3 ], 168.86641641, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 3 ], 168.866924187, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/pos, 4, 96.9169921875 ], 169.405876392, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/reset, 4 ], 169.408203162, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/start, 4 ], 169.408596809, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 1 ], 211.969974632, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 2 ], 212.210130197, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 3 ], 212.43412134, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/stop, 4 ], 212.610066192, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 2, 1.0 ], 216.863875466, a NetAddr(127.0.0.1, 8888), 57120 ]
[ CroneEngine rx command, [ /command/rate, 4, 1.0 ], 217.119887744, a NetAddr(127.0.0.1, 8888), 57120 ]
@catfact
Copy link
Collaborator

@catfact catfact commented Oct 15, 2018

ok thanks. i'll have to dig into this and probably fix up BufUtil and the sample loading commands.

seems to be some subtly different behavior in supernova and maybe less graceful bad-argument / concurrency handling for buffer stuff (no too surprising since it has a totally different threading model.) don't think this will be too hard and should have something to share late tonight.

apologies for the difficulties.

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 15, 2018

further testing note: while i reported earlier that i had a similar experience as @tehn in being able to reload mlr without the engine crash at the time...after letting it sit unattended for several minutes, without loading any samples, mlr in a blank state, i found that norns had still hardlocked itself. completely unresponsive, and nothing in REPL SC.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 16, 2018

ok thanks.

made a stripped-down test of playback with multiple voices, reading same region, changing rates, using hermit_leaves:

https://github.com/catfact/dust-1/blob/softcut-sample-playback-testing/scripts/emb/softcut-playback-test.lua

experience so far:

  • before adding phase polls and redraw, i ran this for a long time (~30m) and seemed solid.

  • after adding that stuff, i got a crash almost immediately. (SC process dead, &c) but one thing is that i was printing tons of stuff to the terminal in multiple ssh sessions.

  • disabled phase poll and screen stuff

  • went into the engine, double checked how quantized phase works (supernova/sclang update the quantized phase state regardless, but nothing gets sent unless phase_quant poll is enabled)

  • then re-added (cleaning up my lua a little.) but haven't been able to reproduce crash again. (running for another ~30m so far.) will keep trying this.

would be great to see what we can add from a minimal starting place that reproduces. or whether engine/buffer stuff is a total red herring and it's all about OSC and other network traffic density.

@tehn alternatively, could try disabling some polls in mlr.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 16, 2018

(oh, will also try more agressively triggering negative loop points, and maybe quick fix the negative wrap logic in ugen.)

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 16, 2018

left the house and came back - audio still running, but UI is frozen and matron process is gone.

in this case though, i see the problem - i was running matron from an ssh session, and the session timed out, and it killed the child process.

somehow the session running sclang wasn't afffected - sclang uses some kind of virtual terminal which may be the reason.

anyway something to watch out for i guess...

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 16, 2018

anything i can help test on my end at this point? is the lua script something i can run directly on my norns, after changing the hardcoded filepath to point at one of my samples?

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 17, 2018

sure, what i'm trying to do is build on that minimal example until it crashes reproduceably (in fact the rate change is probably not useful and just makes it less boring to listen to!)... not there yet and indeed i don't know at this point that the issue doesn't arise from mlr's greater complexity in general (if it is somehow correlated with network traffic)

also, does this ever happen with wifi off?

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 17, 2018

also, does this ever happen with wifi off?

yes; all the crashes first occurred while wifi was off, and the adapter not even plugged-in. that was what prompted me to file the initial report. i only turned on wifi so i could ssh in and poke at the logfiles.

interestingly, on the harder crashes, in which the audio unpleasantly & noisily locks up, the ssh session also freezes. i can't interact with the OS at all. note that i've only ever run a single ssh terminal at a time, so norns isn't under heavy multi-term network load.

@tehn
Copy link
Member

@tehn tehn commented Oct 17, 2018

alternatively, could try disabling some polls in mlr.

i will see if i get the glitch explosion with polls disabled

@tehn
Copy link
Member

@tehn tehn commented Oct 17, 2018

well, it's not a very good data point, but:

  • ran 4 tracks of hermit_leaves with polls/etc (normal) and got a supernova crash (not hard lockup, no super-noise) after 30 minutes. was able to reboot audio in-menu. wifi not on.
  • been running with polls disabled for an hour with no problems so far. (wifi on, even)
@catfact
Copy link
Collaborator

@catfact catfact commented Oct 21, 2018

report on forum of lockups using loom.lua, no wifi, latest update
this is a different engine that doesn't use any custom ugens
https://llllllll.co/t/norns-help/14016/648?u=zebra

curious to see if there are other reports.
clearly, not everyone is having the norns lock up after 5 minutes of use. (for example the developers of these patches.)

in any case, i'm currently applying the 181008 update. it looks like the update script should overwrite all my custom stuff and give me something like what users have. will report.

still, it would be nice to have a full disk image. given that i can just flash the whole filesystem on the white proto, which isn't a big deal, and see what happens.

re: current / cm3 power supply, i would think that if there were RAM problems due to this, they would show up in the memtest. however another symptom of undercurrent is that the emmc would be intermittent, causing all kinds of mysterious issues which could definitely include kernel panic. i have to consider the strong possiblity of a hardware issue, since so far the lockups seem so much more prevalent on some units than others, and the big-picure change since june is that we are using the hardware more fully across the board (engaging all cores, &c.)

@nightmorph the listing of SC extensions shows that those files were created in july. that's weird, i'd think the update scripts should be overwriting them. i'll have a better idea after trying the update scripts here.

in next update one thing i would like us to add is better logging for supernova process. i'll see what i can do.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 22, 2018

i applied the 181008 updates. this worked as far as i can tell. some interesting wrinkles:

  • i simply could not get the update to work form the menu with a usb stick (tried a few of them.) didn't spend too much time investigating and just copied the update to norns FS and ran the script directly.

  • the first couple times i tried this, it gave up halfway through because i didn't have enough space (somwhere in the midst of dpkg, then in the midst of copying .so's.) had to delete some tape output and some of my dev stuff (temporarily.) i don't know if i would have realized this if attempting the update through the menu.

  • @nightmorph from your listing of the SC extensions dir, it kinda looks like the update didn't actually finish for you either. the .so files should have creation dates from october, not july.

anyways. i'm pretty confident i now have the same binaries and stuff as anyone who successfully ran the 181008 update. (supernova, sclang, sc3 plugins, matron, maiden, ugens, kernel overlays, boot modules.)

and the end result is that MLR is happily running so far (same setup as before.) but i will update after a few hours.

TL/DR (@tehn)
new hypothesis: maybe we are seeing the result of incomplete updates / disk full. that would have unpredictable consequences including random crashes.

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 22, 2018

MLR ran fine for an hour or so. (good thing the samples are pretty!)

following up on forum reports, i tried running loom and got a sudden shutdown (not a freeze) after several minutes.

since this was a shutdown, i suspected a power thing. the first time it happened was on battery. then i plugged into a laptop usb port (macbook adapter + hub, actually) and got it a couple more times.

i hooked up norns to mains power and tried again: result was audio/supernova death after several minutes, but grid and matron keep running.

then i attached a current meter to the USB running between norns and grid. the grid current draw is peaking at 0.4 amps. (loom is an extremely bright and active script.) when i run MLR the USB current draw never exceeds 0.1A. this seems potentially significant.

i think i'm using the standard norns power supply; anyways it's a 2A guy. (my "official" RPI3 power supplies are 2.5A, but have a hardwired micro-USB plug.)
i'm not sure about the current rating of the cable i'm using for power, but it isn't heating noticeably.
i'm using a latest edition grid 128.


last test: running loom with the grid unplugged. (TBH i'm not sure what the heck the grid is doing anyway.) so far so good.


oh, last data point: i was able to immediately trigger a hard shutdown on battery by running cd / && du -chs in a ssh session, with loom running. this is a command to check disk usage and like memtester is pretty power-intensive. (worked fine without the script running.)

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 22, 2018

per something that @catfact mentioned, it does indeed seem like the symlinked shared objects didn't get updated when migrating to 181008. (unless the date is wrong because the hwclock failed to keep itself synced when connecting to wifi.)

is there a logfile for the update script, to see if something was silently failing? is there a set of manual steps i can run to make sure i get the updated libraries, and then re-test? also, do i need to undo/reset any of the various single-line script/lib changes i made in the earlier tests? to mlr, dust/sc, etc.

as far as i know, tape/ is empty, so it's not a lack of space preventing a proper update. i only have 3-4 samples from a different project in dust/ -- there are no other samples or userscripts beyond what's installed by default.

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

image still uploading (stalled overnight, cursed rural internet)

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

i'm completely perplexed how some objects wouldn't have been updated.

the update script: https://github.com/monome/norns/blob/master/update.sh_template

norns is totally erased, and replaced with a pre-compiled (tested) folder. and then install.sh is run which should re-symlink.

dust is different. it overwrites any files present (ie, microchanges to mlr/etc will be overwritten) but not-updated existing files will stay (ie, tape recordings).

there is no logfile, it's just a script. we're working on completely overhauling the update method as it is too fragile.


re: incomplete updates. this is a strong suspect.


re: power. yes, this is disconcerting. it's just that i can't explain differences between people's hardware. one thing i am concerned about is battery quality-- i've seen a couple of them go bad. i'm wondering if random batteries just can't output current to spec.

re @nightmorph, i'd be curious to first have you test a fresh image flash, and if that fails, replace the battery. if the image flash fails i'd be happy to look at your hardware myself and save you the trouble. i'm sorry for all of this.

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

also re power adapter. i chose a 5.25V at 2A which is close to 5V @ 2.5A in terms of wattage, but the higher voltage allows for voltage drop over the usb cable with high current (i also chose a high quality high-gauge usb cable, for lower drop)... this part of the design stage was very intense last year.

but in reality we shouldn't even be getting close to the limits of power draw. i also regularly monitor USB power draw and haven't seen anything too crazy.

@markwheeler
Copy link
Collaborator

@markwheeler markwheeler commented Oct 22, 2018

following up on forum reports, i tried running loom and got a sudden shutdown (not a freeze) after several minutes.

I'd be curious to hear exactly what steps you're taking when seeing the loom issues - I've been testing here and unable to reproduce so far. Perhaps we can open a new issue if it's reproducible and I can investigate.

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

current disk image uploaded: https://monome.nyc3.digitaloceanspaces.com/norns181008.img.zip

@nightmorph did you per chance try changing the number of softcut voices and reducing the mlr tracks? i know ezra suggested it but i may have missed the results in the thread here

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 22, 2018

current disk image uploaded: https://monome.nyc3.digitaloceanspaces.com/norns181008.img.zip

@nightmorph did you per chance try changing the number of softcut voices and reducing the mlr tracks? i know ezra suggested it but i may have missed the results in the thread here

yes, i did that earlier, but it had no effect. just to verify--what's the procedure for loading this image on my norns? or should i just try to reinstall the regular release?

edit:

here's something curious: i ran the update.sh procedure manually, following the linked script, and this time, everything was properly symlinked and installed. i wonder why it worked this time, but not from the release tgz? also, now that the updated libs are in place, how should i re-test the mlr script? any line-by-line changes to make?

note: mlr ran just fine for about 10 minutes, but then hardlocked with the distinctive unpleasant buzz. still, that's greatly improved over the sub-15sec freezes using the old unsymlinked libs.

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

@nightmorph don't bother flashing your disk, we're debugging other over-cpu causes...

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

@nightmorph

edit dust/lib/sc/Engine_SoftCut.sc line 3, change to 4 voices
edit dust/scripts/tehn/mlr.lua line 31, change to 4 tracks

also, can you ssh in to your unit and do

watch vcgencmd measure_temp

while you run your test?

@catfact
Copy link
Collaborator

@catfact catfact commented Oct 22, 2018

@markwheeler i got a couple of hard crashes with loom yesterday, each after 10 minutes or so, not doing any special except dialing up the number of voices to 10 or something.

interestingly, i couldn't get any by running loom without the grid connected. other people have never had a crash.

[ed: oh i should note: i had these after running the 181008 update. before that i was using sources+scripts from tip of git, and sclang/supernova/ugens/matron built on device.]

i don't think this is a problem with your engine or script in pariticular, we're seeing stability problems across the board with high usage under supernova and are still trying to triage this.

making it far more frustrating is the variability across units (or users, or climates, or houses of the zodiac, or who knows.) e.g., josh can get reliable crashes after 30s with mlr, but it takes me 5 days to get one.

anyways, after spending lots of time on softcut-specific obvious culprits (like buffers and custom ugens) i think these are describing the same issue. so seems ok to discuss them both here.

@tehn
Copy link
Member

@tehn tehn commented Oct 22, 2018

@nightmorph i can't explain why those files wouldn't have been properly symlinked. the update procedure is not working correctly and needs to be worked on.

if you would indeed like to try a clean disk image: https://github.com/monome/norns-image/blob/master/readme-usbdisk.md

@markwheeler i've been test-running loom for about 20 minutes now without problems, everything max'd out.

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Oct 22, 2018

edit dust/lib/sc/Engine_SoftCut.sc line 3, change to 4 voices
edit dust/scripts/tehn/mlr.lua line 31, change to 4 tracks

also, can you ssh in to your unit and do

watch vcgencmd measure_temp

changes made, temps tested. really interesting results when it did crash.

  1. mlr ran just fine for 12+ minutes with all 4 pattern recorders operating on sample position and play speed/direction
  2. when it did lockup with the harsh buzzing, the patterns recorded into the grid's REC page continued to move the leds, though nothing showed on the other pages. the norns on-device menu/buttons remained functional.
  3. temps:
  • idle: 48.9c
  • selecting clips: 61.2c
  • playing: 63.4c (just looping)
  • playing: 66.6c, 67.7c (button-mashing, then setting all 4 patterns and letting them run)
    • occasional spikes to 68.8c during this time
  1. when it finally locked up, matron showed a segmentation fault, and i got the most interesting kernel output on the temperature ssh terminal:
Message from syslogd@norns at Oct 23 05:04:37 ...
 kern54.8 1883.169323] 9f60: 6c844ddc 8018e64c 7ee07930 00000000 ffffffff 00000000 809455fc 00000000

Message from syslogd@norns at Oct 23 05:04:37 ...
 kernel:[ 1883.177493] 9f80: 00000011 00000000 00000001 7ee07930 96167ffe 96168000 000000f0 80107cc4

Message from syslogd@norns at Oct 23 05:04:37 ...
 kernel:[ 1883.185664] 9fa0: aca48000 80107ae0 7ee07930 96167ffe 003d4d8c 00000081 00000001 00000000

Message from syslogd@norns at Oct 23 05:04:37 ...
 kernel:[ 1883.193835] 9fc0: 7ee07930 96167ffe 96168000 000000f0 7edc7738 7ee07738 00000001 6c844ddc

Message from syslogd@norns at Oct 23 05:04:37 ...
 kernel:[ 1883.202005] 9fe0: 00000001 6c844d08 00000000 76f2f67c 20000010 003d4d8c 00000000 00000000

Message from syslogd@norns at Oct 23 05:04:37 ...
 kernel:[ 1883.272615] Code: e3480083 eb095918 ee1d3f90 e1a00005 (e7847003)
@catfact
Copy link
Collaborator

@catfact catfact commented Oct 22, 2018

looks like kernel oops / near panic (meaningless Code output, &c). surprised the system didn't go down...

@okyeron
Copy link
Contributor

@okyeron okyeron commented Nov 2, 2018

@tehn i can't explain why those files wouldn't have been properly symlinked. the update procedure is not working correctly and needs to be worked on.

I posted this in the lines update thread, but I'll mention again here:

when I was manually running the sc/install.sh script on RasPi I would get some errors about failing to created symlinks.

A friend helped me out with this and apparently adding -p flag to the mkdir commands fixes those symlink errors.

@catfact
Copy link
Collaborator

@catfact catfact commented Nov 2, 2018

that makes sense. sc install script assumes parents exist but i guess now we are nuking higher levels of SC extension dir tree

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Nov 9, 2018

unfortunately, this hardlock bug is still present, even after receiving my norns back from @tehn and updated to the latest november release. just about a minute of playing four unique samples in mlr (each in their own slot, ranging in size from 34sec to 46sec), and then the device hardlocked with the buzzing sound of death, while running with AC power plugged in, no wifi. controls on the unit and grid/mlr were completely unresponsive.

i think i've managed to reproduce the freezes in a second test:

while playing samples, go into mlr's parameters screen, and adjust volumes for each track (i only touched 2-4). any noticeable/rapid volume change, e.g. 0.85 -> 0.70 resulted in the freeze.

@catfact
Copy link
Collaborator

@catfact catfact commented Nov 9, 2018

ok thanks. we're getting close with some large changes especially to the MLR engine.

in the meantime i'd love to know if you happen get any crashes with any other scripts, and in general what the cpu/temp readings in system are looking like in typical use...

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Nov 9, 2018

when plugged in, temp is 65-66deg when letting all 4 tracks just loop. and what looks like 53%-56% cpu usage at the same time. i'll test more scripts soon as i can.

so far, it's stable for a few minutes when just looping, not making any large adjustments to volume while tracks play.

@tehn
Copy link
Member

@tehn tehn commented Nov 10, 2018

this is alarming to me. i performed similar looping tests for hours here and had no issue. i'm having a difficult time imagining that ambient temperature is our only variation, and will certainly replace hardware if need be.

please report any further data points if you have time.

@catfact
Copy link
Collaborator

@catfact catfact commented Nov 10, 2018

i'm starting to suspect that there are just bugs in supernova and maybe particularly on the ARM/NEON branch of nova-simd. there are definitely places in supernova sources where array bounds checking isn't performed and should be.

@nightmorph
Copy link
Author

@nightmorph nightmorph commented Nov 10, 2018

this is alarming to me. i performed similar looping tests for hours here and had no issue. i'm having a difficult time imagining that ambient temperature is our only variation, and will certainly replace hardware if need be.

please report any further data points if you have time.

i also tested it in pretty cool ambient air; took it out to a nearby canyon late this afternoon. ran off the internal battery, only powering a grid and main audio outs (not the headphone jack). temps were a few degrees C lower, but the unit still locked up twice while running mlr -- both times when switching to the system audio/fx menu.

the first time, the audio cut out immediately upon switching to that menu, even before i'd started adjusting the reverb send amount. the grid remained responsive, but didn't actually do anything. resetting the audio and relaunching mlr was ineffective; no sound came out, so i had to reboot.

the second time, the audio cut out just after switching to the audio menu and quickly adjusting the reverb send. this time it locked up with the harsh buzz.

after those two freezes and reboots, i got a good third take (i was filming a video). i had the proper fx screen already prepared and the setting highlighted, so i didn't need to menu dive the way i did the second take. it was a one-press switchover from mlr to fx settings. in this third try, i made a point of gradually adjusting the send amount, and that worked just fine. so one success outta three 3-minute tries ain't bad.

i'm starting to suspect that there are just bugs in supernova and maybe particularly on the ARM/NEON branch of nova-simd. there are definitely places in that codebase where array bounds checking isn't performed and should be.

last time i played with arm and compilation/optimization/bootstrapping an OS for the architecture was on beagleboard circa 2009. at the time, the arch as a whole had major issues with neon and softfloat. wouldn't surprise me if they still linger in anything that does intense dsp.


lemme know if either of you want me to upload my samples and mlr settings somewhere; it's mostly just track volumes and fx amounts.

@catfact
Copy link
Collaborator

@catfact catfact commented Nov 10, 2018

@nightmorph to fill you in, one thing we're doing is definitely getting rid of supernova. we still want to support people's supercollider patches so there is some work to do re-architecting things. this might include making the SoftCut engine a standalone application (or other plugin like lv2); this is actually underway in a side channel here, single voice with OSC interface for testing https://github.com/catfact/softcut

i'd welcome feedback if you want to give that a spin. it fixes write-head resampling, adds some weird new things (a filter), is still missing many other things (loading files, more voices, routing, param smoothing, &c) and is undergoing more optimization right now. it's nothing like a complete instrument and pretty much needs to be controlled from a remote computer. if you get random crashes with a standalone buffer-manipulating jack client like this then i think there is definitely something bad going with your unit.

@tehn
Copy link
Member

@tehn tehn commented Nov 10, 2018

@nightmorph i know you need the reverb for your performance, but i'd be interested if the crash occurs with AUX turned off?

also for mlr specifically, i'd be curious to have you try commenting out this line (disable supernova): https://github.com/monome/norns/blob/master/sc/core/Crone.sc#L47

you'll need to stop.sh the start.sh to enable this change, which will use normal scsynth

@catfact catfact added bug crone labels Nov 25, 2018
@catfact
Copy link
Collaborator

@catfact catfact commented Apr 7, 2019

2.0 is out; closing

@catfact catfact closed this Apr 7, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
5 participants