Timing is jittery.

[karnevil9]

Raveloxmidi is pretty dang promising. Thanks so much for putting this out.

I am finding that note on/off events are sometimes being delayed resulting in, for example, uneven rythym, and occasionally, stuck notes. Very strangely, once it gets really bad, I can stop playing altogether and seconds later, a note-on will arrive (very late, obviously). Feels like maybe a buffer is being overrun or something.

To demonstrate the problem, I am using a Korg nanoKey Studio, a small keyboard with an arpeggiator feature. I set up the nanoKey so that it simply alternates between one note and another an octave above, fairly rapidly, at an even rythym. Over a wired USB connection, the timing is perfect. Using the nanoKey's built-in bluetooth, it's still really good. USB to a Raspberry Pi, then raveloxmidi to my MacBook, timing is not great.

Running "top" while this is happening shows that the raveloxmidi process is pretty consistently at around 20-25% with nothing else spiking (as near as I can tell), nor does it appear that there is any paging involved.

I am attaching a video contrasting the raveloxmidi with the USB direct connect cases.
midibridge usb.mov.zip
midibridge ravelox.mov.zip

Please let me know what other information you need to help impove this.

[karnevil9]

BTW, I tried increasing "alsa.input_buffer_size" to 16384 and it made no difference that I could tell, which I suppose kills the "buffer overrun" theory.

[karnevil9]

Ping?

[ravelox]

Ping?

Yes, still here.

At the moment, I'm theorising that the issue is related to the fact that the MIDI events are not sent until the whole buffer has been parsed. I'm working in a new branch to introduce a new queueing thread that is solely there to send events so that as soon as a MIDI command is parsed, it gets sent.

Threads, memory allocations and acquiring/releasing context data is what I'm wrestling with at the moment. I have a framework in place, I need to test it.

Thanks

Dave

[ravelox]

I've checked in my changes to the 'queue' branch and thrown at least 1 Pet Shop Boys MIDI file at it to check for any crashes and memory leaks. Please check out that branch and let me know if that has any effect on the timing.

Thanks

Dave

[ravelox]

I've completed my testing. I've made some tweaks to reduce some mutex locking and also added a config option journal.write to enable or disable whether the MIDI journal is written to the RTP packet. Additionally, I made some debugging changes to track memory allocation to ensure that there are no leaks.

Please take a look at the queue branch and let me know.

[ravelox]

If there are no issues, I'm going to merge these changes into the master branch and release 0.10.0.

[karnevil9]

Looking at this now…

[karnevil9]

Following the directions at https://blog.tarn-vedra.de/pimidi-box/, at the step:

sudo raveloxmidi -dN -c /etc/raveloxmidi.conf

I am getting the following repeating message:

[1597982125.901445] [tid=3069251600] ERROR: ring_buffer_write: Insufficient space available in buffer

And unsurprisingly, it is very jittery.

[ravelox]

How are you testing this? The default ring buffer size is 10K so, if you're getting that error message it typically means that raveloxmidi is reading a large amount of data being sent down the pipe and filling the ring buffer before it can be drained.

There's another code change I can make to process the each chunk as it's read instead of waiting until all the data has been received. However, there is a setting "read.ring_buffer_size" which you can change. Could you change that to something large like 1M ( read.ring_buffer_size = 1048576 ) and test again?

Thanks

Dave

[ravelox]

Did changing the ring buffer size make any difference?

Thanks

Dave

[karnevil9]

Hi Dave,

I'm testing this on a MacBookPro 13" (2020) running Mainstage. Ravelox is running on a Pi Zero W. I have a Korg nanoKEY Studio plugged into the Pi via USB, and am using the nanoKEY's arpeggiator to generate putatively evenly spaced notes.

I'm posting video of the results (to Vimeo; too big for Github, apparently), both before making the modification to the buffer size and after. The "before" case is pretty bad, and you can see what looks like a buffer overrun is occurring. The "after" case is much improved, but still a bit jittery.

Video is at https://vimeo.com/451732379

(I really appreciate the work you're doing BTW, would love to help out any way I can.)

[ravelox]

So...we're going for the nuclear option here :)

The code currently reads the input from the ALSA device using a 4K input buffer size by default. This means if there is 4K worth of data, it will read it store it in the ring buffer and then read 4K more until there is no more data in the pipe. At that point, it will process the data that has been input.

What I've done now is to remove the loop around that read routine so that there is only 1 read done before the buffer is handed off.

That's all relevant because, if you set alsa.input_buffer_size = 1, the buffer will be processed on each byte meaning as soon as a MIDI command has been found, it will be sent out without needing to read all the data in the pipe. That's a further improvement on what I did earlier where I read all the data first and, during processing, if the a MIDI command is found, it's added to the sending queue.

I've checked in the change to the queue branch so could you check it out and run without the ring_buffer_size config option ( it shouldn't be need now ) but with alsa_input_buffer_size = 1.

