krevis / MIDIApps

MIDI apps for Mac OS X: MIDI Monitor and SysEx Librarian.
http://www.snoize.com/
BSD 3-Clause "New" or "Revised" License
714 stars 112 forks source link

MIDI Monitor first-message latency #118

Open aolsenjazz opened 1 month ago

aolsenjazz commented 1 month ago

Thanks for building and making these apps free + open source.

MIDI Monitor spy-on functionality has a bug where it reports an incorrect timestamp for receipt of MIDI messages. Below are the steps to recreate:

I hope that accurately communicates the issue. Note that as more messages are sent, the delay increases - seemingly maxing out around 30ms. Tested CoreMIDI separately to ensure this wasn't a CoreMIDI issue. The easiest way to reproduce this might be using my app, Mimic (not trying to shill, but I made something to debug these problems).

14 inch Macbook pro 2023, M2 max, Ventura 13.3.1

krevis commented 1 month ago

I'll try to repro, but a few questions while you still have this set up:

  1. What happens if you turn on "expert mode" in the MIDI Monitor settings? Are the timestamps shown as numeric values, or are they zero?
  2. In the original MIDI messages that you send to the virtual port, are you specifying a specific timestamp in each MIDIPacketList, or are you just leaving it zero (meaning "send now")?

CoreMIDI timestamps are not terribly reliable, in general. The "zero means now" issue is the tip of the iceberg. In general timestamps get passed through the system as-is most of the time (especially when no hardware device is involved), so zero or nonsense values won't get corrected by the system.

MIDI Monitor's "spying" MIDI driver does not currently do any processing of timestamps itself. It just passes through whatever CoreMIDI tells it, which might be zero or nonsense depending on what the sending app put in.

In the MIDI Monitor app, I found that people got very confused by seeing zero timestamps, so by default if it sees a zero timestamp it will substitute the time when we parse the incoming MIDI stream and construct a Message. That's not great -- as you noticed, it will be a few ms later than when the originating app sent it, depending on exactly how long all that IPC takes and when the parsing thread gets scheduled -- but it's better than nothing. You can always turn on "expert mode" to disable that, and you'll see exactly what CoreMIDI tells us.

I suspect that's the path you're hitting, based on the symptoms you describe, but I'd have to dig into it.

krevis commented 1 month ago

(Arguably, the spying driver should capture a timestamp when it receives each MIDIPacket, and should attach that to the data sent to the app, along with the original timestamp that CoreMIDI provided. Then we would have a closer-to-reality, or at least earlier, timestamp to show to most users, and also allow experts to see the original timestamp. But the thing is, that timestamp doesn't really reflect reality any better -- it's always going to be after the originating app sent the message to CoreMIDI, and before any app would be able to receive the message.)

aolsenjazz commented 1 month ago

Thanks for looking into this so quickly!

  1. With expert mode on, timestamps for messages received from the Mimic-created virtual port are HH:mm:ss:fff, while timestamps to to the Mimic-created virtual port (spy-on port) are 0.
  2. I'm setting time to 0, fwiw: outPacket = MIDIPacketListAdd(outPacketList, sizeof(buffer), outPacket, 0, packet.length, packet.data);

I think the disconnect here is that spy-on reports a 30-ms delay only after a certain amount of time has elapsed, and only after processing a number of messages , whereas the actual virtual MIDI port receiving the message reports <1ms. Implicit in this is that the delay grows as more messages are transmitted. I wish I knew more about CoreMIDI or OS-level thread prioritization to suggest what might be going on.

I'll put together a repo with the C++ script I'm using, as well as instructions to reproduce tomorrow. Realistically, this is only affecting nerds like me who sweat over milliseconds.

Thanks again!

aolsenjazz commented 1 month ago

Here is the repo to test. It's got a quite a few steps, so thanks for bearing with me.

Let me know how else I can help to figure this out.

krevis commented 1 month ago

Thanks, will take a look when I can.

By the way, why are these particular timestamps so important to you? What, precisely, are you trying to measure?

(I'm asking because the "spy" feature is only a MIDI Monitor thing, so it has no direct relation to anything that any other app would see.)

From your earlier message, it looks like the "spy" is seeing the zero timestamp that you put in the original packet. You might try putting your own timestamp in there, and see if it gets passed through as-is -- I suspect it will be. If so, you could just specify a timestamp of AudioGetCurrentHostTime() which would give you the current time. Then MIDI Monitor would let you easily compare the "spy" events, which would show the time that you created the packet list, to the timestamp that CoreMIDI put on the events when they were sent to other apps.

(But note that the timestamp CoreMIDI put on the events is somewhat arbitrary. I suspect it's the time when the CoreMIDI server processes the event. If that's the case, any app receiving the event won't see it until a little bit afterwards. It's up to you whether you care about that.)

aolsenjazz commented 1 month ago

I was working on a MIDI translator, testing a new plugin design. Wanted to make sure latency was still < 1 ms for basic translation+propagation. To test this I used MIDI Monitor and found the delay, which led to testing all layers and eventually ending up here.

Will test w/AudioGetCurrentHostTime(). If I'm understanding your last paragraph correctly, you're saying that the timestamp passed by CoreMIDI represents its time of processing? Is this the timestamp being display in Monitor? If so, I'm not certain that the situation you illustrate is happening, since my virtual ports are receiving the messages before CoreMIDI would have processed it.

As I alluded to before, I was using this to benchmark my own software. I realize this is far from the intended use case for most people using this app.