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

use all memory then crashes once first midi message is sent #43

Closed
TheTechnobear opened this issue Nov 18, 2019 · 22 comments
Closed

use all memory then crashes once first midi message is sent #43

TheTechnobear opened this issue Nov 18, 2019 · 22 comments
Assignees
Labels

Comments

@TheTechnobear
Copy link

TheTechnobear commented Nov 18, 2019

Hi,

im attempting to run raveloxmidi on a rPI3 connecting to a mac (10.14.5) over wifi
a very simple setup.. built from GitHub

alsa.input_device = hw:2,0,0
network.bind_address = 0.0.0.0
logging.enabled = yes
logging.log_level = normal

sudo raveloxmidi -N -d -c /etc/raveloxmidi.conf

it starts ok on the rPI, reporting

network.control.port = 5004
network.data.port = 5005
network.local.port = 5006
network.socket_timeout = 30
network.max_connections = 8
service.name = raveloxmidi
service.ipv4 = yes
service.ipv6 = no
run_as_daemon = no
daemon.pid_file = raveloxmidi.pid
logging.enabled = yes
logging.log_level = normal
security.check = yes
readonly = no
inbound_midi = /dev/sequencer
file_mode = 0640
discover.timeout = 5
sync.interval = 10
network.read.blocksize = 2048
alsa.input_buffer_size = 4096
config.file = /etc/raveloxmidi.conf
alsa.input_device = hw:2,0,0
network.bind_address = 0.0.0.0

and the mac sees it, and then I can connect...

viewing with 'top' on rPI, all looks good,
but as soon as i touch a key on the midi controller

the cpu % rises to 100%, and memory then rises to 100% and ravelosmidi is killed by out of memory reaper, and I can see below in dmesg

thoughts?