If that shows an improvement, I can set the default input_buffer_size to be 1.

Thanks

Dave

[karnevil9]

Here's what my config file looks like now:

alsa.input_device = hw:1,0,0
network.bind_address = 0.0.0.0
logging.enabled = yes
logging.log_level = normal
service.name = midibridge-wifi
alsa_input_buffer_size = 1

And raveloxmidi --info reports

[1598592696.180497] [tid=3069964304] INFO: raveloxmidi (0.10.0.389-queue)

I am still getting buffer overruns (?) and poor timing, though not immediately.

[1598591625.779305]	[tid=3069599760]	WARNING: applemidi_by_responder:No existing connection found
[1598591642.487324]	[tid=3069599760]	ERROR: ring_buffer_write: Insufficient space available in buffer
[1598591642.515992]	[tid=3069599760]	ERROR: ring_buffer_write: Insufficient space available in buffer
[1598591642.536127]	[tid=3069599760]	ERROR: ring_buffer_write: Insufficient space available in buffer
[1598591642.581570]	[tid=3069599760]	ERROR: ring_buffer_write: Insufficient space available in buffer
[1598591642.587707]	[tid=3069599760]	ERROR: ring_buffer_write: Insufficient space available in buffer
[1598591642.610007]	[tid=3069599760]	ERROR: ring_buffer_write: Insufficient space available in buffer

Hoping to mess around some more with this on Saturday.

[ravelox]

Hi, the setting is alsa.input_buffer_size. You have a typo there.

Thanks

Dave

[karnevil9]

That’s a relief! I copied that from your last comment.

Will try again this evening.

[karnevil9]

I'm still getting the same results.

Here's my corrected config:

alsa.input_device = hw:1,0,0
network.bind_address = 0.0.0.0
logging.enabled = yes
logging.log_level = normal
service.name = midibridge-wifi
alsa.input_buffer_size = 1

And here are the first couple of error messages:

[1598669506.428429]	[tid=3069304848]	ERROR: ring_buffer_write: Insufficient space available in buffer
[1598669506.444780]	[tid=3069304848]	ERROR: ring_buffer_write: Insufficient space available in buffer

[karnevil9]

Are you in the Bay Area? I'd like to send you a nanoKEY Studio (the device I'm using to generate a MIDI stream in my tests) if that might help.

[karnevil9]

Should CPU utilization be so high?

[ravelox]

No, it shouldn't be using that much CPU and I can see it's like that when idle. Gprof is showing that it's spending time in the loop that checks if MIDI messages are in the queue to be sent. I can use pthread condition variables to control this but it'll take a bit of time to get that together.

Thanks

Dave

[ravelox]

I've checked in a number of changes. One observation I have is that using a Pi Zero seems to be worse than using a Pi 4. I'm starting to think it might be a limitation of the hardware. The same code works better on more powerful models.

[vldp2000]

Hi guys, I've already gave up on RPi Zero for my project where RaveloxMidi plays the main role.
I'm using RPi 2 now which has multi-core processor but not as power hungry as RPi 4.
It resolved a lot of my issues 👍

Thank you Dave!

[ravelox]

Are you in the Bay Area? I'd like to send you a nanoKEY Studio (the device I'm using to generate a MIDI stream in my tests) if that might help.

I was sure I'd replied to this. Yes, I'm in the Bay Area. If you send an email to github ( at ) ravelox (dot) co ( dot ) uk, we could work out how to arrange this.

Thanks

Dave

[ravelox]

Hi guys, I've already gave up on RPi Zero for my project where RaveloxMidi plays the main role.
I'm using RPi 2 now which has multi-core processor but not as power hungry as RPi 4.
It resolved a lot of my issues 👍

Thank you Dave!

That kind of makes sense as there are a number of threads in raveloxmidi that would be contending for resources on a single-core CPU.

[karnevil9]

About the suitability of a PiZero: it's possible that a Zero hasn't the muscle required, but early on I looked at how much CPU was being used and it was actually quite low. On the other hand, the core-count observation is a good one.

I'll try the newest fixes and report back.

[karnevil9]

Hi Dave,

I'm not seeing anything new available. Are the changes live?

[ravelox]

I'm not seeing anything new available. Are the changes live?

The last changes I made were a couple of weeks ago but after your last post in this thread so I'm not sure if you'd been checking them out.

They're in the queue branch.

Thanks

Dave

[karnevil9]

Ok, CPU utilization is down to under 12%, but I still get buffer overruns.

I've tried setting alsa.input_buffer_size to 1, 4096, and leaving it undefined in the config but the buffer overruns still occur.

[1600583794.872625] [tid=3069497360] ERROR: ring_buffer_write: Insufficient space available in buffer

I added the following line to the ring_buffer_write(...) function, at line 156 in ring_buffer.c:

logging_printf( LOGGING_ERROR, "len: %d, ring->used: %d, ring->size: %d\n", len, ring->used, ring->size);

It looks like there are three buffers. One of them is never emptied but keeps getting three bytes added, and that's responsible for the eventual overrun messages. It seems unrelated to what the controller is actually doing, I don't even have to play anything on the keyboard.

Here's an excerpt of what I see, just as one of the buffers overflows:

[ravelox]

Interesting observation. I'll take a look but what confuses me is that I can use something like aplaymidi with a MIDI file and send it on to Logic with none of the reported problems you have. You're definitely exercising the code paths in ways I can't :)

[ravelox]

I've added some more debugging statements into the ring buffer code so that I can see which buffer is causing the problem. Can you check out the code and test again and then paste the full output?

Thanks

Dave

[karnevil9]

Here you go. The trouble seems to start when I connect to the Pi from my MacBook (see attached screen recording where one of the buffers' "used" number starts to climb once I've connected).

log.txt
troubleEdit720.mov.zip

[ravelox]

Thanks for that. The buffer in question is the inbound connection from the Macbook to raveloxmidi.

There are 2 types of data that should be coming over that connection. Neither type should be 3 bytes in length.

Firstly, it can be the AppleMIDI commands. These are prefixed with 0xff 0xff and I have code that handles that.
Secondly, it can be RTP MIDI data. There is no prefix but the code assumes that if it's not AppleMIDI (0xff 0xff) then it must be RTP MIDI.

Problem is, 3 bytes is way too short for that to be RTP MIDI data. Even if it was the header for RTP MIDI, that's bigger.

So, there's a case where this isn't being handled so well and the input buffer is never drained.

What I'll need to see is a packet capture for the network communication from the Macbook. If you're OK with doing this, the command to run should be:

sudo tcpdump -s 0 -w /tmp/packet.trc -i any host ip.addr.of.macbook &

then run your test again. Once you're done, please attach /tmp/packet.trc

Thanks

Dave

[ravelox]

I should have added that I'm assuming that the AppleMIDI commands are being handled OK because MacOS will report that the connection is lost if it doesn't get a response from raveloxmidi within a certain time and you haven't indicated that you see that behaviour.

[karnevil9]

I’m away from my rig for a few hours but I’ll try to get to this tonight. The connection to my Mac does seem stable. No unexpected disconnects.

[karnevil9]

Looks like I won't get to it tonight. I'll try tomorrow night.

[karnevil9]

I sent a packet trace to your email address.

[ravelox]

Acking receipt of the packet capture.

I can see that the Mac is sending Timing Clock MIDI events. Can you remind me what you have listening on the Mac side? If there is no output ALSA device, those MIDI events go into the ether and it's possible that I am not draining the buffer at that point but I'd like to confirm that if I can.

I use Logic Pro X and don't immediately see how to have the Timing Clock messages get generated.

[ravelox]

Scratch that. I found a way of generating the problem. Now the fun starts :)

[ravelox]

OK...here's the science bit :)

For inbound MIDI over RTP, multiple connections communicate over the same socket and I can't determine which connection is sending the data until I read from the socket.

So...

I use the same code to avoid repeating myself and the input data from the socket is read into a MIDI state machine with an underlying ring buffer, that data is drained from the buffer and parsed to determine which connection is sending the data and the MIDI payload in the RTP data is transferred to a 2nd MIDI state machine specifically for that connection. This is necessary because partial data could have been read previously and we need to keep state for each connection.

The bug was that I was draining the socket data and writing to the correct connection buffer BUT when it came to parse that data, I was referencing the socket data buffer which was empty. So the parsing routines had nothing to do AND never drained the connection-specific buffer. Hence it got filled.

This only affects inbound MIDI data over RTP. In most cases, people have been sending one way but you had specific options set on the Mac side to send Timing Clock MIDI commands.

I've checked in the (1-line) change to the queue branch. Please check it out and test again.

Thanks

Dave

[karnevil9]

I am using Logic Pro as well. I do remember adjusting some clock settings in Logic for an unrelated project, but can't remember where. I can confirm that the buffer "used" number stops going up when I quit Logic, so it does seem that Logic is the source of the bytes.

I'll download the latest tonight and try again.

[karnevil9]

Oops, scratch that. Even without Logic running, that 'used' number is going up. I don't know what the source of the mystery bytes could be.

[karnevil9]

That seems to have fixed the buffer overrun problem! It's a lot more stable now. I do hear some jitter now and then but it is much improved and more episodic. It's certainly very usable for just playing by hand.

The jitter I'm hearing tends to correspond to spikes in latency as displayed by the "MIDI Network Setup" window in "Audio MIDI Setup". No idea if that's a symptom or a cause. Normally, latencies are between ~2 and ~15 ms. But every now and then it spikes to over 50 and you can definitely hear that.

I have Raspberry Pi A on order which has two cores. Curious to see how the extra core affects things.

[ravelox]

I've merged all the changes from queue into master as v0.10.0