Strange issue when ran on Mac (Montery) with M1 Arm chip

[ElectricNoodle]

Currently looking into this myself as I might be able to figure out the fix, but I'm seeing the following strange behaviour on the above laptop/OS:

Currently using the go lang code to run the following, have looked through the Go bindings and believe that they're simple enough that the issue doesn't lie there, might be wrong though:

` package main

import( "log" "time" "github.com/rakyll/portmidi" )

func main() { portmidi.Initialize()

out, err := portmidi.NewOutputStream(1, 1024, 0) if err != nil { log.Fatal(err) }

// note on events to play C major chord //out.WriteShort(0x90, 60, 100) //out.WriteShort(0x90, 61, 100) //out.WriteShort(0x90, 67, 100)

// notes will be sustained for 2 seconds time.Sleep(2 * time.Second)

// note off events out.WriteShort(0x80, 60, 100) out.WriteShort(0x80, 64, 100) out.WriteShort(0x80, 67, 100)

    out.Close()

} `

When the above code is ran and I sniff the midi, I only see a single note on event, followed by 3 note off events with a velocity of 64 instead of 100.

If I comment out the note on events, I then see one note off event with a velocity of 100, followed by 2 with a velocity of 64.

So it seems like the message buffer is somehow being corrupted. Possibly due to an endianness issue?

Going to try and compile from source tonight and see if I can figure it out, so will update here if I do, but if anyone has any ideas that'd be great too.

[ElectricNoodle]

add 144 to packet 0x152009c20 len 3 timestamp 30830628419 @ 53525396562083 Pm_Write() buffer->message : 6569360 643d90 Pm_Write() buffer[0]: 123000 1e080 1 add 144 to packet 0x152009c20 len 3 timestamp 53525396570625 @ 53525396598875 Pm_Write() buffer->message : 6570896 644390 Pm_Write() buffer[0]: 123008 1e088 1 add 144 to packet 0x152009c20 len 3 timestamp 53525396604125 @ 53525396615583 Pm_Write() buffer->message : 6569088 643c80 Pm_Write() buffer[0]: 1261576 134010 1 add 128 to packet 0x152009c20 len 3 timestamp 53525396621291 @ 53527397907250 Pm_Write() buffer->message : 6570112 644080 Pm_Write() buffer[0]: 1261584 134018 1 add 128 to packet 0x152009c20 len 3 timestamp 53527397925916 @ 53527397989916 Pm_Write() buffer->message : 6570880 644380 Pm_Write() buffer[0]: 1261592 134020 1 add 128 to packet 0x152009c20 len 3 timestamp 53527398003375 @ 53527398036625

So it appears that on the first note on event:

    timestamp = AudioConvertNanosToHostTime(AudioGetCurrentHostTime());

The above call is returning a timestamp that's way off. (30830628419) Not quite sure how that's happening but will keep looking.

[ryandesign]

timestamp = AudioConvertNanosToHostTime(AudioGetCurrentHostTime());

The above call is returning a timestamp that's way off.

I know nothing about this code, but it seems wrong to me to pass the result of a function called AudioGetCurrentHostTime (which I assume returns something in "host time") to a function called AudioConvertNanosToHostTime (which I assume wants its input to be in "nanos" not in "host time").

Does this help: https://github.com/PortMidi/portmidi/commit/25ffc36ec7e18962156c216f4ab6f9d5ce3ef712 (I have not tested it.)

If so, then I think the problem was introduced in 64314cc3d1a6fdddfc6ff5408a3f83af685b8cea, which is huge and impossible to review.

[rbdannenberg]

I'm in the process of getting an M1 to test. Note that 100 = 0x64 -- is that just coincidence? I'll look into the HostTime question: it does look suspicious, but then I can't explain how this is covered in successful tests.

[StewMacLean]

Hi,

I suspect I have a similar problem. I'm using an M1 running Monterey.

I am working on a Pharo Smalltalk binding. All good so far, except that I can only send one shortMessage or a bunch of messages using Pm_Write, but only once.

After that the code executes with no errors but nothing appears in MidiMonitor. Interestingly when I shut down the library some events appear.

My hunch is that it is something to do with timing, the messages are received by PortMidi, but not being "released". All my timestamps are zero, and I have zero latency set on the device.

Please let me know if I can run any tests on the M1 that may help get to the bottom of this.

I haven't compile the module myself but installed it via homebrew and the library is libportmidi.2.0.3.dylib.

Ah, life on the bleeding edge!

[ryandesign]

Well, please try recompiling and including the patch I linked to above.

[StewMacLean]

Hi Ryan, well I've recompiled including your fix - to no avail.

So I thought I'd run testio. This seems to have the same problem. It sends the first CC message as shown in MidiMonitor, but then doesn't send anything else. When it gets to the end a bunch of note off messages appear, which doesn't seem to be the expected behaviour. BTW, same behaviour with a "real' device.