[  379.645199] raveloxmidi invoked oom-killer: gfp_mask=0x6080c0(GFP_KERNEL|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0
[  379.645208] raveloxmidi cpuset=/ mems_allowed=0
[  379.645225] CPU: 2 PID: 1462 Comm: raveloxmidi Tainted: G         C        4.19.27-v7+ #1206
[  379.645228] Hardware name: BCM2835
[  379.645251] [<80111ea8>] (unwind_backtrace) from [<8010d430>] (show_stack+0x20/0x24)
[  379.645263] [<8010d430>] (show_stack) from [<8080cdc0>] (dump_stack+0xd4/0x118)
[  379.645275] [<8080cdc0>] (dump_stack) from [<8023a9dc>] (dump_header+0x80/0x250)
[  379.645285] [<8023a9dc>] (dump_header) from [<80239d54>] (oom_kill_process+0x358/0x3a8)
[  379.645293] [<80239d54>] (oom_kill_process) from [<8023a684>] (out_of_memory+0x134/0x36c)
[  379.645303] [<8023a684>] (out_of_memory) from [<80240adc>] (__alloc_pages_nodemask+0x1024/0x1178)
[  379.645314] [<80240adc>] (__alloc_pages_nodemask) from [<8026f8d8>] (__pte_alloc+0x34/0x1b4)
[  379.645323] [<8026f8d8>] (__pte_alloc) from [<802739f8>] (handle_mm_fault+0xce4/0xd68)
[  379.645334] [<802739f8>] (handle_mm_fault) from [<8082a9a8>] (do_page_fault+0x330/0x3a4)
[  379.645343] [<8082a9a8>] (do_page_fault) from [<8082aad8>] (do_translation_fault+0xbc/0xc0)
[  379.645351] [<8082aad8>] (do_translation_fault) from [<801165dc>] (do_DataAbort+0x58/0xf4)
[  379.645360] [<801165dc>] (do_DataAbort) from [<80101ca4>] (__dabt_usr+0x44/0x60)
[  379.645364] Exception stack(0x9d085fb0 to 0x9d085ff8)
[  379.645369] 5fa0:                                     69a00000 347ff018 00000000 35201008
[  379.645375] 5fc0: 00000001 347feff8 00000000 00000000 75600fac 7613ac1c 00000006 01e30f00
[  379.645381] 5fe0: 34800000 7613aba0 000000ac 000175e4 20000010 ffffffff
[  379.645384] Mem-Info:
[  379.645396] active_anon:219476 inactive_anon:2524 isolated_anon:0
                active_file:81 inactive_file:95 isolated_file:0
                unevictable:0 dirty:0 writeback:0 unstable:0
                slab_reclaimable:3384 slab_unreclaimable:2828
                mapped:367 shmem:2650 pagetables:662 bounce:0
                free:5141 free_pcp:0 free_cma:1634
[  379.645405] Node 0 active_anon:877904kB inactive_anon:10096kB active_file:324kB inactive_file:380kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:1468kB dirty:0kB writeback:0kB shmem:10600kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[  379.645417] Normal free:20564kB min:16384kB low:20480kB high:24576kB active_anon:877904kB inactive_anon:10096kB active_file:324kB inactive_file:380kB unevictable:0kB writepending:0kB present:970752kB managed:948300kB mlocked:0kB kernel_stack:952kB pagetables:2648kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:6536kB
[  379.645420] lowmem_reserve[]: 0 0
[  379.645429] Normal: 259*4kB (UMEC) 128*8kB (UME) 125*16kB (UMEC) 60*32kB (UMEC) 21*64kB (UMEC) 12*128kB (UEC) 4*256kB (U) 3*512kB (UE) 1*1024kB (E) 2*2048kB (MC) 1*4096kB (C) = 20636kB
[  379.645487] 2813 total pagecache pages
[  379.645491] 0 pages in swap cache
[  379.645494] Swap cache stats: add 0, delete 0, find 0/0
[  379.645497] Free swap  = 0kB
[  379.645500] Total swap = 0kB
[  379.645503] 242688 pages RAM
[  379.645505] 0 pages HighMem/MovableOnly
[  379.645508] 5613 pages reserved
[  379.645511] 2048 pages cma reserved
[  379.645513] Tasks state (memory values in pages):
[  379.645516] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[  379.645538] [    115]     0   115     3196      358    18432        0             0 systemd-journal
[  379.645544] [    137]     0   137     3646      205    12288        0         -1000 systemd-udevd
[  379.645554] [    277]   100   277     4320       99    20480        0             0 systemd-timesyn
[  379.645560] [    326]     0   326     5937      117    18432        0             0 rsyslogd
[  379.645567] [    330]     0   330     1425       54    16384        0             0 cron
[  379.645573] [    337]   105   337     1623      122    12288        0          -900 dbus-daemon
[  379.645579] [    359]     0   359    23284      565    53248        0             0 NetworkManager
[  379.645586] [    360]     0   360     1845      104    14336        0             0 systemd-logind
[  379.645591] [    361]   108   361     1601       77    16384        0             0 avahi-daemon
[  379.645598] [    370]   108   370     1601       77    12288        0             0 avahi-daemon
[  379.645604] [    394]     0   394     1150       31    14336        0             0 agetty
[  379.645610] [    409]     0   409     2552      132    16384        0         -1000 sshd
[  379.645616] [    415]     0   415     2419      120    14336        0             0 wpa_supplicant
[  379.645622] [    429]     0   429      524       34     8192        0             0 hciattach
[  379.645628] [    438]     0   438     1818       73    14336        0             0 bluetoothd
[  379.645634] [    449]     0   449     1661      181    16384        0             0 dhclient
[  379.645640] [    582]     0   582     2882      186    20480        0             0 sshd
[  379.645647] [    588]  1000   588     2414      166    18432        0             0 systemd
[  379.645653] [    591]  1000   591     2802      283    16384        0             0 (sd-pam)
[  379.645659] [    598]  1000   598     2915      182    20480        0             0 sshd
[  379.645665] [    601]  1000   601     1663      366    16384        0             0 bash
[  379.645671] [   1456]     0  1456     1908       93    16384        0             0 sudo
[  379.645677] [   1460]     0  1460   221370   215130   882688        0             0 raveloxmidi
[  379.645683] [   1464]     0  1464     2882      186    18432        0             0 sshd
[  379.645689] [   1475]  1000  1475     2882      191    18432        0             0 sshd
[  379.645696] [   1478]  1000  1478     1653      351    12288        0             0 bash
[  379.645702] [   1498]  1000  1498     2133      140    16384        0             0 top
[  379.645706] Out of memory: Kill process 1460 (raveloxmidi) score 908 or sacrifice child
[  379.645735] Killed process 1460 (raveloxmidi) total-vm:885480kB, anon-rss:860520kB, file-rss:0kB, shmem-rss:0kB
[  379.754512] oom_reaper: reaped process 1460 (raveloxmidi), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
@ravelox
Copy link
Owner

ravelox commented Nov 18, 2019

Hi

Can you run it in debug mode and paste some of the last few lines of output?

Thanks

Dave

@TheTechnobear
Copy link
Author

TheTechnobear commented Nov 18, 2019

ok, Ive just realised its actually happening even if I don't connect it to the mac..
so just pressing keys on controller causes the issues....

Im trying to get it to crash now in debug...
its at 100% cpu, and is filling memory but VERY slowly

currently it seems to be filling up the log file with the same message about poly aftertouch

(note: Ive stopped pressing anything at this point)

hex_dump(0x75500cb4 , 1)

3d =	
-- end hex_dump
[1574105629]	[tid=1978659712]	DEBUG: MIDI Command: status=0xAA,description="Polyphonic Key Pressure (Aftertouch)"
[1574105629]	[tid=1978659712]	DEBUG: 	channel_message:channel=0xa message=0xa
[1574105629]	[tid=1978659712]	DEBUG: 	system_message: message=0xaa
[1574105629]	[tid=1978659712]	DEBUG: 	delta=0, data_len=0
[1574105629]	[tid=1978659712]	INFO: 	Channel: 10
[1574105629]	[tid=1978659712]	DEBUG: midi_payload_to_commands: current_len=1
hex_dump(0x75500cb4 , 1)

3d =	
-- end hex_dump
[1574105629]	[tid=1978659712]	DEBUG: MIDI Command: status=0xAA,description="Polyphonic Key Pressure (Aftertouch)"
[1574105629]	[tid=1978659712]	DEBUG: 	channel_message:channel=0xa message=0xa
[1574105629]	[tid=1978659712]	DEBUG: 	system_message: message=0xaa
[1574105629]	[tid=1978659712]	DEBUG: 	delta=0, data_len=0
[1574105629]	[tid=1978659712]	INFO: 	Channel: 10
[1574105629]	[tid=1978659712]	DEBUG: midi_payload_to_commands: current_len=1
hex_dump(0x75500cb4 , 1)

3d =	
-- end hex_dump
[1574105629]	[tid=1978659712]	DEBUG: MIDI Command: status=0xAA,description="Polyphonic Key Pressure (Aftertouch)"
[1574105629]	[tid=1978659712]	DEBUG: 	channel_message:channel=0xa message=0xa
[1574105629]	[tid=1978659712]	DEBUG: 	system_message: message=0xaa
[1574105629]	[tid=1978659712]	DEBUG: 	delta=0, data_len=0

hmm, I guess what I need to do is test with another controller , perhaps its got an issue with polyAT?

@TheTechnobear
Copy link
Author

ok, it's something about that controller.

I was testing using an Ableton Push 2.

Ive now switched to another controller and it seems to be working fine!

@TheTechnobear
Copy link
Author

TheTechnobear commented Nov 18, 2019

ok, this is odd...

so the new control (Access Virus ) works fine for a while, and then suddenly I get a stuck note (so note_on , but no note_off)
I go check the logs... and I find indeed its full of polyAT messages again,
but if I scroll back, I can see the last message before polyAT , was a note-on

now the odd thing is... this controller does not send poly AT messages!
(and this time, it would have only been sending note on/off and possibly channel AT messages)

[1574111353]	[tid=1995866112]	DEBUG: midi_payload_to_commands: payload->header->len=3
hex_dump(0x23d8a0 , 3)

80 .	2f /	75 u	
-- end hex_dump
[1574111353]	[tid=1995866112]	DEBUG: midi_payload_to_commands: current_len=3
hex_dump(0x23d8a0 , 3)

80 .	2f /	75 u	
-- end hex_dump
[1574111353]	[tid=1995866112]	DEBUG: MIDI Command: status=0x80,description="Note Off"
[1574111353]	[tid=1995866112]	DEBUG: 	channel_message:channel=0x0 message=0x8
[1574111353]	[tid=1995866112]	DEBUG: 	system_message: message=0x80
[1574111353]	[tid=1995866112]	DEBUG: 	delta=0, data_len=0
[1574111353]	[tid=1995866112]	INFO: 	Channel: 0
[1574111353]	[tid=1995866112]	DEBUG: net_socket_read: feedback write(bytes=12,socket=5,host=192.168.1.94,port=5005)
[1574111353]	[tid=1995866112]	DEBUG: net_socket_read: output_enabled
[1574111353]	[tid=1995866112]	DEBUG: net_socket_read: inbound MIDI write(bytes=3)
[1574111353]	[tid=1995866112]	DEBUG: FREENULL: "midi_payload:payload->buffer"=0x23d8a0
[1574111353]	[tid=1995866112]	DEBUG: FREENULL: "midi_payload:payload->header"=0x22fc18
[1574111353]	[tid=1995866112]	DEBUG: FREENULL: "midi_payload"=0x231310
[1574111353]	[tid=1995866112]	DEBUG: FREENULL: "rtp_packet"=0x22f850
[1574111353]	[tid=1978659712]	DEBUG: net_socket_read: Block size set to 2048
[1574111353]	[tid=1978659712]	DEBUG: net_socket_read: read socket=ALSA recv_len=4 first_byte=aa
[1574111353]	[tid=1978659712]	DEBUG: net_socket_read: 4 > 0, incrementing block count
[1574111353]	[tid=1978659712]	DEBUG: net_socket_read: Copying 4 bytes to read_buffer at postion 0 (block_count=1)
[1574111353]	[tid=1978659712]	DEBUG: net_socket_read: read socket=ALSA recv_len=4 first_byte=aa
[1574111353]	[tid=1978659712]	DEBUG: net_socket_read: Copying 4 bytes to read_buffer at postion 4 (block_count=1)
hex_dump(0x75500488 , 8)

aa .	90 .	2f /	3b ;	aa .	80 .	30 0	7c |	
-- end hex_dump
[1574111353]	[tid=1978659712]	DEBUG: midi_payload_set_buffer: payload=0x75500fa0,buffer=0x75500489,buffer_size=7
[1574111353]	[tid=1978659712]	DEBUG: midi_payload_to_commands: payload->header->len=7
hex_dump(0x75500ca0 , 7)

90 .	2f /	3b ;	aa .	80 .	30 0	7c |	
-- end hex_dump
[1574111353]	[tid=1978659712]	DEBUG: midi_payload_to_commands: current_len=7
hex_dump(0x75500ca0 , 7)

90 .	2f /	3b ;	aa .	80 .	30 0	7c |	
-- end hex_dump
[1574111353]	[tid=1978659712]	DEBUG: MIDI Command: status=0x90,description="Note On"
[1574111353]	[tid=1978659712]	DEBUG: 	channel_message:channel=0x0 message=0x9
[1574111353]	[tid=1978659712]	DEBUG: 	system_message: message=0x90
[1574111353]	[tid=1978659712]	DEBUG: 	delta=0, data_len=0
[1574111353]	[tid=1978659712]	INFO: 	Channel: 0
[1574111353]	[tid=1978659712]	DEBUG: midi_payload_to_commands: current_len=4
hex_dump(0x75500ca3 , 4)

aa .	80 .	30 0	7c |	
-- end hex_dump
[1574111353]	[tid=1978659712]	DEBUG: MIDI Command: status=0xAA,description="Polyphonic Key Pressure (Aftertouch)"
[1574111353]	[tid=1978659712]	DEBUG: 	channel_message:channel=0xa message=0xa
[1574111353]	[tid=1978659712]	DEBUG: 	system_message: message=0xaa
[1574111353]	[tid=1978659712]	DEBUG: 	delta=0, data_len=0
[1574111353]	[tid=1978659712]	INFO: 	Channel: 10
[1574111353]	[tid=1978659712]	DEBUG: midi_payload_to_commands: current_len=1


@TheTechnobear
Copy link
Author

those 'aa' bytes look suspicious ;)
not only is the synth not sending polyAT (0xa0) , but its also not sending data on channel 10

@ravelox
Copy link
Owner

ravelox commented Nov 21, 2019

The first 0xaa byte is a fake one that I prepend to the input buffer to allow me to use the same MIDI parsing that I have for the raw local port.

From what you're showing me, it's highly-likely that I'm prepending that to every read from the ALSA buffer. I'll dig into that.

ravelox pushed a commit that referenced this issue Nov 21, 2019
…s the internal origin prefix to be included more than once
@ravelox
Copy link
Owner

ravelox commented Nov 21, 2019

Can you check out the latest experimental branch and confirm if the fix I added solves the problem?

Thanks

Dave

@TheTechnobear
Copy link
Author

TheTechnobear commented Nov 21, 2019

k, tried with experimental include last fix, unfortunately same issue.
it did seem to last a bit longer, in that i got a few messages thru, and then it fell over in the same way.

so what I see is...
raveloxmidi runs ok, cpu and memory is constant, then suddenly whilst pressing some keys, it just spirals out of control.

one thing, that may be relevant... (and I could see now it stayed up) the controller is sending 'active sense' messages constantly... perhaps this is connected?

BTW: is there a way to for raveloxmidi to read from virtual alsa devices... or for me to send messages to it from a process running on the rPI (e.g. connect via aconnect)

@ravelox
Copy link
Owner

ravelox commented Nov 21, 2019

Can you provide me with the full debug output somewhere so that I can take a look?

Regarding using aconnect, If you take a look at FAQ.md, I wrote up some brief instructions on testing input support using aplaymidi.

Thanks

Dave

@ravelox
Copy link
Owner

ravelox commented Nov 21, 2019

I should have added that I don't do anything with active sensing messages. I receive them but that's all.

@TheTechnobear
Copy link
Author

TheTechnobear commented Nov 21, 2019

doh, yeah of course snd-virmidi forgot all about that :)

active sensing - cool, i just wanted to point out they were there, as its constant traffic.

ok, here is the debug...
https://www.dropbox.com/s/3pkev6q95oedsr5/r.zip?dl=0

so as mentioned previously, the debug mode slows it down, so I don't actually wait for it to run out of memory... but instead i just wait till i can see it steadily growing.

so in this particular case what i did was:
start raveloxmidi
wait a short while to see if it was going to crash without any intervention
then start hitting keys on the controller
UNTIL I saw cpu load go to 97-98% as this is when i know its falling down a slippery slope
I then watched it slowly consuming memory, and stay pegged at 97+%

then I killed it... and zipped up the log file.

Note: I did not even bother to connect it to the mac. so the messages were going nowhere.

the reason i dont connect is it doesnt affect if it crashes or not
but also Ive noticed if raveloxmidi crashes, it seems to have a habit of blocking coremidi on the mac, and so need to reboot the mac!

