Seeing `INFO: Command: CK` loop when connecting ravelox-client to a ravelox-server
Closed this issue · 1 comments
I've been trying to use ravelox to connect a 'client' to my 'server' (both on Pis running Buster) but on connection they seem to get stuck in a loop both repeatedly logging: INFO: Command: CK - It looks a bit like a bug but I wasn't sure? I see there's an option remote.use_control_for_ck - I wasn't sure if that would help?
I've provided the config I've used for both with some debug log of the CK looping I'm seeing:
client.conf (192.168.1.3):
network.bind_address = ::
remote.connect = server
service.name = client
alsa.input_device = hw:1,0
logging.log_level = debug
Log sample:
[1611999987.457014] [tid=1996443664] INFO: Command: CK
[1611999987.457031] [tid=1996443664] DEBUG: sync_data(ssrc=0x641f4e75,count=0,padding=0x000000,timestamp1=0x00000000000012a9,timestamp2=0x0000000000001290,timestamp3=0x00
000000000012aa)
[1611999987.457055] [tid=1996443664] DEBUG: net_ctx_find_by_ssrc: ssrc=0x641f4e75
[1611999987.457073] [tid=1996443664] DEBUG: net_ctx: ctx=0x52818, ssrc=0x641f4e75,status=[remote_connection],send_ssrc=0x46515f3a,initiator=0x7a6356f8,seq=1,host=192.168.
1.232,control=5004,data=5005,start=4294732696 [1611999987.457097] [tid=1996443664] DEBUG: midi_state=0x51b00, status=[MIDI_STATE_INIT], running_status=0x00
[1611999987.457116] [tid=1996443664] DEBUG: ring_buffer=0x51f08,data=0x53d98,size=10240, start=0, end=0, used=0
[1611999987.457135] [tid=1996443664] DEBUG: dbuffer: buffer=0x509e0, len=0, blocks=0
[1611999987.457154] [tid=1996443664] DEBUG: applemidi_sync_responder: now=4294737502 start=4294732696 local_timestamp=4806
[1611999987.457172] [tid=1996443664] INFO: Command: CK
[1611999987.457189] [tid=1996443664] DEBUG: sync_data(ssrc=0x46515f3a,count=1,padding=0x000000,timestamp1=0x00000000000012a9,timestamp2=0x00000000000012c6,timestamp3=0x00
000000000012aa)
[1611999987.457272] [tid=1996443664] DEBUG: net_socket_read: response write(bytes=36,socket=3,host=::ffff:192.168.1.232,port=5004)
[1611999987.458716] [tid=1996443664] DEBUG: net_socket_read: control_fd
[1611999987.458761] [tid=1996443664] DEBUG: net_socket_read: read socket=3, recv_len=36, host=::ffff:192.168.1.232, port=5004, first_byte=ff)
[1611999987.458783] [tid=1996443664] DEBUG: ring_buffer_write: stage=start len=36, ring_buffer=0x38b88,data=0x3ace0,size=10240, start=6575, end=6575, used=0
[1611999987.458805] [tid=1996443664] DEBUG: ring_buffer_write: buffer=contiguous write=contiguous ring=0x38b88 [1611999987.458824] [tid=1996443664] DEBUG: ring_buffer_write: stage=end len=36, ring_buffer=0x38b88,data=0x3ace0,size=10240, start=6575, end=6611, used=36
[1611999987.458847] [tid=1996443664] DEBUG: ring_buffer_read: ring=0x38b88,len=36,advance=0
[1611999987.458866] [tid=1996443664] DEBUG: ring_buffer_read: ring=0x38b88,len=36,advance=0
[1611999987.458884] [tid=1996443664] DEBUG: ring_buffer_read: ring=0x38b88,len=36,advance=1
[1611999987.458903] [tid=1996443664] INFO: Command: CK
server.conf (192.168.1.232)
network.bind_address = ::
service.name = server
alsa.output_device = hw:1,0,0
logging.log_level = debug
Log sample:
[1611999986.982220] [tid=3064107024] INFO: Command: CK
[1611999986.982245] [tid=3064107024] DEBUG: sync_data(ssrc=0x46515f3a,count=0,padding=0x000000,timestamp1=0x0000000000000037,timestamp2=0x000000006dda3afd,timestamp3=0x00
00000075feefb6)
[1611999986.982275] [tid=3064107024] DEBUG: net_ctx_find_by_ssrc: ssrc=0x46515f3a
[1611999986.982301] [tid=3064107024] DEBUG: net_ctx: ctx=0x51898, ssrc=0x46515f3a,status=[idle],send_ssrc=0x641f4e75,initiator=0x7a6356f8,seq=1,host=::ffff:192.168.1.3,co
ntrol=5004,data=5005,start=4294732707
[1611999986.982330] [tid=3064107024] DEBUG: midi_state=0x51928, status=[MIDI_STATE_INIT], running_status=0x00
[1611999986.982356] [tid=3064107024] DEBUG: ring_buffer=0x508f8,data=0x51968,size=10240, start=0, end=0, used=0
[1611999986.982382] [tid=3064107024] DEBUG: dbuffer: buffer=0x50fd0, len=0, blocks=0
[1611999986.982409] [tid=3064107024] DEBUG: applemidi_sync_responder: now=4294732754 start=4294732707 local_timestamp=47
[1611999986.982435] [tid=3064107024] INFO: Command: CK
[1611999986.982460] [tid=3064107024] DEBUG: sync_data(ssrc=0x641f4e75,count=1,padding=0x000000,timestamp1=0x0000000000000037,timestamp2=0x000000000000002f,timestamp3=0x00
00000075feefb6)
[1611999986.982527] [tid=3064107024] DEBUG: net_socket_read: response write(bytes=36,socket=3,host=::ffff:192.168.1.3,port=5004)
[1611999986.984423] [tid=3064107024] DEBUG: net_socket_read: control_fd
[1611999986.984467] [tid=3064107024] DEBUG: net_socket_read: read socket=3, recv_len=36, host=::ffff:192.168.1.3, port=5004, first_byte=ff)
[1611999986.984496] [tid=3064107024] DEBUG: ring_buffer_write: stage=start len=36, ring_buffer=0x38b80,data=0x3ac28,size=10240, start=60, end=60, used=0
[1611999986.984523] [tid=3064107024] DEBUG: ring_buffer_write: buffer=contiguous write=contiguous ring=0x38b80
[1611999986.984549] [tid=3064107024] DEBUG: ring_buffer_write: stage=end len=36, ring_buffer=0x38b80,data=0x3ac28,size=10240, start=60, end=96, used=36
[1611999986.984576] [tid=3064107024] DEBUG: ring_buffer_read: ring=0x38b80,len=36,advance=0
[1611999986.984602] [tid=3064107024] DEBUG: ring_buffer_read: ring=0x38b80,len=36,advance=0
[1611999986.984628] [tid=3064107024] DEBUG: ring_buffer_read: ring=0x38b80,len=36,advance=1
[1611999986.984654] [tid=3064107024] INFO: Command: CK
[1611999986.984679] [tid=3064107024] DEBUG: sync_data(ssrc=0x46515f3a,count=2,padding=0x000000,timestamp1=0x0000000000000037,timestamp2=0x000000000000002f,timestamp3=0x00
00000000000051)
[1611999986.984707] [tid=3064107024] DEBUG: net_ctx_find_by_ssrc: ssrc=0x46515f3a
[1611999986.984733] [tid=3064107024] DEBUG: net_ctx: ctx=0x51898, ssrc=0x46515f3a,status=[idle],send_ssrc=0x641f4e75,initiator=0x7a6356f8,seq=1,host=::ffff:192.168.1.3,co
ntrol=5004,data=5005,start=4294732707
[1611999986.984761] [tid=3064107024] DEBUG: midi_state=0x51928, status=[MIDI_STATE_INIT], running_status=0x00
[1611999986.984787] [tid=3064107024] DEBUG: ring_buffer=0x508f8,data=0x51968,size=10240, start=0, end=0, used=0
[1611999986.984813] [tid=3064107024] DEBUG: dbuffer: buffer=0x50fd0, len=0, blocks=0
[1611999986.984839] [tid=3064107024] DEBUG: applemidi_sync_responder: now=4294732779 start=4294732707 local_timestamp=72
[1611999986.984865] [tid=3064107024] INFO: Command: CK