zynthian / zynthian-issue-tracking

Centralized Issue Tracking for Zynthian Project
https://github.com/orgs/zynthian/projects/1
11 stars 3 forks source link

Dexed fails to play/open. But is visible in UI.. #428

Closed kanaida2 closed 6 months ago

kanaida2 commented 3 years ago

Describe the bug Dexed fails to open when selected. Nothing plays. UI shows up ok.

Apr 03 04:54:19 zynthian startx[3267]: ERROR:zynthian_engine.proc_cmd: Can't exec engine command: preset file:///zynthian/zynthian-my-data/presets/lv2/dexed-DCDCollection.lv2/dexed-03_Meinecke.ttl => End Of File (EOF). Exception style platform. Apr 03 04:54:19 zynthian startx[3267]: <pexpect.pty_spawn.spawn object at 0xac823730> Apr 03 04:54:19 zynthian startx[3267]: command: /usr/local/bin/jalv.gtk Apr 03 04:54:19 zynthian startx[3267]: args: ['/usr/local/bin/jalv.gtk', '--jack-name', 'Dexed-00', 'https://github.com/dcoredump/dexed.lv2'] Apr 03 04:54:19 zynthian startx[3267]: buffer (last 100 chars): b'' Apr 03 04:54:19 zynthian startx[3267]: before (last 100 chars): b'preset file:///zynthian/zynthian-my-data/presets/lv2/dexed-DCDCollection.lv2/dexed-03_Meinecke.ttl\r\n' Apr 03 04:54:19 zynthian startx[3267]: after: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: match: None Apr 03 04:54:19 zynthian startx[3267]: match_index: None Apr 03 04:54:19 zynthian startx[3267]: exitstatus: None Apr 03 04:54:19 zynthian startx[3267]: flag_eof: True Apr 03 04:54:19 zynthian startx[3267]: pid: 3843 Apr 03 04:54:19 zynthian startx[3267]: child_fd: 32 Apr 03 04:54:19 zynthian startx[3267]: closed: False Apr 03 04:54:19 zynthian startx[3267]: timeout: 20 Apr 03 04:54:19 zynthian startx[3267]: delimiter: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: logfile: None Apr 03 04:54:19 zynthian startx[3267]: logfile_read: None Apr 03 04:54:19 zynthian startx[3267]: logfile_send: None Apr 03 04:54:19 zynthian startx[3267]: maxread: 2000 Apr 03 04:54:19 zynthian startx[3267]: ignorecase: False Apr 03 04:54:19 zynthian startx[3267]: searchwindowsize: None Apr 03 04:54:19 zynthian startx[3267]: delaybeforesend: 0 Apr 03 04:54:19 zynthian startx[3267]: delayafterclose: 0.1 Apr 03 04:54:19 zynthian startx[3267]: delayafterterminate: 0.1 Apr 03 04:54:19 zynthian startx[3267]: searcher: searcher_re: Apr 03 04:54:19 zynthian startx[3267]: 0: re.compile(b'\n> ') Apr 03 04:54:19 zynthian startx[3267]: ERROR:zynthian_engine.proc_cmd: Can't exec engine command: set 2 1.000000 => End Of File (EOF). Exception style platform. Apr 03 04:54:19 zynthian startx[3267]: <pexpect.pty_spawn.spawn object at 0xac823730> Apr 03 04:54:19 zynthian startx[3267]: command: /usr/local/bin/jalv.gtk Apr 03 04:54:19 zynthian startx[3267]: args: ['/usr/local/bin/jalv.gtk', '--jack-name', 'Dexed-00', 'https://github.com/dcoredump/dexed.lv2'] Apr 03 04:54:19 zynthian startx[3267]: buffer (last 100 chars): b'' Apr 03 04:54:19 zynthian startx[3267]: before (last 100 chars): b'set 2 1.000000\r\n' Apr 03 04:54:19 zynthian startx[3267]: after: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: match: None Apr 03 04:54:19 zynthian startx[3267]: match_index: None Apr 03 04:54:19 zynthian startx[3267]: exitstatus: None Apr 03 04:54:19 zynthian startx[3267]: flag_eof: True Apr 03 04:54:19 zynthian startx[3267]: pid: 3843 Apr 03 04:54:19 zynthian startx[3267]: child_fd: 32 Apr 03 04:54:19 zynthian startx[3267]: closed: False Apr 03 04:54:19 zynthian startx[3267]: timeout: 20 Apr 03 04:54:19 zynthian startx[3267]: delimiter: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: logfile: None Apr 03 04:54:19 zynthian startx[3267]: logfile_read: None Apr 03 04:54:19 zynthian startx[3267]: logfile_send: None Apr 03 04:54:19 zynthian startx[3267]: maxread: 2000 Apr 03 04:54:19 zynthian startx[3267]: ignorecase: False Apr 03 04:54:19 zynthian startx[3267]: searchwindowsize: None Apr 03 04:54:19 zynthian startx[3267]: delaybeforesend: 0 Apr 03 04:54:19 zynthian startx[3267]: delayafterclose: 0.1 Apr 03 04:54:19 zynthian startx[3267]: delayafterterminate: 0.1 Apr 03 04:54:19 zynthian startx[3267]: searcher: searcher_re: Apr 03 04:54:19 zynthian startx[3267]: 0: re.compile(b'\n> ') Apr 03 04:54:19 zynthian startx[3267]: ERROR:zynthian_engine.proc_cmd: Can't exec engine command: set 3 0.000000 => End Of File (EOF). Exception style platform. Apr 03 04:54:19 zynthian startx[3267]: <pexpect.pty_spawn.spawn object at 0xac823730> Apr 03 04:54:19 zynthian startx[3267]: command: /usr/local/bin/jalv.gtk Apr 03 04:54:19 zynthian startx[3267]: args: ['/usr/local/bin/jalv.gtk', '--jack-name', 'Dexed-00', 'https://github.com/dcoredump/dexed.lv2'] Apr 03 04:54:19 zynthian startx[3267]: buffer (last 100 chars): b'' Apr 03 04:54:19 zynthian startx[3267]: before (last 100 chars): b'set 3 0.000000\r\n' Apr 03 04:54:19 zynthian startx[3267]: after: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: match: None Apr 03 04:54:19 zynthian startx[3267]: match_index: None Apr 03 04:54:19 zynthian startx[3267]: exitstatus: None Apr 03 04:54:19 zynthian startx[3267]: flag_eof: True Apr 03 04:54:19 zynthian startx[3267]: pid: 3843 Apr 03 04:54:19 zynthian startx[3267]: child_fd: 32 Apr 03 04:54:19 zynthian startx[3267]: closed: False Apr 03 04:54:19 zynthian startx[3267]: timeout: 20 Apr 03 04:54:19 zynthian startx[3267]: delimiter: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: logfile: None Apr 03 04:54:19 zynthian startx[3267]: logfile_read: None Apr 03 04:54:19 zynthian startx[3267]: logfile_send: None Apr 03 04:54:19 zynthian startx[3267]: maxread: 2000 Apr 03 04:54:19 zynthian startx[3267]: ignorecase: False Apr 03 04:54:19 zynthian startx[3267]: searchwindowsize: None Apr 03 04:54:19 zynthian startx[3267]: delaybeforesend: 0 Apr 03 04:54:19 zynthian startx[3267]: delayafterclose: 0.1 Apr 03 04:54:19 zynthian startx[3267]: delayafterterminate: 0.1 Apr 03 04:54:19 zynthian startx[3267]: searcher: searcher_re: Apr 03 04:54:19 zynthian startx[3267]: 0: re.compile(b'\n> ') Apr 03 04:54:19 zynthian startx[3267]: ERROR:zynthian_engine.proc_cmd: Can't exec engine command: set 4 1.000000 => End Of File (EOF). Exception style platform. Apr 03 04:54:19 zynthian startx[3267]: <pexpect.pty_spawn.spawn object at 0xac823730> Apr 03 04:54:19 zynthian startx[3267]: command: /usr/local/bin/jalv.gtk Apr 03 04:54:19 zynthian startx[3267]: args: ['/usr/local/bin/jalv.gtk', '--jack-name', 'Dexed-00', 'https://github.com/dcoredump/dexed.lv2'] Apr 03 04:54:19 zynthian startx[3267]: buffer (last 100 chars): b'' Apr 03 04:54:19 zynthian startx[3267]: before (last 100 chars): b'set 4 1.000000\r\n' Apr 03 04:54:19 zynthian startx[3267]: after: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: match: None Apr 03 04:54:19 zynthian startx[3267]: match_index: None Apr 03 04:54:19 zynthian startx[3267]: exitstatus: None Apr 03 04:54:19 zynthian startx[3267]: flag_eof: True Apr 03 04:54:19 zynthian startx[3267]: pid: 3843 Apr 03 04:54:19 zynthian startx[3267]: child_fd: 32 Apr 03 04:54:19 zynthian startx[3267]: closed: False Apr 03 04:54:19 zynthian startx[3267]: timeout: 20 Apr 03 04:54:19 zynthian startx[3267]: delimiter: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: logfile: None Apr 03 04:54:19 zynthian startx[3267]: logfile_read: None Apr 03 04:54:19 zynthian startx[3267]: logfile_send: None Apr 03 04:54:19 zynthian startx[3267]: maxread: 2000 Apr 03 04:54:19 zynthian startx[3267]: ignorecase: False Apr 03 04:54:19 zynthian startx[3267]: searchwindowsize: None Apr 03 04:54:19 zynthian startx[3267]: delaybeforesend: 0 Apr 03 04:54:19 zynthian startx[3267]: delayafterclose: 0.1 Apr 03 04:54:19 zynthian startx[3267]: delayafterterminate: 0.1 Apr 03 04:54:19 zynthian startx[3267]: searcher: searcher_re: Apr 03 04:54:19 zynthian startx[3267]: 0: re.compile(b'\n> ') Apr 03 04:54:19 zynthian startx[3267]: ERROR:zynthian_engine.proc_cmd: Can't exec engine command: set 5 0.000000 => End Of File (EOF). Exception style platform. Apr 03 04:54:19 zynthian startx[3267]: <pexpect.pty_spawn.spawn object at 0xac823730> Apr 03 04:54:19 zynthian startx[3267]: command: /usr/local/bin/jalv.gtk Apr 03 04:54:19 zynthian startx[3267]: args: ['/usr/local/bin/jalv.gtk', '--jack-name', 'Dexed-00', 'https://github.com/dcoredump/dexed.lv2'] Apr 03 04:54:19 zynthian startx[3267]: buffer (last 100 chars): b'' Apr 03 04:54:19 zynthian startx[3267]: before (last 100 chars): b'set 5 0.000000\r\n' Apr 03 04:54:19 zynthian startx[3267]: after: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: match: None Apr 03 04:54:19 zynthian startx[3267]: match_index: None Apr 03 04:54:19 zynthian startx[3267]: exitstatus: None Apr 03 04:54:19 zynthian startx[3267]: flag_eof: True Apr 03 04:54:19 zynthian startx[3267]: pid: 3843 Apr 03 04:54:19 zynthian startx[3267]: child_fd: 32 Apr 03 04:54:19 zynthian startx[3267]: closed: False Apr 03 04:54:19 zynthian startx[3267]: timeout: 20 Apr 03 04:54:19 zynthian startx[3267]: delimiter: <class 'pexpect.exceptions.EOF'> Apr 03 04:54:19 zynthian startx[3267]: logfile: None Apr 03 04:54:19 zynthian startx[3267]: logfile_read: None Apr 03 04:54:19 zynthian startx[3267]: logfile_send: None Apr 03 04:54:19 zynthian startx[3267]: maxread: 2000 Apr 03 04:54:19 zynthian startx[3267]: ignorecase: False Apr 03 04:54:19 zynthian startx[3267]: searchwindowsize: None Apr 03 04:54:19 zynthian startx[3267]: delaybeforesend: 0 Apr 03 04:54:19 zynthian startx[3267]: delayafterclose: 0.1 Apr 03 04:54:19 zynthian startx[3267]: delayafterterminate: 0.1 Apr 03 04:54:19 zynthian startx[3267]: searcher: searcher_re: Apr 03 04:54:19 zynthian startx[3267]: 0: re.compile(b'\n> ')