ravelox pushed a commit that referenced this issue Nov 21, 2019
@ravelox
Copy link
Owner

ravelox commented Nov 21, 2019

I may have had some logic reversed in the change I made. Can you check out the latest experimental code and send me the logging again? I've added a log line that should contain the text "first_byte_ignore", if you want to grep for that.

Thanks

DAve

ravelox pushed a commit that referenced this issue Nov 21, 2019
@ravelox
Copy link
Owner

ravelox commented Nov 21, 2019

I've fixed up my logic. Could you run another test please?

Thanks

Dave

@TheTechnobear
Copy link
Author

k, pulled, compiled, tested - issue remains
new log here..
https://www.dropbox.com/s/3pkev6q95oedsr5/r.zip?dl=0

@TheTechnobear
Copy link
Author

TheTechnobear commented Nov 22, 2019

I had a quick look at the logs, so issue would appear to occur around line 5900

what we can see is we get a new note_on (90, 3a, 19)
we can see it gets coped in net_socket_read, but the buffer is not updated correctly
also we dont see the usual processing sequence, for midi_payload_* as we get on other note messages...
e.g.

[1574429174]	[tid=1973416944]	DEBUG: midi_payload_set_buffer: payload=0x75000fa8,buffer=0x75000739,buffer_size=2
[1574429174]	[tid=1973416944]	DEBUG: midi_payload_to_commands: payload->header->len=2
hex_dump(0x75001138 , 2)

