Re: [PATCH v7 6/7] mac_newworld: Deprecate mac99 "via" option

[BALATON Zoltan]

On Mon, 30 Jan 2023, Howard Spoelstra wrote:
> On Sat, Jan 28, 2023 at 3:03 AM BALATON Zoltan <balaton@eik.bme.hu> wrote:
> > On Sat, 28 Jan 2023, BALATON Zoltan wrote:
> > > On Fri, 27 Jan 2023, BALATON Zoltan wrote:
> > > > On Fri, 27 Jan 2023, BALATON Zoltan wrote:
> > > > The simplest driver is in the oldest 10.0 version so maybe we should
> > > > try to look at that:
> > > [...]
> > > find the driver sources but looks like OS X versions before 10.2 don't 
> > > have these low level USB driver sources, Maybe these still used some 
> > > older MacOS drivers? Still not knowing what the guest is trying to do 
> > > I've added some more detailed debug logging to the QEMU hcd-ohci model 
> > > and got this trace while booting OS X 10.0: (Numbers after reg name 
> > > are:
> > > hex reg offset as in docs, dec reg offset / 4 as in hcd-ohci.c, hex value)
[...]
> > > Now somebody could get the OpenHCI specifications and go through it to 
> > > find out what is happening above and if we can spot some difference in 
> > > what QEMU does and what the docs say or the access pattern may suggest 
> > > (such as some interrupt not generated or some value is not as 
> > > documented, etc.). I hope there's somebody interested in fixing it who 
> > > can try to do it. It's not difficult just time consuming. (Or maybe 
> > > there's somebody who already knows OHCI who can spot something wrong 
> > > in the above?)
> >
> > My guess is that we may be hitting this part which has a TODO comment:
> >
> > https://gitlab.com/qemu-project/qemu/-/blob/master/hw/usb/hcd-ohci.c#L1280
> >
> > I think it may try to detect if devices are connected to the ports and
> > maybe expects an interrupt when tho port status changes but I'm not sure
> > I've read the docs and log correctly. If sombody understands what this
> > TODO comment is about we can try to implement it and see if that helps.

I've tried to implement that but we don't seem to go there because QEMU 
claims the ports are always powered and devices are always connected so 
the OHCI_PORT_CCS (CurrentConnectStatus) it test for is set therefore it 
won't hit the missing resume here. I've tried forcing a resume and Resume 
Detect interrupt on reset but it did not make it work for me. I've added 
some more debug logs though so here's what I see with OS X 10.0 after it 
starts loading the driver (when text appears with verbose boot):

(mem_read/mem_write: reg name, hex offset decimal offset/4, hex value;
ohci_port_set_if_connected: ohci, i, val, ohci->rhport[i].ctrl in hex at 
the beginning of the function)

