On Sat, Oct 2, 2021 at 5:42 PM BALATON Zoltan <bala...@eik.bme.hu> wrote:
> On Sat, 2 Oct 2021, Howard Spoelstra wrote: > > Both have issues communicating with endpoint 4 (the hid controls volume > > up/down and mute). > > Endpoint 1 should receive the isochronous audio stream, but never does. > > > > After some experimentation with unplugging/plugging the headset and > probing > > the usb stack (using the usb prober from the mac usb ddk for Mac OS 9.2) > at > > some point endpoint 4 communication works for both guests tested. Only > once > > was I able to get sound out and in working in Mac OS 9.2. For OSX I could > > only once get audio in working. > > The async packets are on endpoint 0. I'm not sure the HID endpoint 4 is > normally involved at all unless you push some buttons but it should work > without that so maybe look at the 0 and the audio endpoints instead of > HID that should have no traffic unless you press buttons. > > > Pcap and text logs for both MacOS 9.2 and OSX 10.4 tests included... > > These are way too big to be possible to find anything in them. Maybe you > should do something simpler like boot the guest without the device > attached and discard all logs up to that point. Then start collecting logs > and attach device and play a short sound. Stop collecting log and try to > make sense of where that fails. That's still a lot of traces but should > only contain the relevant info of detecing the device and playing a sound > not a lot of others that makes it difficult to find what's relevant. > > I'm also not sure where's the problem (maybe we have multiple problems). > It also does not work with an emulated usb-audio device but that also > doesn't work with EHCI so it may have a problem by itself (UHCI also seems > to be broken on its own so it does not even work as much as OHCI and > EHCI). You've also said it worked with pass through with a different > device so maybe this only happens with some devices or some sequence of > things these devices are doing. Only allowing one async packet in OHCI > instead of allowing one per endpoint is just a guess that could cause > delays in processing other packets but eventually it should go through > unless one async packet never completes and blocks all later ones or the > delays introduced by this limitaion causes things to go in a way that > guests don't expect and thus fail. > > Regards, > BALATON Zoltan > After some sifting through the logs, I my interpretation of our issue is this: Too many pending is referring to endpoint 0 when something is not completed. Qemu permantly checks endpoint 4 for hid activity, skips when no interrupt occurs. You can see both intermittently in the 1st log below. Too many pending refers to qemu not being able to fully read/get the device descriptors from boot. The too many pending is "solved", with a click on a hid button. That leads to async complete, after which the only activity is to check for interrupts from the hid devices. However, as the descriptors from endpoint 0 are not fully read from boot, endpoint 1 (the actual audio stream) is not available. Unplugging/plugging the usb device in combination with some hid interrupts (me pushing the volume button) can sometimes reload the configuration correctly, so endpoint 1 becomes available and sound can be played through it. usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_async_complete ----------------------------------> me clicking a hid button. usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=95 en=4 d=2 s=0 k=0 f=0 mps=37 After unplugging/plugging the device and some ep 4 traffic generated by button clicks, ep 1 also becomes active: usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_async_complete usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending usb_ohci_ed_pkt_flags fa=96 en=4 d=2 s=0 k=0 f=0 mps=37 usb_ohci_ed_pkt_flags fa=96 en=1 d=1 s=0 k=0 f=1 mps=192 usb_ohci_ed_pkt_flags fa=96 en=0 d=0 s=0 k=0 f=0 mps=64 usb_ohci_td_too_many_pending
