PortMidi / portmidi

portmidi is a cross-platform MIDI input/output library
Other
116 stars 31 forks source link

Double the number of packets received compared to MIDIMonitor and not returning SystemReset messages #31

Closed StewMacLean closed 2 years ago

StewMacLean commented 2 years ago

Hi Roger, been working on my midi parser and I've noticed that I'm receiving messages that have been sent by Logic, twice - in two separate instalments. Initially I thought it might have been the way I was calling PortMidi. I tried the polling read and the regular read (the docs say not to use the Polling).

So I put some tracing in to establish that in fact PortMidi is returning double the number of packets, in two lots.

Please see attached: 1) Trace from PortMidi in debug mode and also showing the number of packets returned. The total is 80. 2) What is received by Pharo from Pm_Read. The total is 80. 3) Screenshot of MIDIMonitor output. The total is 20 = 40 sys ex packets, combined.

Also note that the System Reset messages are not being presented by PortMidi.

FYI, this is bumph that Logic returns when hooking up to a Control Surface.

Happy to conduct further tests if required. Thanks

M1, Monterey, Pharo Smalltalk

PortMidi debug log and tracing. 80 packets.rtf.zip

Received by Pharo 80 packets Midi monitor 20 SysExs
rbdannenberg commented 2 years ago

The first thing I would do is use the PortMidi midi monitor (mm) program and see what output you get, just to eliminate any question about your interface to portmidi. If you can do that, let me know. Then I can compare results with Logic + mm on my x64 machine.

I read the code in pm_mac/pmmacosxcm.cm that parses RESET (0xFF), and it seems no different from other messages like MIDI_START (0xFA).

StewMacLean commented 2 years ago

I've dug a bit deeper... I tried using the PortMidi midi monitor, but I can't configure the port until it is created, and the messages are arriving as the port is created, as is shown by the trace below. I've logged the actions that the application is doing and it shows that two lots of the same messages are returned. Once on opening the input port, as you would expect, and once on opening the output port, which is not what I'd expect. I hope this is a clue!

The good news is, that once start up is complete, I receive messages as expected :)

