dagargo / overwitch

JACK client for Overbridge devices
GNU General Public License v3.0
127 stars 15 forks source link

Audio not working or with huge glitches #45

Closed lentferj closed 11 months ago

lentferj commented 1 year ago

I did not update for a long time, today I did. I would not get audio at all or only after several minutes and then with hefty glitches. I bisected the code and found e852feba18c32de1aed7052484a39585e7024bd9 to be the causing commit.

I confirmed by compiling latest master with this patch, and it worked for me again on both Digitone and Digitakt:

diff --git a/src/engine.c b/src/engine.c
index b283529..9add2de 100644
--- a/src/engine.c
+++ b/src/engine.c
@@ -37,7 +37,7 @@
 #define MIDI_OUT_EP 0x01
 #define MIDI_IN_EP  (MIDI_OUT_EP | 0x80)

-#define XFR_TIMEOUT 5
+#define XFR_TIMEOUT 0

 #define MIDI_BUF_EVENTS 64
 #define MIDI_BUF_LEN (MIDI_BUF_EVENTS * OB_MIDI_EVENT_SIZE)
dagargo commented 1 year ago

That's weird. Master branch is working great for me.

Can't remember the reason I changed this but I guess you're having issues because some packets cannot be delivered on time and therefore the timeout is reached and the next packages are sent after 5 ms.

Is it possible that you're having too much USB traffic and your issue is caused by this? Are you having other USB issues with other devices on the same USB bus? Could you try with only one machine? Are you using dummy cores (Intel Hyperthreading or the like)? Could you deactivate them?

Perhaps is safer -and easier- to set it to 0 as you did but let's investigate this a bit because timeout should never be reached for RT applications and it's just a safety measure.

lentferj commented 1 year ago

Sorry for the late response, holidays kept me busy ;

I do have quite a bit going on on my USB, I tried to strip it down as much as possible:

# lsusb
Bus 002 Device 016: ID 1935:0014 Elektron Music Machines Elektron Digitone
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 008 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 007 Device 006: ID 1b1c:1b45 Corsair CORSAIR K63 Wireless Mechanical Gaming Keyboard
Bus 007 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver
Bus 007 Device 003: ID 05e3:0608 Genesys Logic, Inc. Hub
Bus 007 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 006 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 003: ID 1235:8214 Focusrite-Novation Scarlett 18i8 3rd Gen
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub

Recompiled with XFR_TIMEOUT 5 - problem is there again. No audio at all this time (only waited for 2-3 minutes).

This is the console output

