|
| From: | BALATON Zoltan |
| Subject: | Re: [PATCH v7 6/7] mac_newworld: Deprecate mac99 "via" option |
| Date: | Sat, 28 Jan 2023 00:03:39 +0100 (CET) |
On Fri, 27 Jan 2023, BALATON Zoltan wrote:
On Fri, 27 Jan 2023, BALATON Zoltan wrote:On Thu, 26 Jan 2023, Howard Spoelstra wrote:On Thu, Jan 26, 2023 at 9:57 PM BALATON Zoltan <balaton@eik.bme.hu> wrote:On Thu, 26 Jan 2023, Howard Spoelstra wrote:Mac OS X #10.0 bus1 mouse: usb_ohci_stop pci-ohci: USB Suspended. Reverts to adb mouse. No recognition as HID device. #10.0 bus2 kbd: usb_ohci_stop pci-ohci: USB Suspended. Up to that pointkbdpcap shows normal interrupt operation and recognition as HID device #10.0 bus1 kbd: usb_ohci_stop pci-ohci: USB Suspended. Up to that pointkbdpcap shows normal interrupt operation and recognition as HID device #10.0 bus2 mouse: usb_ohci_stop pci-ohci: USB Suspended. Reverts to adb mouse. pcap shows no recognition as HID device. #10.0 in both cases apple system profiler shows 2 usb buses but nodevices.These are all the logs I get booting a 10.0 install iso with mac99,via=pmu============================================================= OpenBIOS 1.1 [May 25 2022 20:04] Configuration device id QEMU version 1 machine id 1 CPUs: 1 Memory: 256M UUID: 00000000-0000-0000-0000-000000000000 CPU type PowerPC,G4milliseconds isn't unique.switching to new context: call-method slw_update_keymap failed with error ffffffdf call-method slw_update_keymap failed with error ffffffdfusb_ohci_reset pci-ohci usb_ohci_stop pci-ohci: USB Suspended usb_ohci_set_ctl pci-ohci: new state 0x0 usb_ohci_stop pci-ohci: USB Suspended usb_ohci_port_detach port #0 usb_ohci_port_attach port #0 usb_ohci_port_detach port #1 usb_ohci_port_attach port #1 dbdma_unassigned_flush: use of unassigned channel 0 dbdma_unassigned_flush: use of unassigned channel 0 usb_ohci_mem_write_bad_offset 0x30 usb_ohci_set_ctl pci-ohci: new state 0x80 usb_ohci_start pci-ohci: USB Operational usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_set_ctl pci-ohci: new state 0xc0 usb_ohci_stop pci-ohci: USB Suspended usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_port_reset port #0 It's probably OK until it restarts but the seems to be stopped. Anybody wants to have a look? Maybe start with finding what the states mean.I get the same with two usb-ohci controllers (so 6 ports) running Mac OS 9.0.4: usb_ohci_set_ctl pci-ohci: new state 0x80 usb_ohci_start pci-ohci: USB Operational usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_hub_power_up powered up all ports usb_ohci_port_reset port #0 usb_ohci_port_reset port #0 So both usb mouse and kbd do not work. the pcap file for the mouse stalls here: 12 0.007048 0.1.0 host USB 64 SET CONFIGURATION ResponseMaybe the driver gets something from the emulated HID device that it cannot handle and stops during init? Can you reproduce the same with OS X 10.0 and try to correlate the events you see in pcap and trace with the driver source or find out how to enable and read the messages in the driver (unless these are stripped from the binary in Mac OS X but maybe there's something in the guest logs; ave you checked those?) In QEMU the usb-kbd and mouse are implemented in hw/usb/dev-hid.c but this file does not have any debuging or traces. You might try to add some printfs for testing.However, when I use the usb probe tool from the USB DDK, to probe the busesI see the host emit a get descriptor 13 115.761725 host 0.0.0 USB 64 GET DESCRIPTOR Request DEVICE 14 115.761803 0.0.0 host USB 72 GET DESCRIPTOR Response DEVICE 15 115.773719 host 0.0.0 USB 64 SET ADDRESS Request etc. and this time the mouse is recognised as HID device, the host starts polling it and mouse and kbd start to work.It could be possible that the driver did not get to this point but once something else get's past that it recognises the device but I have no idea how this works and not even sure which OS you had this result with. Is this still 9.0.4? That's hard to debug because we don't know what its driver is doing.Is there a Darwin, OpenDarwin or whatever was that called during the years iso that boots on this machine (also on the real one)? That should be fully open source and probably have the same drivers as Mac OS X so reproducing with that could give some more info or maybe its driver is more verbose about errors and has debugging. So you could try to find an early Darwin version that's about the same time as early OS X versions or look at the IOHIDFamily and try to find what part of it is running when you see the logs (as this driver is quite complex it may not be easy).The oldest Darwin CD I could find is 6.2 which boots and works so it's not old enough for us.The simplest driver is in the oldest 10.0 version so maybe we should try to look at that:https://github.com/apple-oss-distributions/IOHIDFamily/tree/IOHIDFamily-6 and the low level part is in the xnu kernel: https://github.com/apple-oss-distributions/xnu/tree/xnu-123.5/iokit/Families/IOHIDSystemI don't quite know how it works and where it starts running but a large part of it looks like it handles key mapping. While booting I see an error from OpenBIOS saying:call-method slw_update_keymap failed with error ffffffdf
After finding out this error is not causing the problem I've tried to 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)
call-method slw_update_keymap failed with error ffffffdf
ohci_mem_write: HcRhPortStatus[1] 54 21 <- 1 ohci_mem_read: HcRhPortStatus[1] 54 21 -> 101 ohci_mem_read: HcRhPortStatus[1] 54 21 -> 101 ohci_mem_read: HcRhPortStatus[1] 54 21 -> 101 ohci_mem_read: HcRhPortStatus[1] 54 21 -> 101 ohci_mem_write: HcRhPortStatus[2] 58 22 <- 1 ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101 ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101 ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101 ohci_mem_read: HcRhPortStatus[2] 58 22 -> 101 ohci_mem_write: HcRhPortStatus[3] 5c 23 <- 1 ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100 ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100 ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100 ohci_mem_read: HcRhPortStatus[3] 5c 23 -> 100 ohci_mem_write: HcCommandStatus 8 2 <- 1 usb_ohci_reset pci-ohci usb_ohci_stop pci-ohci: USB Suspended ohci_mem_write: HcControl 4 1 <- 0 usb_ohci_set_ctl pci-ohci: new state 0x0 usb_ohci_stop pci-ohci: USB Suspended usb_ohci_port_detach port #0 usb_ohci_port_attach port #0 usb_ohci_port_detach port #1 usb_ohci_port_attach port #1Up ro this point happy Mac is shown so probably still in BootX and this may be happening when it quiesces the OpenBIOS driver. Then the rest is when XNU starts and I get logs with boot-args=-v on screen so probably this is the interesting part:
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 <- fe1100 ohci_mem_write: HcInterruptStatus c 3 <- 2 ohci_mem_write: HcBulkHeadED 28 10 <- f67840 ohci_mem_write: HcControlHeadED 20 8 <- f67880 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_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_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[2] 58 22 <- 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_write: HcRhPortStatus[3] 5c 23 <- 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_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_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 usb_ohci_port_reset port #0 ohci_mem_read: HcRhPortStatus[1] 54 21 -> 100103 ohci_mem_write: HcRhPortStatus[1] 54 21 <- 100000 ohci_mem_read: HcRhPortStatus[1] 54 21 -> 103 ohci_mem_read: HcControl 4 1 -> c0 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 -> 103 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 <- 2Now 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?)
Regards, BALATON Zoltan
| [Prev in Thread] | Current Thread | [Next in Thread] |