Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

UAC2 hang when adjusting volume from M4 Mac Mini running macOS Sequoia #2912

Open
1 task done
ReimuNotMoe opened this issue Dec 24, 2024 · 5 comments
Open
1 task done
Labels

Comments

@ReimuNotMoe
Copy link
Contributor

ReimuNotMoe commented Dec 24, 2024

Operating System

MacOS 15.2 Sequoia

Board

Custom PIC32MM board.

The PIC32MM uses the Chipidea IP. It has all 16 dual-direction EPs and only supports full-speed.

Firmware

Main program

TinyUSB commit: 7c1afa8

examples/device/uac2_speaker_fb with a few tweaks to make it DMA 16bit 192kHz PCM audio to I2S:

  • Fixed sample rate: 192000
  • Bytes per sample: 2
  • Max EP IN size for all AS: 772
  • EP_OUT_SW_BUF_SZ: 772*4

The tud_audio_*_req_* and tud_audio_feature_unit_* functions are unchanged.

Globals

static int32_t spk_buf[CFG_TUD_AUDIO_FUNC_1_EP_OUT_SZ_MAX / 4 * 2];
static uint16_t spk_buf_chunk_size = 768;
static volatile uint8_t spk_buf_idx = 0;
static volatile uint8_t buffer_changed = 0;

static inline uint16_t* get_current_spk_buf_chunk() {
    auto* bytep = (uint8_t*)&spk_buf;
    bytep += spk_buf_chunk_size * spk_buf_idx;
    return (uint16_t*)bytep;
}

The main loop

while (1) {
    tud_task();

    if (buffer_changed) {
        auto avail = tud_audio_available();
        if (avail >= spk_buf_chunk_size) {
            auto* cur_spk_buf = get_current_spk_buf_chunk();
            tud_audio_read(cur_spk_buf, spk_buf_chunk_size);
            buffer_changed = 0;
        }
    }

}

The USB interrupt handler

extern "C" void __attribute__ ((interrupt, use_shadow_register_set, keep_interrupts_masked)) USBInterrupt() {
    tud_int_handler(0);
}

The I2S DMA interrupt handler

extern "C" void __attribute__ ((interrupt, use_shadow_register_set, keep_interrupts_masked)) DMA1Interrupt() {
    if (DCH1INTbits.CHSHIF) {
        // First half transmitted
        spk_buf_idx = 0;
    } else if (DCH1INTbits.CHBCIF) {
        // Second half transmitted
        spk_buf_idx = 1;
    }

    buffer_changed = 1;

    // Clear interrupt flags
    DCH1INTCLR = 0xff;
    IFS3CLR = (1 << _IFS3_DMA1IF_POSITION);
}

Platform

Device

PIC32MM (full-speed, dcd_pic.c), bare metal (osal_none)

Compiler

Using built-in specs.
COLLECT_GCC=/data3/pic32tc-build/output/bin/mipsel-elf-g++
COLLECT_LTO_WRAPPER=/data3/pic32tc-build/output/libexec/gcc/mipsel-elf/14.2.0/lto-wrapper
Target: mipsel-elf
Configured with: /data3/pic32tc-build/gcc-14.2.0-pre/configure --target mipsel-elf --prefix /data3/pic32tc-build/output --enable-multilib --disable-libmudflap --disable-libgomp --enable-lto --enable-linker-build-id --disable-nls --disable-shared --disable-thread --disable-libssp --with-newlib --enable-languages=c,c++
Thread model: single
Supported LTO compression algorithms: zlib zstd
gcc version 14.2.0 (GCC) 

What happened ?

When the board is connected to an M4 Mac Mini running macOS 15.2 Sequoia, adjusting the volume can cause TinyUSB to hang.

This isn't happening when-

Connecting other USB audio devices to the Mac Mini:

  • Shanling UA2 (high-speed)
  • Sound Blaster X7 (high-speed)
  • Focusrite Scarlett 2i2 (high-speed)
  • C-Media CM108 sound card (full-speed)

-and-

Connecting the TinyUSB device to other devices:

  • Linux PC (Debian 12, Linux 6.1.116, AMD TR 2950X, Gigabyte X399 AORUS PRO)
  • Windows PC (Windows 11 24H2, Intel i9-9900K, Asus PRIME Z390-A)
  • Android Phones (Oneplus 13, Xiaomi MIX 2S)

The built-in debugging of TinyUSB didn't help at all (as mentioned below), so I attempted my investigation by toggling LEDs. Here are the observations:

  • The main loop didn't hang at all. This means tud_task() can be invoked as usual but all USB activity ceased to exist.
  • The USB interrupt isn't disabled when it hangs. But no more USB interrupts will arrive.

How to reproduce ?

  1. Connect the device to an M4 Mac Mini running macOS 15.2 Sequoia.
  2. Start playing music. It works normally.
  3. Open "Audio MIDI Setup" and choose the TinyUSB audio device.
  4. Start dragging the any of the volume sliders. Keep doing it until:
  5. The volume slider will stop responding, either immediately or in half a minute. The mouse icon will change to busy.
  6. A few seconds after that, the audio will hang (like how a 90s PC stopped responding).