Please see screenshots attached.

I'm a relative newbie to XCode and sort of read-only mode with C. If there's any debugging you want me to do, please let me know. (And give some brief instructions as to how to debug using XCode!)

)

[ryandesign]

So I thought I'd run testio. This seems to have the same problem.

Thanks for showing me what you did and what result you got. I know essentially nothing about portmidi but I was able to confirm your results with portmidi built for arm64 on an Apple Silicon Mac running macOS Big Sur 11.6.5. But if I build portmidi universal (passing -DCMAKE_OSX_ARCHITECTURES="arm64;x86_64" to cmake) and run the x86_64 version of testio (arch -x86_64 ./testio) then it works correctly like it does on my Intel Mac running macOS Catalina 10.15.7. So at least that's a workaround you could use until someone figures out what's going wrong when it's built for arm64. I can also confirm that the patch I proposed doesn't change the situation.

[ryandesign]

After editing pm_mac/pmmacosxcm.c to change CM_DEBUG to enable more debug output:

Running arm64 testio on arm64:

% ./testio -v -l 0               
Usage: test [-h] [-l latency-in-ms] [-v]
    -h for this help message (only)
    -l for latency
    -v for verbose (enables more output)
Apparently this is a 64-bit machine.
Verbose is now TRUE
Latency will be 0
begin portMidi test...
enter your choice...
    1: test input
    2: test input (fail w/assert)
    3: test input (fail w/NULL assign)
    4: test output
    5: test both
    6: stream test (for WinMM)
    7. isochronous out
4
0: CoreMIDI, MIDI Monitor (Untitled) (default output)
Type output number: 0
midi_out_open isIACdevice 0
Midi Output opened with 0 ms latency.
ready to send program 1 change... (type ENTER):
add 192 to packet 0x14000a220 len 2 timestamp 1059723731 @ 1839798145625
ready to note-on... (type ENTER):
add 144 to packet 0x14000a220 len 3 timestamp 1839798160041 @ 1841757266125
ready to note-off... (type ENTER):
add 144 to packet 0x14000a220 len 3 timestamp 1841757277875 @ 1842612173750
ready to note-on (short form)... (type ENTER):
add 144 to packet 0x14000a220 len 3 timestamp 1842612187083 @ 1843324528458
ready to note-off (short form)... (type ENTER):
add 144 to packet 0x14000a220 len 3 timestamp 1843324540791 @ 1844045242166
chord should not arpeggiate, latency == 0
ready to chord-on/chord-off... (type ENTER):
starting timestamp 6655
add 144 to packet 0x14000a220 len 3 timestamp 1844045250375 @ 1844780384500
add 144 to packet 0x14000a220 len 3 timestamp 1844045250375 @ 1844780387916
add 144 to packet 0x14000a220 len 3 timestamp 1844045250375 @ 1844780390041
add 144 to packet 0x14000a220 len 3 timestamp 1844045250375 @ 1844780391666
add 144 to packet 0x14000a220 len 3 timestamp 1844045250375 @ 1844780393291
add 144 to packet 0x14000a220 len 3 timestamp 1844780395041 @ 1850783765458
add 144 to packet 0x14000a220 len 3 timestamp 1844780395041 @ 1850783795333
add 144 to packet 0x14000a220 len 3 timestamp 1844780395041 @ 1850783797916
add 144 to packet 0x14000a220 len 3 timestamp 1844780395041 @ 1850783799708
add 144 to packet 0x14000a220 len 3 timestamp 1844780395041 @ 1850783801375
ready to close and terminate... (type ENTER):
done closing and terminating...
finished portMidi test...type ENTER to quit...
%

Running x86_64 testio on arm64:

% arch -x86_64 ./work/build/testio -v -l 0
Usage: test [-h] [-l latency-in-ms] [-v]
    -h for this help message (only)
    -l for latency
    -v for verbose (enables more output)
Apparently this is a 64-bit machine.
Verbose is now TRUE
Latency will be 0
begin portMidi test...
enter your choice...
    1: test input
    2: test input (fail w/assert)
    3: test input (fail w/NULL assign)
    4: test output
    5: test both
    6: stream test (for WinMM)
    7. isochronous out