To Reproduce Steps to reproduce the behavior: I'm not sure.

Expected behavior I expected it to open and play when I use my keyboard

Screenshots

Setup:

Additional context I think I shut it off via the physical switch by accident, but I'm unsure if that's related.

jofemodo commented 3 years ago

Hi @kanaida2 !

I can't reproduce your issue on the latest stable image.

https://os.zynthian.org/2021-03-25-zynthianos-stable-2103.zip

FYI, currently it's quite safe to power off your zynthian by un-plugging the cable. Of course, it's always better to use the soft-power-off, but i normally unplug my zynthians and only very rarely i got a corrupted SD.

Regards,

kanaida2 commented 3 years ago

I will write down all the steps to reproduce when I get my hands on the device again today or tomorrow.

jofemodo commented 3 years ago

Hi @kanaida2 !

Could you reproduce the error?

Thanks

kanaida2 commented 3 years ago

I will try it with your image soon. I'm waiting for another raspberry pi in the mail today. Since my production one is in the case already.

kanaida2 commented 3 years ago

I've created system and data backups so you can reproduce the problem. It was already using the same image, then I went into the web UI and configured it. Plugged in a midi keyboard. Tested dexed and no sound.

https://www.dropbox.com/s/vrvilrh7kus9yyg/zynthian_data_backup20210407-183333.zip?dl=0 https://www.dropbox.com/s/ou3wnf8zz11bt6s/zynthian_system_backup20210407-183350.zip?dl=0

