Choppy transmit audio when using Dire Wolf on macOS

johnboiles commented 1 year ago

Running Dire Wolf 7d3c1d1 on macOS 13.1 with AIOC c65a3f3, most transmitted packets are choppy. A clear error is thrown in Dire Wolf when this happens Transmit timing error: PTT is on 3558 mSec too long.:

And sure enough the radio output looks (and sounds) weird and choppy:

Possible this is a Dire Wolf bug but I don't get this same thing when using my built-in soundcard. My relevant Dire Wolf config is:

ADEVICE "AIOC Audio" "AIOC Audio"
ARATE 48000
PTT /dev/cu.usbmodem5a031bca1 RTS -DTR

johnboiles commented 1 year ago

Seems like my $10 RTLSDR dongle + SDRAngel is doing significantly better than my AIOC + Baofeng + Direwolf at decoding packets, so I'm also suspicious there's something going wrong with the input audio also. But I'm not sure how to debug this.

johnboiles commented 1 year ago

I'm also seeing some core audio processes take up a ton of CPU. Perhaps that's a hint? Perhaps there's something on a single core and CPU constrained? I'm on a MacBook Pro 2021 w/ M1 Max (10 cores). Overall CPU usage is ~30%

johnboiles commented 1 year ago

I killed the CAReportingService process (it was using 14gb RAM!!!) and tried again. The first 4 packets failed, then all subsequent ones worked.

skuep commented 1 year ago

Odd! Do you happen to know, that the message "PTT is on ... too long" is supposed to mean? For now I cannot make sense of those lines.

Regarding the choppy audio: Have you programmed the firmware file v1.0.0 from the GitHub release page or do you have one of the beta devices I sent out a while ago? If the latter, can you try updating the firmware to v1.0.0. I remember there being some issues very similar to choppy audio that I also noticed (although only on very few of my AIOCs).

johnboiles commented 1 year ago

I'm not sure what it's supposed to mean. But I suspect what's happening is that the audio is slow to output (and thus sounds choppy), making the whole packet take too long, and that's why this error is firing.

I'm running on firmware SHA c65a3f3 built from my local machine. That's two commits on top of v1.0.0. If you think there'd be an environment difference I could flash your pre-built hex.

I ordered my boards from jlcpcb on 1/2, so I was probably on commit caed7f6d3 for my hardware.

lysol commented 1 year ago

FWIW, I ran into this same issue on MacOS, switched over to Ubuntu, and didn't have the issue. Same AIOC, same firmware (1.0.0), so I doubt the issue is the AIOC itself. More likely a driver or library issue.

johnboiles commented 1 year ago

@lysol thanks for the note. Setting up a arm64 Ubuntu VM in UTM.app and running Direwolf there worked just fine. Took a beat to find the right device names but after that it's been flawlessly. I needed:

ADEVICE plughw:AllInOneCable,0
PTT /dev/ttyACM0 RTS -DTR

It's a little clunkier perhaps then running natively on macOS since you have to configure/start a VM, but it worked flawlessly.

So this bug could be in portaudio, Direwolf, the sound drivers being used for AIOC, or in the AIOC firmware (unlikely since it works fine on other platforms). I guess the next step to investigate on macOS would be to play+record sound via the AIOC cable with other tools and see if other tools can reproduce it.

skuep commented 1 year ago

I'm running on firmware SHA c65a3f3 built from my local machine. That's two commits on top of v1.0.0. If you think there'd be an environment difference I could flash your pre-built hex.

There shouldn't be any difference. It may be possible that it could be related to your build environment being different, but that is just a long shot. Though confirming that the problem is present with the exact binary that I built could be somewhat helpful in narrowing down the problem. Gotta find a macOS machine first though.

FWIW, I ran into this same issue on MacOS, switched over to Ubuntu, and didn't have the issue. Same AIOC, same firmware (1.0.0), so I doubt the issue is the AIOC itself. More likely a driver or library issue.

Thanks! Helps to know that the problem is not isolated but general. Do you both have M1/M2 Macs by any chance (since you mention arm64 Ubuntu VM). Maybe it could be related? Although I doubt it.

I found this page in the mean time: https://developer.apple.com/library/archive/technotes/tn2274/_index.html I should work this through and find any potential problems. Next would be to somehow get myself a macOS VM working. If someone of you has some spare time, could it be possible to record a pcap dump of the USB communications? On Linux I use Wireshark and the usbmon kernel module for that.

I guess the next step to investigate on macOS would be to play+record sound via the AIOC cable with other tools and see if other tools can reproduce it.

Yeah, also a good idea!

EDIT: Can you try setting direwolf ARATE to 24000 instead of 48000? And see what happens. EDIT2: Also interesting: https://learn.microsoft.com/en-us/answers/questions/103549/usb-audio-2-0-feedback-endpoint-requirements

skuep commented 1 year ago

I have activated CFG_TUD_AUDIO_ENABLE_FEEDBACK_FORMAT_CORRECTION in the tinyusb audio part of the source-code. I remember it saying somewhere in the examples that (although the USB spec says otherwise), USB feedback endpoint format of 16.16 is accepted by most (?) OSes. From the Apple document above however I get the feeling that macOS is very true to the original USB spec (which I applaud). So this might be a problem. With this enabled, it should be more accurate to the spec. But it may have issues with other OSes, which we would need to sort out later.

However can you test this firmware just to check if this is the issue? aioc-fw-fb10-14.bin.zip

agrif commented 1 year ago

I'm having the same issue with choppy transmit on macOS, and I just tried this firmware and it doesn't seem to help. Reducing the sample rate doesn't help either. One new data point: I'm on an x86-64 mac, not an ARM mac, so that's not the issue at least.

I'm happy to try out any changes you think of. I'll be poking around too, although I don't have much hope since I'm unfamiliar with the systems.

skuep commented 1 year ago

Thanks a bunch for checking the firmware. I assume the regular 1.1.1 firmware has the same issue right? That's probably the one you tried before.

Did you work with direwolf? Can you confirm that the issue is actually the AIOC? Do you have another USB soundcard laying around? Is the stuttering in play and/or recording? Can you use some kind of recording software and just try to record something using the AIOC soundcard?

I am wondering what the issue is. I need to get my hands on a MacOS or maybe try to run it in a libvirt VM under Linux... One thing you could try is recording a wireshark dump of the usb transactions from plugging it in to playing something. But it's kind of advanced unfortunately.

agrif commented 1 year ago

I was using 1.1.0 -- I can upgrade to 1.1.1 and try that, if you think it might make a difference.

Yeah, I was using direwolf. I've used direwolf with a digirig before with no issues. Recording from the AIOC in Audacity appears to work just fine, and I'm decoding packets in direwolf. I don't have an easy way to test playback right now, but I'll dig out an oscilloscope and see what I can do later. I'll also try this in linux, just to confirm that this is macOS only and not some problem with my board in particular. It's only for convenience that I tested it on my mac laptop first!

I've used wireshark before, though not for USB. If I can work out how to do that, I'll post the dump here. Unfortunately I don't know enough about USB for a dump to be any use to me.

skuep commented 1 year ago

The difference between 1.1.0 and 1.1.1 is minor, that should not be it.

The AIOC uses USB Audio Class 2.0, its pretty recent and very common with higher performance external sound units (studio class devices). It's only available since USB 2.0 (although the AIOC is a Full-Speed device and not High-Speed but that should not be important).

I looked around again and found interesting articles like this one. (they refer to USB2.0 but it could very well mean USB Audio Class 2, since USB1.1 devices, i.e. fullspeed only can only use USB Audio Class 1, which is fine). https://cdm.link/2019/02/apple-2018-glitch/ https://forums.macrumors.com/threads/audio-dropouts-on-big-sur.2271849/page-2 https://discussions.apple.com/thread/252727766?page=2 https://www.reddit.com/r/apple/comments/anvufc/psa_2018_macs_with_t2_chip_unusable_with_external/

Since the problem only seems to be in combination with direwolf. Here someone is reporting the issue where changing the audio library (that the application uses) was changed from SDL to PortAudio. No idea what direwolf uses, but could be a lead also. https://github.com/UltraStar-Deluxe/USDX/issues/573

What MacOS version do you (all) have? Apparently the problems started with Big Sur (macOS 11.3) https://www.reddit.com/r/Schiit/comments/n04yiz/dont_update_to_bigsur_113/

If you can get USB capturing with Wireshark to work, you can just send me the pcap file. But at least on Linux you need to load a kernel module for that, not sure if it's even possible on mac.