4
0: CoreMIDI, MIDI Monitor (Untitled) (default output)
Type output number: 0
midi_out_open isIACdevice 0
Midi Output opened with 0 ms latency.
ready to send program 1 change... (type ENTER):
add 192 to packet 0x7f7ef5008420 len 2 timestamp 1871678064791 @ 1871678070083
ready to note-on... (type ENTER):
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1873540701708 @ 1873540706958
ready to note-off... (type ENTER):
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1874396668000 @ 1874396668750
ready to note-on (short form)... (type ENTER):
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1875156624041 @ 1875156624833
ready to note-off (short form)... (type ENTER):
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1875972191833 @ 1875972192625
chord should not arpeggiate, latency == 0
ready to chord-on/chord-off... (type ENTER):
starting timestamp 7415
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1876757738833 @ 1876757739416
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1876757748625 @ 1876757748666
add 144 to packet 0x7f7ef500842d len 3 timestamp 1876757752000 @ 1876757752041
add 144 to packet 0x7f7ef500843a len 3 timestamp 1876757754958 @ 1876757755041
add 144 to packet 0x7f7ef5008447 len 3 timestamp 1876757757708 @ 1876757757791
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1882767577833 @ 1882767578375
add 144 to packet 0x7f7ef5008420 len 3 timestamp 1882767635041 @ 1882767635083
add 144 to packet 0x7f7ef500842d len 3 timestamp 1882767639500 @ 1882767639583
add 144 to packet 0x7f7ef500843a len 3 timestamp 1882767642500 @ 1882767642583
add 144 to packet 0x7f7ef5008447 len 3 timestamp 1882767645333 @ 1882767645375
ready to close and terminate... (type ENTER):
done closing and terminating...
finished portMidi test...type ENTER to quit...
%

So I see the same results as @ElectricNoodle and @StewMacLean except:

The above call is returning a timestamp that's way off. (30830628419)

The first packet is the only one that's getting through, so I'd say instead that that's the only correct timestamp and all the others are wrong. It would not surprise me if "host time" uses different units on arm64 processors than it does on x86_64. (glib had a longstanding bug where their time code was wrong on non-Intel processors.) With a little extra debugging, it looks like host time is nanoseconds on x86_64, so I think all uses of AudioConvertNanosToHostTime and AudioConvertHostTimeToNanos in this code are suspect need to be reexamined since they do nothing on Intel. I'm looking at them now...

[ryandesign]

Does this fix it for you? It does for me: all packets received by MIDI Monitor and consistent (architecture-specific) timestamps both with arm64-on-arm64, x86_64-on-arm64, and x86_64-on-x86_64.

The change to info->sysex_timestamp is untested but there was a discrepancy there (it was initially set to a value in host time using AudioConvertNanosToHostTime(when_ns) and was then, depending on a condition, changed to a value in nanosecond time using AudioConvertHostTimeToNanos(AudioGetCurrentHostTime())) and I made the assumption that, like timestamp, sysex_timestamp should always be expressed in host time.

[rbdannenberg]

This is very helpful. I'm making a pass looking at all timestamps in pmmacosxcm.c. There seem to be even more problems than the ones listed here, but all related to host time vs. nanoseconds, which seem to be the same on x86.

Could someone get values of info->us_per_host_tick on M1 and x86?

[ryandesign]

Could someone get values of info->us_per_host_tick on M1 and x86?

Sure, on arm64 I see 0.041667 and on x86_64 I see 0.001000.

[rbdannenberg]

Excellent! Thanks.

[rbdannenberg]

I just did a quick test with changes from Does this fix it for you and a few more minor things. I pushed the updates and I think this will (also) work on M1. Any testing would be appreciated -- I have an M1 on order now.

[StewMacLean]

Thanks Guys! Happy to test, but sorry, I'm a Git newbie... I've deleted my local repo, and cloned again but the change is not there in the master branch. I can see there is a change in upstream/master 7 hrs ago, but when I select that in the desktop it say it already exists. The last change in master is 15 days ago. What am I doing wrong?

[rbdannenberg]

If I look at https://github.com/PortMidi/portmidi, under Code, with "master" selected, I see rbdannenberg Merge branch 'master' of github.com-rbdannenberg:PortMidi/portmidi ... 41c6646 8 hours ago and the pm_mac/pmmacosxcm.c file is updated today too. Make sure you are getting code from PortMidi/portmidi project.

[StewMacLean]

Thanks, it appears the GitHub desktop was caching it somehow... anyway it is an improvement, but still doesn't look right. The first Note On is correct, but then for the Note Off there is one Note Off and a Note On! Please see screenshot. With the complete test, there are some Invalid events which doesn't bode well? Thanks.

[rbdannenberg]

It would help to know what/how you are testing and what you expect, but I think I see the NoteOff/NoteOn pairs you are talking about. At first I thought maybe noteoff (0x80) was not parsed right, since you can also indicate noteoff with 0x90 and velocity 0x00, but there's very little in PortMidi that actually looks at status bytes -- mostly they are just copied. I don't see any byte order problems either, but byte-order sensitivity seems pretty plausible.

[ryandesign]