Oh, and the System Resets are a total mystery - they actually occur on library shutdown, and I don't know where they are coming from - they're not in the Logic output log (which is not to say that it's not outputting them...). PortMidi doesn't present them, cause the library is closed by this stage.

About to initialize library...

driver com.apple.AppleMIDIIACDriver driver com.apple.AppleMIDIIACDriver driver driver driver com.apple.AppleMIDIIACDriver driver com.apple.AppleMIDIIACDriver driver driver

About to create input port:

About to open input port:

read_callback: numPackets 1: read_callback packet @ 100691652980416 ns (host 2416599671530) status b9 length 6 packet->timeStamp 0 ns 0 host len 6 stat b9 read_callback: numPackets 1: read_callback packet @ 100691653950083 ns (host 2416599694803) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 Pm_Read returning 4 packets read_callback: numPackets 1: read_callback packet @ 100691654147416 ns (host 2416599699538) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 Pm_Read returning 2 packets read_callback: numPackets 1: read_callback packet @ 100691654449000 ns (host 2416599706776) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100691654454083 ns (host 2416599706899) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100691654754750 ns (host 2416599714114) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100691654781958 ns (host 2416599714767) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655071416 ns (host 2416599721715) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655076791 ns (host 2416599721843) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655370333 ns (host 2416599728889) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655374333 ns (host 2416599728984) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655660125 ns (host 2416599735843) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655665375 ns (host 2416599735970) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655949083 ns (host 2416599742778) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100691655953833 ns (host 2416599742892) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 2: read_callback packet @ 100691656239083 ns (host 2416599749738) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 packet->timeStamp 0 ns 0 host len 8 stat f0 Pm_Read returning 28 packets read_callback: numPackets 1: read_callback packet @ 100691656563125 ns (host 2416599757515) status f0 length 6 packet->timeStamp 0 ns 0 host len 6 stat f0 read_callback: numPackets 1: read_callback packet @ 100691656965166 ns (host 2416599767165) status f0 length 5 packet->timeStamp 0 ns 0 host len 5 stat f0 read_callback: numPackets 1: read_callback packet @ 100691657303333 ns (host 2416599775281) status f0 length 6 packet->timeStamp 0 ns 0 host len 6 stat f0 read_callback: numPackets 1: read_callback packet @ 100691657671500 ns (host 2416599784116) status f0 length 5 packet->timeStamp 0 ns 0 host len 5 stat f0 Pm_Read returning 8 packets

About to create output port:

About to open output port:

midi_out_open isIACdevice 0 read_callback: numPackets 1: read_callback packet @ 100692066653250 ns (host 2416609599679) status b9 length 6 packet->timeStamp 0 ns 0 host len 6 stat b9 read_callback: numPackets 1: read_callback packet @ 100692067647500 ns (host 2416609623540) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 Pm_Read returning 4 packets read_callback: numPackets 1: read_callback packet @ 100692067892500 ns (host 2416609629420) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692068191958 ns (host 2416609636608) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692068234333 ns (host 2416609637624) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692068466291 ns (host 2416609643192) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692068477375 ns (host 2416609643457) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692068778083 ns (host 2416609650674) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692068783791 ns (host 2416609650811) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692069132708 ns (host 2416609659186) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692069154291 ns (host 2416609659704) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692069378375 ns (host 2416609665082) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692069401958 ns (host 2416609665647) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692069678791 ns (host 2416609672291) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692069700833 ns (host 2416609672821) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692070029458 ns (host 2416609680708) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 100692070122875 ns (host 2416609682949) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 100692070313083 ns (host 2416609687515) status f0 length 6 packet->timeStamp 0 ns 0 host len 6 stat f0 Pm_Read returning 32 packets read_callback: numPackets 1: read_callback packet @ 100692070700500 ns (host 2416609696813) status f0 length 5 packet->timeStamp 0 ns 0 host len 5 stat f0 read_callback: numPackets 1: read_callback packet @ 100692070982625 ns (host 2416609703583) status f0 length 6 packet->timeStamp 0 ns 0 host len 6 stat f0 read_callback: numPackets 1: read_callback packet @ 100692071310916 ns (host 2416609711462) status f0 length 5 packet->timeStamp 0 ns 0 host len 5 stat f0 ***** Pm_Read returning 6 packets

About to finialise library:

got close request packet

rbdannenberg commented 2 years ago

I'm not sure what you are expecting. If the sender creates a new port and sends to it immediately, I would not expect any program to be able to receive everything reliably. My mental model is a virtual port is like a hardware port: First you install it, then you connect a cable from the output port to an interested destination (MIDI input port), then after the connection is made you can send from source to destination. Closing ports is tricky: I think we don't want a disappearing virtual port to disturb an application, so I'm pretty sure PortMidi abstraction allows the "stream" to stay open even when the source is removed. The receiver can continue to poll for input, but of course there will not be any input after the source is closed (even if a new source is created, PortMidi does not actively discover and reconnect). If the receiver closes the input stream and tries to reopen, the open operation will now fail because the virtual port no longer exists.

StewMacLean commented 2 years ago

Hi Roger, actually it is behaving as expected, once you take into account that PortMidi is splitting packets returned by the CoreMIDI read callback into structures of size 4 bytes. So each of these SysEx packets are being split into two structures (application packets). So in the output below there are 20 OS packets, which are returned as 40 PortMidi structures/packets.

I'm guessing this is by design in order to provide cross platform portability, but I'm wondering if it would be possible to have a Mac OS specific api to register a callback and receive the OS packets in their entirety. This would also avoid chewing cpu cycles whilst polling.

The library would still be cross platform, but with the option of using a platform specific read via callback.

Thanks for helping me clarify this. The other thing that was confusing me, is that Logic sends two sets of initialisation messages - one for when it detects the new input port, and one when it detects the output port - hence receiving another bunch of messages after the output port opens.

With regard to opening/closing of ports, interestingly once the virtual port names have been configured in Logic it "reconnects" with the application's virtual ports if you leave them open when restarting Logic. This is a good thing!

About to open input port:

read_callback: numPackets 1: read_callback packet @ 154434145062625 ns (host 3706419481504) status f0 length 5 packet->timeStamp 0 ns 0 host len 5 stat f0 read_callback: numPackets 1: read_callback packet @ 154434145132166 ns (host 3706419483173) status f0 length 6 packet->timeStamp 0 ns 0 host len 6 stat f0 read_callback: numPackets 1: read_callback packet @ 154434145216875 ns (host 3706419485206) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 154434145256541 ns (host 3706419486158) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 154434145308250 ns (host 3706419487399) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 3: read_callback packet @ 154434145317833 ns (host 3706419487629) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 packet->timeStamp 0 ns 0 host len 7 stat f0 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 3: read_callback packet @ 154434146776541 ns (host 3706419522638) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 packet->timeStamp 0 ns 0 host len 8 stat f0 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 1: read_callback packet @ 154434146790333 ns (host 3706419522968) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 154434146824625 ns (host 3706419523792) status f0 length 7 packet->timeStamp 0 ns 0 host len 7 stat f0 read_callback: numPackets 5: read_callback packet @ 154434146832166 ns (host 3706419523973) status f0 length 8 packet->timeStamp 0 ns 0 host len 8 stat f0 packet->timeStamp 0 ns 0 host len 7 stat f0 packet->timeStamp 0 ns 0 host len 8 stat f0 packet->timeStamp 0 ns 0 host len 7 stat f0 packet->timeStamp 0 ns 0 host len 8 stat f0 read_callback: numPackets 1: read_callback packet @ 154434146881583 ns (host 3706419525159) status f0 length 5 packet->timeStamp 0 ns 0 host len 5 stat f0 Pm_Read returning 38 packets read_callback: numPackets 1: read_callback packet @ 154434146914666 ns (host 3706419525953) status f0 length 6 packet->timeStamp 0 ns 0 host len 6 stat f0 Pm_Read returning 2 packets

rbdannenberg commented 2 years ago

Sysex is a real problem for API design since there's no upper bound on message size, and I've seen messages as big as 256K (memory dumps from synthesizers). I think every API packetizes SysEx messages. Callbacks are problematic because they are almost by definition asynchronous and on another thread, so you have to use synchronization primitives. Even if you get them right, you introduce the possibility of priority inversion if you are using priorities (PortMidi does, and real-time music applications should). The only solution to priority inversion, short of switching operating systems, is lock-free primitives, but malloc uses locks, so to be lock free and send messages, you need a lock-free heap, so things start getting complicated quickly. There's a real argument that since modern computers are multicore, priority inversion can never really block a high-priority process. Maybe some of these real-time design principles are out of date now and we shouldn't worry about calling malloc or using locks, but that would suggest a complete rethinking of the API.

Another option would be, on the application/client side, create a layer above pm_poll() that strips out SysEx message data and accumulates messages into a buffer. At the end of the message, a registered callback is called. This would be called within pm_poll, so it would be synchronous and on the same thread, thus no synchronization primitives needed. So you could get an even higher-level functionality (complete SysEx messages without embedded real-time messages) in a cross-platform way without messing with the CoreMIDI side of the implementation.

StewMacLean commented 2 years ago

Hi Roger, thanks for the background - this is complicated! I'm closing this as described in my previous comment, it is behaving as expected. Cheers