Debug Log as txt file (LOG/CFG_TUSB_DEBUG=2)

It's just the usual volume get/set logs from the callbacks.

The problem completely disappears when I enable CFG_TUSB_DEBUG.

I spent half an hour dragging the volume slider back and forth and still unable to reproduce it with CFG_TUSB_DEBUG enabled.

The problem immediately comes back when CFG_TUSB_DEBUG is disabled again.

So please see the "What happened" section for my investigation attempts.

Screenshots

No response

I have checked existing issues, dicussion and documentation

  • I confirm I have checked existing issues, dicussion and documentation.
@ReimuNotMoe
Copy link
Contributor Author

ReimuNotMoe commented Dec 24, 2024

Update: This situation only happens when a 1000Hz report rate USB mouse is connected to the same hub and the mouse is being used for dragging the volume slider.

TinyUSB audio device--
                     |
                USB2.0 Hub ------ Front USB 3.2 Type-C Port of the Mac Mini
                     |
     USB Mouse--------

Update 2: When connecting the TinyUSB audio device to an iPhone 13 Pro Max via an OTG cable, there is a delay when adjusting volume. Example: Drag the volume slider back and forth for 2 times very quickly, then, after a few seconds, the volume slider will move itself for another 2 times.

Please tell me if you need more information.

@HiFiPhile
Copy link
Collaborator

The problem completely disappears when I enable CFG_TUSB_DEBUG.

That's quiet interesting, the opposite case will be easier explained.

What's inside your volume callback (tud_audio_feature_unit_set_request), is there anything needs extra processing time ?

This situation only happens when a 1000Hz report rate USB mouse is connected to the same hub and the mouse is being used for dragging the volume slider.

My surmise that you have a STT (single Transaction Translator) hub, where all FS devices sharing 12Mbps bandwidth. (cf. USB 2.0 specification 11.14)

772 bytes IN is pretty high for FS, when the total bandwidth exceed the limit weird things happens.

@ReimuNotMoe
Copy link
Contributor Author

ReimuNotMoe commented Dec 26, 2024

The problem completely disappears when I enable CFG_TUSB_DEBUG.

That's quiet interesting, the opposite case will be easier explained.

What's inside your volume callback (tud_audio_feature_unit_set_request), is there anything needs extra processing time ?

It's the same as the example, that is, merely overwriting the values in the volume and mute arrays. Nothing else is done.

Now it almost gives me the impression that doing some blocking operation (like printing debugging log over UART) in the callbacks can make the problem go away

This situation only happens when a 1000Hz report rate USB mouse is connected to the same hub and the mouse is being used for dragging the volume slider.

My surmise that you have a STT (single Transaction Translator) hub, where all FS devices sharing 12Mbps bandwidth. (cf. USB 2.0 specification 11.14)

Yes it's a STT hub chip made by GenesysLogic

772 bytes IN is pretty high for FS, when the total bandwidth exceed the limit weird things happens.

I tried to change it to 48000Hz (192 + 4 bytes) and the problem persists...

Since this is only happening with TinyUSB + PIC32MM (Chipidea FS IP) + This USB mouse + This hub + ARM based Apple devices, I really don't know who is to blame lol

@HiFiPhile
Copy link
Collaborator

I think an analyser is needed to see what happened.

Maybe there is something related to bus time allocation and incomplete ISO transfer. Ideally 2 FS ISO packets have 1ms interval, if the bus is occupied the interval could be altered. (On a poorly Intel Gen11 PC I saw 20us between 2 HS ISO packets instead of 125us, wondering why my DAC keeps popping)

At least for DWC2 DCD a special sequence is needed when incomplete IN/OUT ISO transfer happens.

@ClassicOldSong
Copy link

ClassicOldSong commented Dec 27, 2024

Some more detailed information about this bug:

  1. Cheap ass hubs are required
  2. Must have a specific USB mouse or its wireless receiver plugged to the same hub(in this case the Keychron M6, which is very likely to have a poorly implemented USB stack)
  3. Must be Mac mini M4 as host, not sure if other M1-M4 Macs are affected, but Intel ones are fine

The problem does not go away completely when debugging is enabled, it'll still stuck for around 5secs and then reply the control request. It can resume playing then. ISO transports/bulk transports never actually got stuck, only control ones.

When I captured the USB transport using Wireshark, I can see a TT Buffer reset command sent from the host right after the control got a reply after the stuck, but nothing suspicious happened when the last volume control request was sent.

Hubs I tested affected are:

  1. 1a86:8095 WCH
  2. 05e3:0608 Genesys Logic

The specific mouse only needs to be plugged in, no data transfer is required to trigger this bug. In fact, there's totally no log about any transports between the host and mouse in the Wireshark capture.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants