[BUG] midi.exe received(or showed) wrong UMP event

[dmiura]

Applies To midi.exe(or MIDI services?)

Describe the bug midi.exe received(or showed) wrong UMP event. This is similar but different issue from #174.

To Reproduce We are using ProtoZOA with following firmware. https://github.com/midi-mma/Amenote_Protozoa/blob/main/Releases/V0.4/ProtoZOA_Main.uf2 ZoA_UUT.uf2.zip (When "5" button on ProtoZOA, it will send UMP message(Note On) with 500usec interval, "3" means 300usec.)

When ProtoZOA sends continuously UMP MIDI 2.0 Note On messages with interval e.g. 500usec, then it seems that some scheduled messages appeared different UMP event, around 100,000 messages as following screen shot. It shows "###### HR" and shows unexpected UMP events in after "###### HR", probably those are old events which USB MIDI 2.0 Driver received previously.

[Psychlist1972]

Thanks.

[dmiura]

We've confirmed with Developer Preview 3(Worked Around https://github.com/microsoft/MIDI/issues/182 also related to message scheduling), same issue still occurred in our environment.

[Psychlist1972]

@dmiura If you are seeing this on Developer Preview 3, it's unrelated to message scheduling. Scheduling is bypassed in DP3

Edit: Actually, given that this is an incoming message from USB, scheduling would never be involved anyway.

I can't reproduce this with any of the commercial MIDI devices I have or the loopback endpoints. Can you reproduce this with anything other than the protozoa?

[Psychlist1972]

@garydan42 is it possible that the circular buffer (either the one connected to USB or the one connected to the client) is wrapping around here and resulting in this? I know you've taken pains to ensure that doesn't happen, but I can't think of how else this might happen.

[m-komo]

@Psychlist1972 @dmiura

This issue could be reproduced on Roland side with DP3.

I also checked USB log and verified that the messages sent from the device were no problem.

As you can see in the attached screen captures, unexpected UMP messages appear to be just 512 messages ago. As far as I remember, the size of the buffer between MIDIService and API/Driver was 4KB, so it can store 512 MT4 messages. I'm not sure but the symptoms may change if you change the buffer size.

[Psychlist1972]

@garydan42 @AmeNote-Michael I've never run into this with the loopbacks, however, so either it's not a client (app<->service) xproc buffer issue, or timing is a component. Is it possible this is related to the messages being put into the buffer from the driver and that queue?

[Psychlist1972]

I'm running the same firmware on protozoa and haven't had the out of order messages yet, but I do see what I assume are dropped messages (the second word is not incrementing by 0x1 each time). It started off fine, but higher numbers seem to skip.

(Note, I was capturing to file at the same time, so the latency is higher. Just filed a bug on that)

protozoa-2024-01-15.midi2.txt

As I recall, dropped messages are expected if the client can't keep up with the incoming stream, but these aren't coming fast enough for me to think that's the problem here.

[Psychlist1972]

Some more detail.

1. I'm not getting old messages or anything out of order. Not sure how to repro that. Is this with the current attestation-signed driver from December?

2. Messages are all arriving around 700us apart for me, no matter if I press "3" or "5" on the protozoa. I originally thought that was due to capturing to file, but normal monitoring looks the same. I'm not sure what the difference is there, but it could be a factor.

3. After around that 500 or so messages, I do start to see skipped messages. I am not sure yet if they are being skipped between the driver and device, the driver and service, or between service and client. Restarting the service fixes this, but that resets pretty much everything when you do that.

[Psychlist1972]

Edit: Ignore conclusions below. I changed the buffer size back to PAGE_SIZE, rebuilt the service, and I'm still getting 300us between messages and nothing skipped. Not sure what's going on here and why the issues before. The rest of the running code is the same. I had previously restarted the service in case that was it, but nothing. Requires more investigation.

---

Original message:

Interestingly, I changed the client buffer size in MidiSrv from 4096 bytes to 512 bytes and the messages are now all coming in at around 300us. The larger buffer was 2x slower. I recall Gary mentioning that possibility in the past.

So far, I'm not seeing any skipped messages, and still no out-of-order timestamps.

I do get bursts of faster messages from time to time. I'm guessing that there's a pile-up and wait somewhere and then in the next timeslice they can all be sent?

But nothing out of order

The downside of small buffers is that messages will be more easily lost if the client or device can't keep up, and there isn't code in there that will wait until the queue frees up.

[Psychlist1972]

Finally had a message displayed out of order. Given that the text at the bottom says no messages were received out of order (that's checked in the background thread handling incoming messages), and this is strangely at the last message, AND the index is old, this looks to be a display issue. I'll look into it more. Difficult to repro this, though.

[Psychlist1972]

I didn't notice in the earlier screen shots that the index was also out of order. The index is generated in midi.exe.

So, been a long way around saying this is a problem in my code :)

The dropped messages are something else, however. I haven't been able to repro that now, which is annoying.

[Psychlist1972]

I've made some significant performance changes to the console monitor. However, I cannot repro this specific issue at will to know if it will address it or not.

I can say that if I press "1" on the ProtoZoa, I get messages that are all around 100 microseconds from message to message (there's definite jitter there, but it's in the +/- tens of microseconds) and I haven't had any dropped messages or messages received out of order.

If this fixes the issue, the problems were all in the display, not in the data path between the service and the client. However, again, I can't repro the original problem at will, so I will await your feedback once you try this change.

Can you try this release preview, please, @dmiura @m-komo ?

https://github.com/microsoft/MIDI/releases/tag/dev-preview-4-daily1

[m-komo]

@Psychlist1972 I have tried to install DP4 after uninstalling DP3, but I couldn't. Setup failed with the error below:

Any advice?

[Psychlist1972]

@Psychlist1972 I have tried to install DP4 after uninstalling DP3, but I couldn't. Setup failed with the error below:

Any advice?

It's presumably because a component didn't register during install. I've only see this when something stuck around from before. May need to do a manual cleanup. Sorry about that.

1. Ensure you don't have the console app actively monitoring an endpoing. If you do, exit it.

2. Uninstall the previous release from Apps > Installed Apps in Settings.

3. After that, check the Windows Services Console (search->Services) and see if "Microsoft MIDI Service" is still listed. If it is, right-click it and choose "Stop"

4. Then go into %ProgramFiles%\Windows MIDI Services and if it exists, delete all three subdirectories. (Will require administrator permission)

Those steps should clear up anything that was lingering around.

5. Re-run the latest installer.

[m-komo]

@Psychlist1972 Thank you for your suggestion. In my case, there is no installed MIDI Service, no running service and no installed files under %ProgramFiles%. However, the installer still fails. But it's okay, I will re-install windows. It may take an hour, but for me it's not a pain. ;-)

[Psychlist1972]

@Psychlist1972 Thank you for your suggestion. In my case, there is no installed MIDI Service, no running service and no installed files under %ProgramFiles%. However, the installer still fails. But it's okay, I will re-install windows. It may take an hour, but for me it's not a pain. ;-)

Oh! Sorry. I do hope it works after you reinstall. I'll be up for a couple more hours if you need anything.

[Psychlist1972]

@Psychlist1972 Thank you for your suggestion. In my case, there is no installed MIDI Service, no running service and no installed files under %ProgramFiles%. However, the installer still fails. But it's okay, I will re-install windows. It may take an hour, but for me it's not a pain. ;-)

Andrew also mentioned having issues with the install from this one. I'm testing in a VM now, and assuming there's something broken in the installer, I'll put out an update.

[Psychlist1972]

@m-komo

It was a bad installer file. I'm so sorry.

Updated installer here https://github.com/microsoft/MIDI/releases/tag/dev-preview-4-daily1

[m-komo]

@Psychlist1972

Thank you for updating the installer. I successfully installed it on my PC.

Then I checked whether the issue persists and there were no out of order messages. It seems the issue has been solved.

However, the message displayed by the monitor command is very slow. The device sends a message every 500 microseconds, so you should have received 10,000 messages after 5 seconds. But the message displayed on the monitor was about 300 messages.

Is this a limitation due to this fix?

[dmiura]

@Psychlist1972

We've installed updated installer and confirming the issue again. As m-komo commented, monitor command is very slow...