fe .	fe .	
-- end hex_dump
[1574429174]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=2

on the next active sensing , we can see in the hex dump that 3a,19 remained (with a new active sensing message also present)

raveloxmidi seems to then always leave these present in the buffer, and tries to continue to process active sensing messages, but by looking at previous processing msgs, it appears this is incomplete.

relevant portion of log



fe .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload:payload->buffer"=0x75001138
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload:payload->header"=0x75001128
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload"=0x75000fa8
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_set_buffer: payload=0x75000fa8,buffer=0x75001138,buffer_size=1
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload:payload->buffer"=0x75000f50
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload:payload->header"=0x75001128
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload"=0x75000fa8
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_set_buffer: payload=0x75000fa8,buffer=0x75000f50,buffer_size=1
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload:payload->buffer"=0x75001138
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload:payload->header"=0x75001128
[1574429203]	[tid=1973416944]	DEBUG: FREENULL: "midi_payload"=0x75000fa8
[1574429203]	[tid=1973416944]	DEBUG: net_socket_read: Block size set to 2048
[1574429203]	[tid=1973416944]	DEBUG: net_socket_read: read socket=ALSA recv_len=3 first_byte=90
[1574429203]	[tid=1973416944]	DEBUG: net_socket_read: 3 > 0, incrementing block count
[1574429203]	[tid=1973416944]	DEBUG: net_socket_read: Copying 3 bytes to read_buffer at postion 0 (block_count=1)
hex_dump(0x75000738 , 3)

90 .	3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_set_buffer: payload=0x75000fa8,buffer=0x75000739,buffer_size=2
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: payload->header->len=3
hex_dump(0x75001138 , 3)

fe .	3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=3
hex_dump(0x75001138 , 3)

fe .	3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=2
hex_dump(0x75001139 , 2)

3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=2
hex_dump(0x75001139 , 2)

3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=2
hex_dump(0x75001139 , 2)

3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=2
hex_dump(0x75001139 , 2)

3a :	19 .	
-- end hex_dump
[1574429203]	[tid=1973416944]	DEBUG: MIDI Command: status=0xFE,description="Active Sensing"
[1574429203]	[tid=1973416944]	DEBUG: 	channel_message:channel=0xe message=0xf
[1574429203]	[tid=1973416944]	DEBUG: 	system_message: message=0xfe
[1574429203]	[tid=1973416944]	DEBUG: 	delta=0, data_len=0
[1574429203]	[tid=1973416944]	DEBUG: midi_payload_to_commands: current_len=2
hex_dump(0x75001139 , 2)