ohci_mem_write: HcControlCurrentED 24 9 <- 0
ohci_mem_write: HcControlHeadED 20 8 <- 0
ohci_mem_write: HcDoneHead 30 12 <- 0
usb_ohci_mem_write_bad_offset 0x30
ohci_mem_write: HcHCCA 18 6 <- fd3500
ohci_mem_write: HcInterruptStatus c 3 <- 2
ohci_mem_write: HcBulkHeadED 28 10 <- fd8840
ohci_mem_write: HcControlHeadED 20 8 <- fd8880
ohci_mem_read: HcFmInterval 34 13 -> 27782edf
ohci_mem_write: HcFmInterval 34 13 <- 27782edf
ohci_mem_write: HcPeriodicStart 40 16 <- 2a2f
ohci_mem_write: HcControl 4 1 <- 0
ohci_mem_write: HcControl 4 1 <- bc
usb_ohci_set_ctl pci-ohci: new state 0x80
usb_ohci_start pci-ohci: USB Operational
ohci_mem_write: HcRhStatus 50 20 <- 28000
ohci_mem_read: HcRhStatus 50 20 -> 8000
ohci_mem_write: HcRhStatus 50 20 <- 18000
usb_ohci_hub_power_up powered up all ports
ohci_mem_write: HcInterruptEnable 10 4 <- 8000003a
ohci_mem_read: HcRhDescriptorA 48 18 -> 203
ohci_mem_read: HcRhDescriptorB 4c 19 -> 0
ohci_mem_write: HcRhPortStatus[1] 54 21 <- 100
ohci_port_set_if_connected: 0x559e2a865de0 0 0 10101
ohci_port_set_if_connected: 0x559e2a865de0 0 0 10101
ohci_port_set_if_connected: 0x559e2a865de0 0 0 10101
ohci_mem_read: HcRhStatus 50 20 -> 8000
ohci_mem_write: HcRhStatus 50 20 <- 18000
usb_ohci_hub_power_up powered up all ports
ohci_mem_read: HcControl 4 1 -> bc
ohci_mem_write: HcControl 4 1 <- 80
ohci_mem_write: HcInterruptStatus c 3 <- 4
ohci_mem_write: HcRhPortStatus[2] 58 22 <- 100
ohci_port_set_if_connected: 0x559e2a865de0 1 0 10101
ohci_port_set_if_connected: 0x559e2a865de0 1 0 10101
ohci_port_set_if_connected: 0x559e2a865de0 1 0 10101
ohci_mem_read: HcRhStatus 50 20 -> 8000
ohci_mem_write: HcRhStatus 50 20 <- 18000
usb_ohci_hub_power_up powered up all ports
ohci_mem_read: HcInterruptStatus c 3 -> 44
ohci_mem_read: HcInterruptStatus c 3 -> 44
ohci_mem_read: HcInterruptEnable 10 4 -> 8000003a
ohci_mem_write: HcInterruptEnable 10 4 <- 8000003a
ohci_mem_write: HcControl 4 1 <- c0
usb_ohci_set_ctl pci-ohci: new state 0xc0
usb_ohci_stop pci-ohci: USB Suspended
ohci_mem_write: HcRhPortStatus[3] 5c 23 <- 100
ohci_port_set_if_connected: 0x559e2a865de0 2 0 100
ohci_port_set_if_connected: 0x559e2a865de0 2 0 100
ohci_port_set_if_connected: 0x559e2a865de0 2 0 100
ohci_mem_read: HcRhStatus 50 20 -> 8000
ohci_mem_write: HcRhStatus 50 20 <- 18000
usb_ohci_hub_power_up powered up all ports
ohci_mem_read: HcInterruptEnable 10 4 -> 8000003a
ohci_mem_write: HcInterruptEnable 10 4 <- 8000007a
ohci_mem_read: HcInterruptEnable 10 4 -> 8000007a
ohci_mem_read: HcInterruptStatus c 3 -> 40
ohci_mem_write: HcInterruptStatus c 3 <- 40
ohci_mem_write: HcInterruptDisable 14 5 <- 40
ohci_mem_read: HcRhStatus 50 20 -> 8000
ohci_mem_read: HcRhDescriptorA 48 18 -> 203
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 10101
ohci_mem_read: HcRhPortStatus[2] 58 22 -> 10101
ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 10101
ohci_mem_write: HcRhPortStatus[1] 54 21 <- 10000
ohci_port_set_if_connected: 0x559e2a865de0 0 0 101
ohci_port_set_if_connected: 0x559e2a865de0 0 0 101
ohci_port_set_if_connected: 0x559e2a865de0 0 0 101
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 101
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 101
ohci_mem_read: HcRhPortStatus[2] 58 22 -> 10101
ohci_mem_write: HcRhPortStatus[2] 58 22 <- 10000
ohci_port_set_if_connected: 0x559e2a865de0 1 0 101
ohci_port_set_if_connected: 0x559e2a865de0 1 0 101
ohci_port_set_if_connected: 0x559e2a865de0 1 0 101
ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101
ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101
ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100
ohci_mem_read: HcInterruptEnable 10 4 -> 8000003a
ohci_mem_write: HcInterruptEnable 10 4 <- 8000007a
ohci_mem_write: HcRhPortStatus[1] 54 21 <- 10
ohci_port_set_if_connected: 0x559e2a865de0 0 0 101
ohci_port_set_if_connected: 0x559e2a865de0 0 0 101
ohci_port_set_if_connected: 0x559e2a865de0 0 10 101
usb_ohci_port_reset port #0
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 120103
ohci_mem_write: HcRhPortStatus[1] 54 21 <- 100000
ohci_port_set_if_connected: 0x559e2a865de0 0 0 20103
ohci_port_set_if_connected: 0x559e2a865de0 0 0 20103
ohci_port_set_if_connected: 0x559e2a865de0 0 0 20103
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 20103
ohci_mem_read: HcInterruptEnable 10 4 -> 8000007a
ohci_mem_read: HcInterruptStatus c 3 -> 40
ohci_mem_write: HcInterruptStatus c 3 <- 40
ohci_mem_write: HcInterruptDisable 14 5 <- 40
ohci_mem_read: HcRhStatus 50 20 -> 8000
ohci_mem_read: HcRhDescriptorA 48 18 -> 203
ohci_mem_read: HcRhPortStatus[1] 54 21 -> 20103
ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101
ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100
ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100
ohci_mem_read: HcInterruptEnable 10 4 -> 8000003a
ohci_mem_write: HcInterruptEnable 10 4 <- 8000007a
ohci_mem_read: HcControl 4 1 -> c0
ohci_mem_write: HcControl 4 1 <- c0
ohci_mem_write: HcInterruptStatus c 3 <- 4
ohci_mem_write: HcControl 4 1 <- d0
ohci_mem_write: HcCommandStatus 8 2 <- 2
ohci_mem_write: HcCommandStatus 8 2 <- 2
ohci_mem_write: HcCommandStatus 8 2 <- 2
ohci_mem_read: HcControl 4 1 -> d0

It seems to enable Root Hub Status Change interrupt and also Resume Detect 
but the latter is also masked in InterruptDisable reg so I'm not sure what 
it tried to do to get some event about connected devices. (I'll try to 
clean these debug logs and make them traces the help debugging sometimes 
later when I find the time.)

> Some additional observations:
>
> When adding an usb device in the monitor with e.g device_add usb-mouse, i
> see an error in the OSX 10.1 system log stating AppleUSBMouse:error getting
> HID descriptor. err=0xe000404f. Looking into that error I find that it
> refers to:
> #define kIOUSBPipeStalled           iokit_usb_err(79)  // 0xe000404f  Pipe
> has stalled, error needs to be cleared
> in e,g,
> https://opensource.apple.com/source/IOUSBFamily/IOUSBFamily-220.4.10/IOUSBFamily/Headers/USB.h.auto.html
>
> In libusb discussions I read something about usb device alternative
> settings not being read correctly by Mac OS or OSX.
> https://github.com/libusb/libusb/issues/838
> Not knowing how to stop the reading of the alternative settings, I removed
> the whole function "void usb_ep_dump(USBDevice *dev):  from hw/usb/core.c

This seems unrelated. The same error could be returned from different 
places but the object orienred design of OS X drivers makes it a bit 
difficult for me to see what's called from where. I've read the first 
available AppleUSBOHCI source from 10.2 but this just defines some methods 
that some parent objects are calling but I could not see how device 
detection on boot should happen. I suspect that it may power down ports 
then get connection or attach events on powering up which does not happen 
with QEMU's always powered ports but I'm not sure this does not correlate 
with the log above. I could identify some methods from the OHCI driver in 
the above log but don't know what calls them. (Also the 10.2 driver is 
different as that works while this from 10.0 fails so likely there were 
some changes there.)

I'm also surprised you could just remove a function and still compile QEMU 
without problem but looks like usb_ep_dump() is just dead code not called 
from anywhere. It seems to be only useful for debugging anyway so it's not 
relevant for this problem. The pipe stalled error probably just means the 
connection has broken.

> I also changed line 1286 in hcd-ohci.c to read: ret = 1

This is more likely what helped.

> After this terrible hack Mac OS 9.0.4 can boot with mac99,via=pmu (when usb
> tracing is) and it has a functional usb kbd and mouse.

> From the above log the only call of ohci_port_set_if_connected() which 
would not return due to val == 0 is the one before reset port #0 where it 
writes the reset bit that should do a reset but your change prevented 
that. So I still don't understand what's happening here and what should be 
happening.

> This does not work with OSX 10.1:
> When started with mac99 and using the monotor in 10.1 a kbd can be added
> and it shows up in the profiler, so the HIDdescriptor seems to have been
> read.  When adding a mouse the HID descriptor is not read.
>
> When I add an usb-kbd to 10.0 it says:
> AppleUSBHub timeout: Port 1 has devZero locked
> AppleUSBHub Releasing devZero lock for port 1
> AppleUSBHubPort: calling releaseDeviceZero()
> USB: AppleUSBOHCI ControlPacketHandler, returning status E00002EB
> AppleUSBHubPort: calling ResetPort().

At least these are some strings we can search for in the sources, although 
they aren't the same sources this driver was compiled from maybe they are 
similar to give some clue. The error seems to be

#define kIOReturnAborted         iokit_common_err(0x2eb) // operation aborted

In 10.2 AppleUSBOHCI does not have ControlPAcketHandler method, maybe it's 
moved to its parent (or I don't get how C++ works or the error message) 
but the closest method is IOUSBController::ControlPacketHandler in 10.2 in

https://github.com/apple-oss-distributions/IOUSBFamily/blob/IOUSBFamily-190.4.1/IOUSBFamily/Classes/IOUSBController.cpp

this has some comment on what it used to do that it now does differently 
but I don't understand it and don't know if it's relevant. The logs above 
suggest that some communication has failed and the reset is due to that. 
Now the question is what's devZero lock and what has timed out? These 
other logs are probably from:

https://github.com/apple-oss-distributions/IOUSBFamily/blob/IOUSBFamily-190.4.1/AppleUSBHub/Classes/AppleUSBHubPort.cpp

which also has some comments on what MacOS 9 used to do but I don't quite 
get what it's doing so somebody with more knowledge about USB or somebody 
willing to dive in these sources might be needed to find this out.

Regards,
BALATON Zoltan