$ overwitch-cli -l
0: Digitone (ID 1935:0014) at bus 002, address 016
$ overwitch-cli -vvvvv -d Digitone
DEBUG:overwitch.c:303:(ow_get_device_desc_from_vid_pid): Failed to open file “/home/lentferj/.config/overwitch/devices.json”: No such file or directory
DEBUG:overwitch.c:309:(ow_get_device_desc_from_vid_pid): Falling back to /usr/local/share/overwitch/devices.json...
DEBUG:overwitch.c:368:(ow_get_device_desc_from_vid_pid): Device with PID 20 found
DEBUG:overwitch.c:229:(ow_get_usb_device_list): Found Digitone (bus 002, address 016, ID 1935:0014)
DEBUG:overwitch.c:303:(ow_get_device_desc_from_vid_pid): Failed to open file “/home/lentferj/.config/overwitch/devices.json”: No such file or directory
DEBUG:overwitch.c:309:(ow_get_device_desc_from_vid_pid): Falling back to /usr/local/share/overwitch/devices.json...
DEBUG:overwitch.c:368:(ow_get_device_desc_from_vid_pid): Device with PID 20 found
DEBUG:engine.c:531:(ow_engine_init_mem): o2p: USB in frame size: 48 B
DEBUG:engine.c:532:(ow_engine_init_mem): p2o: USB out frame size: 8 B
DEBUG:engine.c:541:(ow_engine_init_mem): o2p: USB in block size: 368 B
DEBUG:engine.c:543:(ow_engine_init_mem): p2o: USB out block size: 88 B
DEBUG:engine.c:551:(ow_engine_init_mem): o2p: audio transfer size: 8064 B
DEBUG:engine.c:553:(ow_engine_init_mem): p2o: audio transfer size: 1344 B
DEBUG:engine.c:1280:(ow_engine_load_overbridge_name): USB control in data (32 B): Digitone
DEBUG:engine.c:1300:(ow_engine_load_overbridge_name): USB control in data (16 B): 0080       1.40A
Jack: JackClient::SetupDriverSync driver sem in flush mode
Jack: JackLinuxFutex::Connect name = jack_sem.1002_default_Digitone
Jack: Clock source : system clock via clock_gettime
Jack: JackLibClient::Open name = Digitone refnum = 5
DEBUG:jclient.c:102:(jclient_set_buffer_size_cb): JACK buffer size: 128
DEBUG:resampler.c:539:(ow_resampler_set_buffer_size): resampler buffer size: 128
DEBUG:resampler.c:161:(ow_resampler_reset_dll): Resetting the DLL...
DEBUG:dll.c:114:(ow_dll_primary_reset): Target delay: 11.0 ms (528 frames)
DEBUG:jclient.c:112:(jclient_set_sample_rate_cb): JACK sample rate: 48000
DEBUG:resampler.c:552:(ow_resampler_set_samplerate): resampler sample rate: 48000
DEBUG:resampler.c:161:(ow_resampler_reset_dll): Resetting the DLL...
DEBUG:dll.c:114:(ow_dll_primary_reset): Target delay: 11.0 ms (528 frames)
DEBUG:jclient.c:112:(jclient_set_sample_rate_cb): JACK sample rate: 48000
DEBUG:jclient.c:502:(jclient_run): Using RT priority 90...
Jack: JackClient::PortRegister ref = 5 name = Digitone:Main L type = 32 bit float mono audio port_index = 33
Jack: JackClient::PortRegister ref = 5 name = Digitone:Main R type = 32 bit float mono audio port_index = 34
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 1 L type = 32 bit float mono audio port_index = 35
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 1 R type = 32 bit float mono audio port_index = 36
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 2 L type = 32 bit float mono audio port_index = 37
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 2 R type = 32 bit float mono audio port_index = 38
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 3 L type = 32 bit float mono audio port_index = 39
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 3 R type = 32 bit float mono audio port_index = 40
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 4 L type = 32 bit float mono audio port_index = 41
Jack: JackClient::PortRegister ref = 5 name = Digitone:Track 4 R type = 32 bit float mono audio port_index = 42
Jack: JackClient::PortRegister ref = 5 name = Digitone:Input L type = 32 bit float mono audio port_index = 43
Jack: JackClient::PortRegister ref = 5 name = Digitone:Input R type = 32 bit float mono audio port_index = 44
Jack: JackClient::PortRegister ref = 5 name = Digitone:Main L Input type = 32 bit float mono audio port_index = 45
Jack: JackClient::PortRegister ref = 5 name = Digitone:Main R Input type = 32 bit float mono audio port_index = 46
Jack: JackClient::PortRegister ref = 5 name = Digitone:MIDI out type = 8 bit raw midi port_index = 47
Jack: JackClient::PortRegister ref = 5 name = Digitone:MIDI in type = 8 bit raw midi port_index = 48
DEBUG:engine.c:1105:(ow_engine_start): Starting p2o MIDI thread...
Jack: JackPosixThread::AcquireRealTimeImp priority = 90
DEBUG:engine.c:1118:(ow_engine_start): Starting audio and o2p MIDI thread...
Jack: JackPosixThread::AcquireRealTimeImp priority = 90
Jack: JackClient::Activate
Jack: JackPosixThread::StartImp : create non RT thread
Jack: JackPosixThread::ThreadHandler : start
Jack: JackClient::kBufferSizeCallback buffer_size = 128
DEBUG:jclient.c:102:(jclient_set_buffer_size_cb): JACK buffer size: 128
Jack: JackClient::Init : period = 2666 computation = 300 constraint = 2666
Jack: JackPosixThread::AcquireRealTimeImp priority = 90
DEBUG:resampler.c:348:(ow_resampler_compute_ratios): Booting Overbridge side...
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 2
Jack: JackClient::kActivateClient name = Digitone ref = 5 
DEBUG:resampler.c:359:(ow_resampler_compute_ratios): Starting up resampler...
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.181892, avg. 1.140558
DEBUG:resampler.c:407:(ow_resampler_compute_ratios): Tuning resampler...
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.176758, avg. 1.180222
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.165957, avg. 1.171064
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.153900, avg. 1.159071
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.149787, avg. 1.151378
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.146668, avg. 1.148483
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.147302, avg. 1.145873
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.153468, avg. 1.150342
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 11
Jack: JackClient::kPortConnectCallback src = 33 dst = 21
Jack: WaitGraphChange...
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156188, avg. 1.154585
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 11
Jack: JackClient::kPortConnectCallback src = 34 dst = 22
Jack: WaitGraphChange...
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.160893, avg. 1.159546
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.160077, avg. 1.160706
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.154875, avg. 1.157804
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.152973, avg. 1.153116
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 11
Jack: JackClient::kPortConnectCallback src = 3 dst = 21
Jack: WaitGraphChange...
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156572, avg. 1.155749
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156388, avg. 1.155334
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.158546, avg. 1.158229
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 11
Jack: JackClient::kPortConnectCallback src = 3 dst = 22
Jack: WaitGraphChange...
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 18
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.152897, avg. 1.156215
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.159201, avg. 1.155054
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.165041, avg. 1.162740
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.159368, avg. 1.162013
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.158442, avg. 1.158948
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.161965, avg. 1.160269
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.162494, avg. 1.162314
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.154040, avg. 1.158784
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.146852, avg. 1.149699
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.143979, avg. 1.145629
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.144332, avg. 1.142973
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.154366, avg. 1.149500
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.159032, avg. 1.157228
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.159367, avg. 1.159452
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.166620, avg. 1.162048
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.170332, avg. 1.169786
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.166040, avg. 1.168092
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.159141, avg. 1.162281
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.155804, avg. 1.156990
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.155712, avg. 1.155141
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156516, avg. 1.156408
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.161377, avg. 1.159316
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.164061, avg. 1.163301
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.166246, avg. 1.165058
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156143, avg. 1.161988
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156746, avg. 1.155729
Digitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.156119, avg. 1.156975

^CDigitone@002,016: o2p latency: -1.0 ms, max. -1.0 ms; p2o latency: -1.0 ms, max. -1.0 ms, o2p ratio: 1.154193, avg. 1.156975
DEBUG:jclient.c:604:(jclient_run): Exiting...
Jack: JackClient::Deactivate
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 12
Jack: JackClient::ClientNotify ref = 5 name = Digitone notify = 12
Jack: JackClient::Deactivate res = 0
Jack: JackPosixThread::Kill
Jack: jack_client_close
Jack: JackClient::Close ref = 5
Jack: JackClient::Deactivate
Jack: JackSocketClientChannel::Stop
Jack: JackPosixThread::Kill
Jack: JackClientSocket::Close
Jack: JackClientSocket::Close
Jack: JackLibClient::~JackLibClient
Jack: JackShmReadWritePtr1::~JackShmReadWritePtr1 5
Jack: Succeeded in unlocking 426 byte memory area
Jack: JackLibGlobals Destroy bc000b60
Jack: ~JackLibGlobals
Jack: no message buffer overruns
Jack: JackPosixThread::Stop
Jack: JackPosixThread::ThreadHandler : exit
Jack: JackShmReadWritePtr::~JackShmReadWritePtr 1
Jack: Succeeded in unlocking 1187 byte memory area
Jack: JackShmReadWritePtr::~JackShmReadWritePtr 0
Jack: Succeeded in unlocking 107341338 byte memory area
Jack: jack_client_close res = 0

Compiled again with XFR_TIMEOUT 0 - sound is there immediately (after connection the audio channels in qjackctl).

lentferj commented 1 year ago

I experimented a bit with the value for XFR_TIMEOUT and at value 7 it starts working again for me, with my whole setup connected. No glitches, sound is available almost immediately.

Maybe 10 is a more reasonable value than 5?

szszoke commented 1 year ago

I wonder if this should be something configurable. People would have to tweak it as part of tuning Overwitch to their system. I think the alternative is that every time this delay is changed someone gets their working Overwitch setup broken.

dagargo commented 1 year ago

@szszoke , definitely, it's the best approach.

I'm currently quite busy but I'm adding this to the 1.1 backlog.

dagargo commented 1 year ago

I've tried to avoid adding this parameter as it's something very technical that might confuse users. But this issue has recently arisen again and decided to add it as it's probably useful for low powered setups that need more tweaking.

It's available in all the binaries and the default value has been increased to 10 as @lentferj suggested.

It would be great if you could test it a bit.

dagargo commented 11 months ago

Closing this as solved.