HARDWARE Raspberry Pi 4 Model B Rev 1.4 (Custom) Soundcard: RBPi HDMI Display: Generic HDMI Display Wiring: DUMMIES GPIO Expander: Not detected SYSTEM Raspbian GNU/Linux 10 (buster) Build Date: 2020-09-05 Memory: 5% (459M/7966M) SD Card: 34% (9.3G/30G) Temperature: 55.0ºC MIDI Profile: default.sh Fine Tuning: 440 Hz Master Channel: 16 Single Active Channel: on ZS3 SubSnapShots: on SOFTWARE zyncoder: stable (d852c8f) zynthian-ui: stable (01c808c) zynthian-sys: stable (140eac7) zynthian-data: stable (194fd59) zynthian-webconf: stable (b64c737) LIBRARY Snapshots: 2 User Presets: 5 User Soundfonts: 0 Audio Captures: 0 MIDI Captures: 0 NETWORK Hostname: zynthian Wifi: on IP: 192.168.0.179 2607:fb90:42fb:2eb:d72f:128:25ae:3af7 RTP-MIDI: off QMidiNet: off

kanaida2 commented 3 years ago

The problem happens each time i create a new zynthian sdcard, then use the webui to configure it all how i need. When i'm done, that same error occurs. If i had to guess, something in the web ui could be responsible but I'm not sure wich step causes the problem without recreating another box again. Then checking dexed after each change i make.

riban-bw commented 2 years ago

This looks like the issue where zynthian fails to parse the jalv command prompt, especially after restarting zynthian too quickly. Occurs very frequently when debugging with a jalv engine. This really needs resolving as a matter of urgency as it has substantial impact.

riban-bw commented 2 years ago

I suspect this only happens with jalv.gtk. The pexpect response is a regexp so maybe there is something that can be done to give more robust result, e.g. "\n.*> ". Or check the code of jalv.gtk which has different console handling to jalv for some reason.

riban-bw commented 2 years ago

Horrid bug that is proving difficult to resolve. Let's not let this block 22.05 but immediately start to look at how we might better implement LV2 hosting. Maybe update jalv for better integration or use alternative LV2 host.

riban-bw commented 2 years ago

There was an improvement to upstream jalv which may have resolved this. I have not experienced this issue since we merged the upstream fix so I have marked this ticket as resolved. We can do further testing during next release candidate testing phase.

riban-bw commented 2 years ago

This issue persists. I feel like it may need a significant investment in jalv (or a replacement) to resolve this.

riban-bw commented 2 years ago

I have been testing how modules behave during restarts and observe that every individual engine seems to behave well but attempting to stop / restart several engines simultaneously can cause bad states, e.g. modules do not fully close or crash and hang before being restarted. This is particularly noticeable during UI restart (which is not a standard user workflow since the option has been removed from the admin menu) but can also occur during snapshot loading, especially when unloading a snapshot with lots of engines to load another, maybe with similar engines.

We have put some measures in place to reduce the risk of this occurring but it is not resolved. The work being done to improve service management (in "service improvements" branch) has identified may of the triggers of this issue including engines (apparently) crashing on shutdown impacting parent modules. I still anticipate jalv may need some attention / replacing but I also believe there are many improvements that can be made by more careful handling of engine start / stop.

This work will not be completed before the release of 2210 so I am removing the milestone tag from the ticket but will retain the urgent tag as this can have significant impact.