@StewMacLean Does the problem persist if you have testio send to MIDI Monitor directly? In your testing I see you selected "IAC Driver OverDriveIn" as the output. I'm not familiar with that and don't have it on my system. In my testing I selected "CoreMIDI, MIDI Monitor (Untitled)" as the output. Can you try that?

[StewMacLean]

OverDrive is an IAC bus that I set up. I've selected MIDIMonitor. I ran testio, but just the first note on, and off commands. I would expect to see corresponding note on and off in the monitor. However there are two note ons. Please see screenshots. I've also disabled my Audio interface drive that has midi as well, in case that was causing problems. When I run the whole sequence of commands, there are no note offs. Curious!

[StewMacLean]

Here's the problem - it's doing exactly what it's told to! I've changed the note offs to be x80 and the output is as expected. Looks like the PortMidi river is flowing on the M1! Thanks for sorting this.

printf("ready to note-on... (type ENTER):"); WAIT_FOR_ENTER buffer[0].timestamp = Pt_Time(); buffer[0].message = Pm_Message(0x90, 60, 100); Pm_Write(midi, buffer, 1); printf("ready to note-off... (type ENTER):"); WAIT_FOR_ENTER buffer[0].timestamp = Pt_Time(); buffer[0].message = Pm_Message(0x90, 60, 0); Pm_Write(midi, buffer, 1);

    /* output short note on/off w/latency offset; hold until user prompts */
    printf("ready to note-on (short form)... (type ENTER):");
    WAIT_FOR_ENTER
    Pm_WriteShort(midi, Pt_Time(),
                  Pm_Message(0x90, 60, 100));
    printf("ready to note-off (short form)... (type ENTER):");
    WAIT_FOR_ENTER
    Pm_WriteShort(midi, Pt_Time(),
                  Pm_Message(0x90, 60, 0));

[ryandesign]

When you were having testio send directly to MIDI Monitor:

it's doing exactly what it's told to! I've changed the note offs to be x80 and the output is as expected

From what I've read, it's valid and common to use note-on-velocity-0 to mean note-off, as testio does. I assume that you have MIDI Monitor's "Expert Mode" turned on in its Preferences window because your output shows hex values. Expert mode will make MIDI Monitor use hex values and show note-on-velocity-0 as note-on. If you turn expert mode off, as I had, that will make it show note-on-velocity-0 as note-off.

When you were having testio use IAC Driver OverDriveIn to relay output to MIDI Monitor:

The first Note On is correct, but then for the Note Off there is one Note Off and a Note On!

I assume IAC Driver OverDriveIn translated the note-on-velocity-0 event to a note-off event.

So everything appears to be working correctly for you now.

[lucretiomsp]

on my M1 with Monterrey, I had the same issue of @StewMacLean (using Pharo, as well but also on stand alone programs). now everything is working fine! thanks a lot @ryandesign and @rbdannenberg . we are going to have fun with PortMidi inside Pharo :)

[StewMacLean]

Yes, thanks heaps to @ryandesign https://github.com/ryandesign and @rbdannenberg https://github.com/rbdannenberg for sorting this out. Good job!

In spite of the Midi semantics of zero velocity for a note off for a note on, to avoid this misinterpretation in the future, I suggest the test actually sends a real note off.

Just tested from Pharo, and it is music to my ears...

On Tue, May 24, 2022 at 7:35 PM Domenico Cipriani @.***> wrote:

on my M1 with Monterrey, I had the same issue of @StewMacLean https://github.com/StewMacLean (using Pharo, as well but also on stand alone programs). now everything is working fine! thanks a lot @ryandesign https://github.com/ryandesign and @rbdannenberg https://github.com/rbdannenberg . we are going to have fun with PortMidi inside Pharo :)

— Reply to this email directly, view it on GitHub https://github.com/PortMidi/portmidi/issues/25#issuecomment-1135516249, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXGQYQ7F2FIDMPUJWPIFWWLVLSBCNANCNFSM5UMGOBHQ . You are receiving this because you were mentioned.Message ID: @.***>

[rbdannenberg]

Maybe another test is in order. By the way, the formal testing I do is in portmidi/pm_test/README.txt. There are 33 tests (!) some involving 3 programs, and I have a custom-built loop-back-over-USB MIDI device because hardware behaves differently from IAC bus. This is still hardly complete testing (as the M1 shows), but it helps.

Note-on with velocity zero is arguably better than Note-off (0x80) because you can use running status in a mix of note-on/note-off actions, so I think you should send 0x80 only if you want to use the rarely-implemented release velocity. Note-on with velocity zero is also good for testing because running status processing has additional ways to fail. But again, testing both is even better.

Thanks for all the testing and feedback.

[rbdannenberg]

I think this is resolved, so I'm closing it, but reopen or contact me if I'm wrong. I'm definitely testing with M1 as soon as I get one, but I hear there's a long wait for new orders.