Finished 100,000 messages transmit, it seems that there is no wrong value, but need to check several times.

[Psychlist1972]

@Psychlist1972

Thank you for updating the installer. I successfully installed it on my PC.

Then I checked whether the issue persists and there were no out of order messages. It seems the issue has been solved.

However, the message displayed by the monitor command is very slow. The device sends a message every 500 microseconds, so you should have received 10,000 messages after 5 seconds. But the message displayed on the monitor was about 300 messages.

Is this a limitation due to this fix?

There's a limit as to how fast messages can be output to the console. It should be much faster than in the past, but I didn't test overall time. I'll look at overall timing next.

[Psychlist1972]

@dmiura @m-komo

I will look at further ways to optimize the console output speed. There's a limit as to how much can be done there, though.

However, because I had separated capture from display, I was able to add to the summary some information that shows me that the actual messages are being received in time, even if the display isn't keeping up.

That is from pressing "5" on the protozoa. This is from pressing "3"

[Psychlist1972]

Bit of a breakthrough here. By splitting out some steps to yet another thread, I was able to get the console to be within 5 or so messages being displayed vs captured.

[Psychlist1972]

@dmiura @m-komo

Please let me know if https://github.com/microsoft/MIDI/releases/tag/dev-preview-4-daily2 fixes this for you. I'll hold off on closing it as complete until then.

[m-komo]

@Psychlist1972

I checked the DP4 daily2. I confirmed that the performance of console output is good and no out of order messages are displayed. Thank you!

[Psychlist1972]

@Psychlist1972

I checked the DP4 daily2. I confirmed that the performance of console output is good and no out of order messages are displayed. Thank you!

Great, thank you!

@dmiura let me know if you also concur, in which case, I will close this bug as fixed.

[dmiura]

@Psychlist1972 @m-komo

We checked DP4-daily2, it was succeeded 100,000 messages transmit with 500usec interval, unfortunately, second transmitting was failed.

We tried several sets of 100,000 messages transmitting, result is as below. 1st transmitting: succeeded. 2nd transmitting: not succeeded, 15 messages were lost. 3rd transmitting: about 40% messages were lost, and receive duration became approximately 1000usec.

We'll check again tomorrow.

[dmiura]

@Psychlist1972 Do we need to install everything(OS, Developer Preview, etc) from scratch for testing? We assume that something cache remained in our environment...

[m-komo]

@Psychlist1972 @dmiura

I've never seen this phenomenon "missing messages" with the 500usec interval, but it could be reproduced with the 100usec interval on my PC.

[Psychlist1972]

@Psychlist1972 Do we need to install everything(OS, Developer Preview, etc) from scratch for testing? We assume that something cache remained in our environment...

Not in my experience, no.

[Psychlist1972]

@Psychlist1972 @m-komo

We checked DP4-daily2, it was succeeded 100,000 messages transmit with 500usec interval, unfortunately, second transmitting was failed.

We tried several sets of 100,000 messages transmitting, result is as below. 1st transmitting: succeeded. 2nd transmitting: not succeeded, 15 messages were lost. 3rd transmitting: about 40% messages were lost, and receive duration became approximately 1000usec.

We'll check again tomorrow.

This is all good information. Thank you. I will look into it.

During this test, did you use Control-C to end the console at all, or did you always use Escape? In the former case, the process is killed and the service buffers do not get cleaned up per #221

[Psychlist1972]

(Note that you don't need to use --verbose for the tests. The data will fit on your screen better without it :))

[Psychlist1972]

Incorrect data is no longer being received, so closing this issue.

I've created a new issue to track the missing message problem. See #227

[dmiura]

@Psychlist1972

During this test, did you use Control-C to end the console at all, or did you always use Escape?

We used Control-C after 2nd transmitting before 3rd transmitting.

[Psychlist1972]

@Psychlist1972

During this test, did you use Control-C to end the console at all, or did you always use Escape?

We used Control-C after 2nd transmitting before 3rd transmitting.

Thanks. Note that if you control-C or crash a client app, you usually need to restart the service for things to work reliably. That's not the cause of the skipped messages, but it can cause hang-ups. #221