EDIT: It might be worth opening an issue with direwolf. Seeing if other people with higher performance USB 2.0 audio interfaces on macOS have the same issue as we have with the AIOC.

agrif commented 1 year ago

I'm on macOS Monterey (12.4). On macs, direwolf uses portaudio. I'm using the version of direwolf 1.6 provided by macports, should that become relevant.

For my reference, here's a list of things I'll try soon:

use AIOC in linux
see if playback from other programs also stutters
poke around the coreaudio api and see if using that directly stutters
try and get USB wireshark dumps working

If this ends up being a direwolf issue, I'll be sure to open one over there. I'd be a little bit surprised -- lots of things use PortAudio, and I feel like somebody would have noticed. But macs surface bugs like nobody's business.

skuep commented 1 year ago

Yeah, let me know how it turns out. I am not sure where the issue exactly is with MacOS, is it USB2.0 or is it the use of UAC2 (USB Audio Class 2)? Most direwolf users very probably don't have a UAC2 soundcard (CM108 is UAC1). UAC2 is mostly used on multi-channel studio grade stuff. I think it's a combination of UAC2 and maybe the library that direwolf uses (if it turns out, that other applications don't have this issue).

If the problem is USB2.0, I can make a firmware where the device enumerates as a USB1.1 device. However, UAC2 with USB1.1 is somewhat out of spec, so it may not work at all. But maybe this way we can narrow down how a workaround for macOS could look like.

EDIT: Can you maybe also try using a lower samplerate such as 24000 or 12000?

agrif commented 1 year ago

I can confirm, it works absolutely fine on linux.

Changing the sample rate in direwolf doesn't help.

I've hooked up my scope today. I see the choppy in/out in Chrome and VLC as well as direwolf. I've attached a picture of my scope when playing a 440 Hz sine wave -- it looks like it'll play about 60ms and then nothing for 80ms or so. VLC was much more intermittent. It also holds the last value for a while, before resetting to 0.

DS1Z_QuickPrint1

(It's also noisy, but I think that's just how it is).

I left the sine wave running for a while, and eventually it became continuous and worked fine. Other applications then worked fine as well! I can't reproduce it at all, however. It's possible I was plugging in other USB things and somehow that kicked macOS into behaving, I don't know.

Right now, it looks like the problem isn't direwolf. Something about the AIOC is confusing macOS.

agrif commented 1 year ago

A few more data points, though none is enlightening:

If I leave the AIOC plugged in for a while, playing sound through it, it sometimes fixes itself. And, sometimes, later breaks again. I have no idea what causes this.
My mac does not have a T2 chip, so I don't think this is the T2 audio bug you linked. (I'm on a late 2015 macbook pro)
If I have two programs outputting audio to the AIOC (say, a sine wave generator and direwolf both), it looks like the buffers that make it to the device aren't the same size -- part of the output will be only sine wave, and part will be sine wave and direwolf mixed. I'm pretty sure the AIOC itself has nothing to do with mixing -- this looks like macOS or the programs themselves are misbehaving. Maybe there's a misunderstanding between macOS and AIOC about what sample rate is being used?

skuep commented 1 year ago

Thanks for all the details... Very odd if I might say. Where did you measure those signals? At the TRS connector output (i.e. after or before the DC blocking cap?). From the voltage level I assume its after. The AIOC currently buffers approximately 5ms of audio data (at 48kHz sample rate). If the buffer runs dry, the AIOC will automatically output the zero level. Which means that the 40 ms (?) of it holding the value must be resulting from MacOS... Hm.

Yeah, last thing I can think of is maybe a USB dump. Other than that I am currently at a loss. I am also not aware how many MacOS AIOC users are out there, that don't have any issues? Is this just a random issue or is it systematic?

agrif commented 1 year ago

I measured at the TRS connector. I'll look in to a USB dump. I wish I had another mac around to test with. I might just be very unlucky with a hardware/OS combination.

johnboiles commented 1 year ago

Just a note to say I'm happy to try things if someone could write up a test sequence. I have access to a M1 Max on macOS 13, and M1 Air on macOS 12, and an older Intel Mac, probably on macOS 12.

I've only tested so far on the macOS M1 Max.

agrif commented 1 year ago

Hello! I got distracted there for a few months, but I installed wireshark today and convinced it to capture USB traffic.

Here's a dump of me connecting the AIOC, starting direwolf, and then "transmitting" a position beacon once. Then I close direwolf and disconnect the AIOC. As far as I know, nothing else is happening on this bus at the time.

aioc-usb-cap.pcapng.zip

As before, audio in seems to work fine but audio out seems to stutter and break apart into pieces with empty space in between, causing the whole thing to take longer to play than it should.

It looks like the AIOC is device 20.8.*, but beyond that I don't know enough about USB to really get a handle on this dump. Hopefully it might mean something to you! Getting these dumps is pretty easy, so if there's anything else you'd like me to record, I'd be happy to.

skuep commented 1 year ago

Thanks a lot, I will have a look in the next days and see if there is something obvious.

k6ef commented 1 year ago

I just want to add a +1 to this issue still being there.

vk2gpu commented 8 months ago

Seeing choppy audio as well on MacOS. Any sample rate seems to reproduce the problem.

Direwolf log:

Attached to AGW client application 0...

Ready to accept AGW client application 1 on port 8000 ...
Attempting connect to VK2GPU-9 ...
[0L] VK2GPU>VK2GPU-9:(SABME cmd, p=1)
Transmit timing error: PTT is on 1126 mSec too long.
[0L] VK2GPU>VK2GPU-9:(SABME cmd, p=1)
Transmit timing error: PTT is on 1095 mSec too long.
[0L] VK2GPU>VK2GPU-9:(SABME cmd, p=1)
Transmit timing error: PTT is on 1091 mSec too long.
[0L] VK2GPU>VK2GPU-9:(SABM cmd, p=1)
Transmit timing error: PTT is on 1094 mSec too long.
[0L] VK2GPU>VK2GPU-9:(SABM cmd, p=1)
Transmit timing error: PTT is on 1175 mSec too long.
[0L] VK2GPU>VK2GPU-9:(SABM cmd, p=1)
Transmit timing error: PTT is on 1090 mSec too long.

Mac in question:

M2, 2022
Chip: Apple M2
Memory: 16 GB
macOS: 14.3.1 (23D60)

daviesgeek commented 4 months ago

I'm also seeing the same. Direwolf 1.7, M3 Max 2023, Sonoma 14.5.

Transmit timing error: PTT is on 2670 mSec too long.

lha commented 3 months ago

I updated to aioc-fw-fb10-14.bin.zip and now I can't change the firm ware any more, the device still seem to work though.

Both the restore firmware and upgrade failed with

dfu-util: No DFU capable USB device available

lha commented 3 months ago

The kernel have plenty of options about the usb device, you can see them if you have a Mac with:

log stream --debug --predicate 'processImagePath contains "kernel"'

it looks like this when failure happens:

2024-08-04 16:37:16.883997-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::externalMethod, selector=0x0,   arg0 0x0, arg1 0x1048e4000, arg2 0x4010 arg3 0x1412
2024-08-04 16:37:16.884012-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   scalarInputCount=0x4  structureInputSize 0x0, scalarOutputCount 0x0, structureOutputSize 0x0
2024-08-04 16:37:16.884018-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::registerBuffer64 0x0 0x1048e4000 0x4010 0x1412
2024-08-04 16:37:16.884023-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::safeRegisterClientBuffer64 <private>
2024-08-04 16:37:16.884027-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient[<private>]::registerClientBuffer64  (<private>[1], 0x1048e4000, 0x4010, 0x1412)
2024-08-04 16:37:16.884033-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   null clientBufferSetList
2024-08-04 16:37:16.884034-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   did not find clientBufferSetList for ID 0x1412
2024-08-04 16:37:16.884084-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   clientBuffer->mAudioClientBuffer32.sourceBuffer before offset: <private>, offset size: 16
2024-08-04 16:37:16.884086-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   clientBuffer->mAudioClientBuffer32.sourceBuffer after offset: <private>
2024-08-04 16:37:16.884088-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   null clientBufferSetList
2024-08-04 16:37:16.884089-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   did not find clientBufferSetList for ID 0x1412
2024-08-04 16:37:16.884090-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   creating new IOAudioClientBufferSet
2024-08-04 16:37:16.884092-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   input
2024-08-04 16:37:16.884093-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   !isOnline
2024-08-04 16:37:16.884095-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::registerClientBuffer64() result 0x0
2024-08-04 16:37:16.884095-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::safeRegisterClientBuffer64  returns 0x0
2024-08-04 16:37:16.884098-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::registerBuffer64 0x0 0x1048e4000 0x4010 0x1412 returns 0x0
2024-08-04 16:37:16.884100-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::externalMethod returns 0x0
2024-08-04 16:37:16.884472-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::externalMethod, selector=0x3,   arg0 0x0, arg1 0x0, arg2 0x0 arg3 0x0
2024-08-04 16:37:16.884476-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   scalarInputCount=0x0  structureInputSize 0x0, scalarOutputCount 0x0, structureOutputSize 0x0
2024-08-04 16:37:16.884480-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient[<private>]::startClient() - 0
2024-08-04 16:37:16.884482-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   audioEngine && !isInactive(). State = 0
2024-08-04 16:37:16.884484-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   audioEngine->getState() != kIOAudioEnginePaused
2024-08-04 16:37:16.884487-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) +- IOAudioEngineUserClient[<private>]::setOnline(1)
2024-08-04 16:37:16.884489-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   !isOnline() setting online
2024-08-04 16:37:16.884490-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::startClient(<private>)
2024-08-04 16:37:16.884492-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::incrementActiveUserClients() - 0
2024-08-04 16:37:16.884495-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::startAudioEngine(state = 0)
2024-08-04 16:37:16.884497-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioDevice[<private>]::audioEngineStarting() - numRunningAudioEngines = 0
2024-08-04 16:37:16.884499-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioDevice[<private>]::initiatePowerStateChange(0x0) - current = 1 - pending = 2
2024-08-04 16:37:16.884501-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioDevice[<private>]::protectedCompletePowerStateChange() - current = 1 - pending = 2
2024-08-04 16:37:16.884505-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioDevice[<private>]::protectedCompletePowerStateChange() - current = 2 - pending = 2 returns 0x0
2024-08-04 16:37:16.884506-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioDevice[<private>]::initiatePowerStateChange(0x0) - current = 2 - pending = 2 returns 0x0
2024-08-04 16:37:16.884508-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioDevice[<private>]::audioEngineStarting() - numRunningAudioEngines = 1
2024-08-04 16:37:16.884516-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::stopEngineAtPosition(0,0)
2024-08-04 16:37:16.884520-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) +- IOAudioEngine[<private>]::resetStatusBuffer()
2024-08-04 16:37:16.889091-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) +-IOAudioEngine[<private>]::setState(0x1. oldState=0)
2024-08-04 16:37:16.889115-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::getTimerInterval()
2024-08-04 16:37:16.889134-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::startAudioEngine() returns 0x0
2024-08-04 16:37:16.889136-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::incrementActiveUserClients() - 1 returns 0
2024-08-04 16:37:16.889139-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::startClient(<private>) returns 0x0
2024-08-04 16:37:16.889141-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   engine started
2024-08-04 16:37:16.889143-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   bufferSet <private>
2024-08-04 16:37:16.889144-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily)   input clientBuffer <private>
2024-08-04 16:37:16.889145-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioStream[<private>]::addClient(<private>)
2024-08-04 16:37:16.889150-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioStream[<private>]::addClient(<private>) returns 0x0
2024-08-04 16:37:16.889152-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient[<private>]::startClient() - 1 returns 0x0
2024-08-04 16:37:16.889154-0700 0x211e8d   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::externalMethod returns 0x0
2024-08-04 16:37:16.927121-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::externalMethod, selector=0x0,   arg0 0x0, arg1 0x104910000, arg2 0x4010 arg3 0x1411
2024-08-04 16:37:16.927135-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   scalarInputCount=0x4  structureInputSize 0x0, scalarOutputCount 0x0, structureOutputSize 0x0
2024-08-04 16:37:16.927144-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::registerBuffer64 0x0 0x104910000 0x4010 0x1411
2024-08-04 16:37:16.927148-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::safeRegisterClientBuffer64 <private>
2024-08-04 16:37:16.927152-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient[<private>]::registerClientBuffer64  (<private>[1], 0x104910000, 0x4010, 0x1411)
2024-08-04 16:37:16.927156-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   null clientBufferSetList
2024-08-04 16:37:16.927157-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   did not find clientBufferSetList for ID 0x1411
2024-08-04 16:37:16.927226-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   clientBuffer->mAudioClientBuffer32.sourceBuffer before offset: <private>, offset size: 16
2024-08-04 16:37:16.927228-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   clientBuffer->mAudioClientBuffer32.sourceBuffer after offset: <private>
2024-08-04 16:37:16.927231-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   null clientBufferSetList
2024-08-04 16:37:16.927231-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   did not find clientBufferSetList for ID 0x1411
2024-08-04 16:37:16.927233-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   creating new IOAudioClientBufferSet
2024-08-04 16:37:16.927237-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   output
2024-08-04 16:37:16.927239-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   !isOnline
2024-08-04 16:37:16.927240-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::registerClientBuffer64() result 0x0
2024-08-04 16:37:16.927242-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::safeRegisterClientBuffer64  returns 0x0
2024-08-04 16:37:16.927244-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::registerBuffer64 0x0 0x104910000 0x4010 0x1411 returns 0x0
2024-08-04 16:37:16.927246-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::externalMethod returns 0x0
2024-08-04 16:37:16.927575-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient::externalMethod, selector=0x3,   arg0 0x0, arg1 0x0, arg2 0x0 arg3 0x0
2024-08-04 16:37:16.927579-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   scalarInputCount=0x0  structureInputSize 0x0, scalarOutputCount 0x0, structureOutputSize 0x0
2024-08-04 16:37:16.927584-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngineUserClient[<private>]::startClient() - 0
2024-08-04 16:37:16.927587-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   audioEngine && !isInactive(). State = 0
2024-08-04 16:37:16.927588-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   audioEngine->getState() != kIOAudioEnginePaused
2024-08-04 16:37:16.927594-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) +- IOAudioEngineUserClient[<private>]::setOnline(1)
2024-08-04 16:37:16.927596-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   !isOnline() setting online
2024-08-04 16:37:16.927597-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::startClient(<private>)
2024-08-04 16:37:16.927598-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::incrementActiveUserClients() - 0
2024-08-04 16:37:16.927603-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::startAudioEngine(state = 0)
2024-08-04 16:37:16.927604-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioDevice[<private>]::audioEngineStarting() - numRunningAudioEngines = 1
2024-08-04 16:37:16.927606-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioDevice[<private>]::audioEngineStarting() - numRunningAudioEngines = 2
2024-08-04 16:37:16.927608-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::stopEngineAtPosition(0,0)
2024-08-04 16:37:16.927610-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) +- IOAudioEngine[<private>]::resetStatusBuffer()
2024-08-04 16:37:16.936632-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) +-IOAudioEngine[<private>]::setState(0x1. oldState=0)
2024-08-04 16:37:16.936647-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::getTimerInterval()
2024-08-04 16:37:16.936665-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::startAudioEngine() returns 0x0
2024-08-04 16:37:16.936668-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::incrementActiveUserClients() - 1 returns 0
2024-08-04 16:37:16.936671-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngine[<private>]::startClient(<private>) returns 0x0
2024-08-04 16:37:16.936672-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   engine started
2024-08-04 16:37:16.936674-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   bufferSet <private>
2024-08-04 16:37:16.936675-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily)   output clientBuffer <private>
2024-08-04 16:37:16.936676-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioStream[<private>]::addClient(<private>)
2024-08-04 16:37:16.936715-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioStream[<private>]::addClient(<private>) returns 0x0
2024-08-04 16:37:16.936717-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient[<private>]::startClient() - 1 returns 0x0
2024-08-04 16:37:16.936720-0700 0x211e98   Default     0x0                  0      0    kernel: (IOAudioFamily) - IOAudioEngineUserClient::externalMethod returns 0x0
2024-08-04 16:37:16.947110-0700 0x769      Error       0x0                  0      0    kernel: (IOUSBHostFamily) AppleUSBIORequest: AppleUSBIORequest::complete: device 1 (All-In-One-Cable@00100000) endpoint 0x82: status 0xe00002e8 (babble error)
[...]
2024-08-04 16:37:16.962246-0700 0x769      Error       0x0                  0      0    kernel: (IOUSBHostFamily) AppleUSBIORequest: AppleUSBIORequest::complete: device 1 (All-In-One-Cable@00100000) endpoint 0x82: status 0xe00002e8 (babble error)
2024-08-04 16:37:17.018103-0700 0x211996   Default     0x0                  0      0    kernel: (IOAudioFamily) + IOAudioEngine[<private>]::pauseAudioEngine()
2024-08-04 16:37:17.018137-0700 0x211996   Error       0x0                  0      0    kernel: (IOUSBHostFamily) AppleUSBXHCIPipe: IOUSBHostPipe::abortGated: device 1 (All-In-One-Cable@00100000) endpoint 0x02: aborting 2 requests

agrif commented 3 months ago

@lha I believe the version of the firmware you flashed was before the DFU programming stuff was added. On those earlier firmwares, you need to short the outer pins on the programming header to enter DFU mode, as described in the initial programming section of the README.

Thanks for posting the log -- I don't know exactly what to make of the details, but it looks like MacOS is occasionally running in to a communication error with the AIOC and completely resetting the audio device, which is causing the issue. It's still not clear whether the communication error is MacOS misbehaving or the AIOC.

Edit: a brief search seems to indicate that a USB 'babble' error means the device is sending more bytes during a transaction than the host is asking for, and usually indicates a bug in the device itself (although sometimes it's a bug in the driver.)

skuep commented 3 months ago

I believe the version of the firmware you flashed was before the DFU programming stuff was added.

Yep, exactly. Probably shouldn't use the old firmware from above anyway

Edit: a brief search seems to indicate that a USB 'babble' error means the device is sending more bytes during a transaction than the host is asking for, and usually indicates a bug in the device itself (although sometimes it's a bug in the driver.)

I also tried to briefly look for the babble error.. Does the error only occur, once Direwolf starts transmitting? (Sound output is active) Or is it also, when Direwolf is just listening? (Sound input is active). In both situations, the AIOC sends data back to the host. In case the sound input is active, the AIOC sends microphone data. In case of the sound output, the AIOC sends feedback data to regulate the sample rate buffer. The babble error has to be related to one of those two (EDIT: Log explicitly says endpoint 0x82 which is indeed the feedback endpoint). Would be good to narrow down which one it is. Maybe there is still a wrong descriptor somewhere, that describes the wrong number of bytes that need to be received by the host..

EDIT: If the issue is confirmed to be only during transmission (audio output), then the following could be a possible culprit. It's related to the transmission of the feedback value (from AIOC to PC) so the PC knows how fast the AIOC is outputting the audio (i.e. samplerate). https://github.com/hathach/tinyusb/blob/1eb6ce784ca9b8acbbe43dba9f1d9c26c2e80eb0/src/class/audio/audio_device.c#L2690 Note how it says // 4th byte is needed to work correctly with MS Windows (sigh, see https://github.com/hathach/tinyusb/issues/1234). The endpoint is actually 4 bytes in size, so theoretically it's no problem to send back 4 bytes of feedback data (and in case of Windows even required?). But the actual USB spec says it should be a 3-byte value. So maybe Apple is extremely close to the spec (wouldn't surprise me) and refuses to work with an additional zero byte appended.

In summary, for full-speed endpoints, the F f value shall be encoded in an unsigned 10.10 (K=10) format which fits into three bytes. Because the maximum integer value is fixed to 1,023, the 10.10 number will be left-justified in the 24 bits, so that it has a 10.14 format. Only the first ten bits behind the binary point are required. The lower four bits may be optionally used to extend the precision of F f , otherwise, they shall be reported as zero. For high-speed endpoints, the F f value shall be encoded in an unsigned 12.13 (K=13) format which fits into four bytes. The value shall be aligned into these four bytes so that the binary point is located between the second and the third byte so that it has a 16.16 format. The most significant four bits shall be reported zero. Only the first 13 bits behind the binary point are required. The lower three bits may be optionally used to extend the precision of F f , otherwise, they shall be reported as zero.

(USB2.0 Spec 5.12.4.2)

We are currently sending the 16.16 format always (despite being a full speed device). I can make a test firmware to test explicit 10.14 feedback value with exactly 3 bytes as required by the spec to see if this is indeed the issue.

skuep commented 3 months ago

Update: Pulling this into here, from the reply I got in the issue https://github.com/hathach/tinyusb/issues/1234

https://github.com/hathach/tinyusb/pull/2328#issuecomment-1944087332 This is very likely our issue... I will monitor, but in the meantime I think we have to exclude MacOS support on the AIOC. :-\

agrif commented 3 months ago

As I remember it, the issue is only when playing audio out of the AIOC. Audio input works fine. If I get the time I'll double-check, but it sounds like this lines up with this expected issue.

Excellent find! I'm still reading, but it sounds like it's possible to make the endpoint work on MacOS or Windows, but not both, is that correct? If so, how much code change would be needed to lock the MacOS behavior behind an #ifdef or something? I wouldn't mind compiling firmware myself for this, and I only ever intend to use my AIOC on linux and mac.

lha commented 3 months ago

Recving audio (reading from the host seed) works fine, it the transmit that is causing issue, I have similar issues on linux btw

skuep commented 3 months ago

Recving audio (reading from the host seed) works fine, it the transmit that is causing issue, I have similar issues on linux btw

It's impossible for this to be related to this issue. The Linux kernel driver doesn't care about this particular issue with the feedback endpoint.

To be honest you are the first person with Linux issues, what distro are you using? Pipewire or pulseaudio? It's probably best if you open a separate issue

skuep commented 3 months ago

Excellent find! I'm still reading, but it sounds like it's possible to make the endpoint work on MacOS or Windows, but not both, is that correct? If so, how much code change would be needed to lock the MacOS behavior behind an #ifdef or something? I wouldn't mind compiling firmware myself for this, and I only ever intend to use my AIOC on linux and mac.

It could be possible. In that case I would like to get the linked pull request in tiny USB merged and update my submodule reference to tinyusb. Then we can also use their new feedback mechanism and the MacOS/Rest Switch.

agrif commented 3 months ago

It looks like the PR https://github.com/hathach/tinyusb/pull/2328 was merged. It also looks like they might try some OS detection to work around this bug, although it might be fragile.

skuep commented 3 months ago

Yeah, interesting. I have to check deeper on how well the OS detection works and how he solves the issue with altering the configuration Descriptor (after it has possibly been sent to the host already?).

I am planning a AIOC firmware session in my holidays end of September for doing all the changes, updating tinyusb and finally getting the settings interface to work on Windows.

lha commented 3 months ago

It's impossible for this to be related to this issue. The Linux kernel driver doesn't care about this particular issue with the feedback endpoint.

To be honest you are the first person with Linux issues, what distro are you using? Pipewire or pulseaudio? It's probably best if you open a separate issue

File https://github.com/skuep/AIOC/issues/84 about is. Using Ubuntu server, I'll try lower power and switch to use a jpole further away and slap on some torrids on the usb cable.

skuep commented 1 month ago

Took me a while to figure out the pull request https://github.com/hathach/tinyusb/pull/2328 but in the end it was not a lot to implement. Here is a test firmware that should now theoretically work on Windows, Linux and MacOS. From what I can tell, Linux seems to be working fine.

Can everyone test this thing under Linux, Windows and especially MacOS?

aioc-fw-1.3.0-rc.2-uacquirk.zip

agrif commented 1 month ago

I found the time today to find my AIOC and flash it, and I can verify that the new firmware works just great on MacOS 12.7.5. Before testing, I verified that the old firmware still exhibits the same buggy behavior, and flashing the new firmware immediately fixed it.

I also tested it out on an old Debian bullseye install I had around and it worked fine there as well. Unfortunately I can't easily test on windows -- somebody else will have to give it a go.

Thank you so much for your help on this! This ended up being quite a rabbit hole. I have an AIOC now that I can use with my normal laptop!

skuep commented 1 month ago

Thanks a bunch for testing. Yeah, was a wild ride after we got some details on what the problem is and stumbling upon the issue in the tinyusb repo.

Have fun 😁

das-Iro commented 4 weeks ago

I have tested the

aioc-fw-1.3.0-rc.2-uacquirk.zip Firmware

Audio works as previous under Linux (sometimes it sounds like sigle input samples are lost, could be a PipeWire problem or my radio though)

On MacOS it does work I do not hear any dropped samples. I have done about 1h of packet radio with it just now.

Perhaps this is a me problem. On both systems I get huge QRM +35dB from N0 on 2m when the AOIC is active streaming audio. The QRM is measured with a TinySA some meters away. I have also measured it with the 1.2.0 firmware. Perhaps I burned one of my pins. I will test this with a friends AIOC.

skuep / AIOC

Choppy transmit audio when using Dire Wolf on macOS #13