ravelox pushed a commit that referenced this issue Nov 22, 2019
@ravelox
Copy link
Owner

ravelox commented Nov 22, 2019

Could you check out latest experimental and test again. It looks like I'm not advancing forward after reading MIDI commands that have no parameters.

Thanks

Dave

@TheTechnobear
Copy link
Author

done - now it just segfaults as soon as it starts (both with and without debug)

https://www.dropbox.com/s/js9c59e39xly7l1/r.zip?dl=0

@TheTechnobear
Copy link
Author

Thread 3 "raveloxmidi" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x75aff3f0 (LWP 2217)]
midi_payload_to_commands (payload=0x17330 <midi_payload_to_commands+172>, data_type=data_type@entry=MIDI_PAYLOAD_STREAM, commands=0x75afec90, 
    commands@entry=0x75afec88, num_commands=0x75afec94, num_commands@entry=0x75afec8c) at midi_payload.c:379
379				data_byte = *p;
(gdb) bt
#0  midi_payload_to_commands (payload=0x17330 <midi_payload_to_commands+172>, data_type=data_type@entry=MIDI_PAYLOAD_STREAM, commands=0x75afec90, 
    commands@entry=0x75afec88, num_commands=0x75afec94, num_commands@entry=0x75afec8c) at midi_payload.c:379
#1  0x0001b994 in net_distribute_midi (packet=0x751005d0 "\376\376\376", packet@entry=0x75afed44 "", recv_len=recv_len@entry=3, first_byte_ignore=<optimized out>)
    at net_distribute.c:97
#2  0x0001596c in net_socket_read (fd=fd@entry=-2) at net_socket.c:344
#3  0x00015d70 in net_socket_alsa_listener (data=<optimized out>) at net_socket.c:604
#4  0x76e65494 in start_thread (arg=0x75aff3f0) at pthread_create.c:486
#5  0x76de8578 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:73 from /lib/arm-linux-gnueabihf/libc.so.6`

current_len looks very dodgy ;)

(gdb) f 0
#0  midi_payload_to_commands (payload=0x17330 <midi_payload_to_commands+172>, data_type=data_type@entry=MIDI_PAYLOAD_STREAM, commands=0x75afec90, 
    commands@entry=0x75afec88, num_commands=0x75afec94, num_commands@entry=0x75afec8c) at midi_payload.c:379
379				data_byte = *p;
(gdb) list
374			(*commands)[index].data = NULL;
375	
376			// Get the status byte. If bit 7 is not set, use the running status
377			if( current_len > 0 )
378			{
379				data_byte = *p;
380	
381				if( data_byte & 0x80 )
382				{
383					running_status = data_byte;
(gdb) p current_len
$3 = 4294835707
(gdb) 

@TheTechnobear
Copy link
Author

the issue is caused by your latest change, using current_len--,
current_len = 0 and because its unsigned, this is causing a very large value.

ravelox pushed a commit that referenced this issue Nov 23, 2019
@ravelox
Copy link
Owner

ravelox commented Nov 23, 2019

Yep, me culpa :)
I've just pushed a change to experimental that appears to work. Basically, I've taken out the fake byte to identify the origin of the data. This is going to break all the test python scripts I provided ( so I need to get those fixed up ) and everybody who is using the local (non-ALSA) port to send raw MIDI data. However, when data is being sent quickly to those ports, my read routines are reading multiple sends into the same buffer and the fake origin byte is causing the problem.

Please try again with the latest experimental code. Thanks for your patience.

Dave

@TheTechnobear
Copy link
Author

this looks good ....... no issues with this device now :)

ok, Ive got another issue, when lots of messages are sent but I'll raise that separately as its quite likely not related?!

@ravelox
Copy link
Owner

ravelox commented Nov 25, 2019

We'll call this one closed and move on to #44

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants