[SOVLED]Can't Address Device correctly on xHC

[Oython]

As the title saying, when I perform Address Device command (BSR=0), the xHC returns Command Completion Event with Code 4(USB Transaction Error).I have search on the Internet but found nothing helpful to me.
This is the screen shot on BOCHS:

The screenshot of the usb debugger on BOCHS

I guess that there is something wrong with the Device Context.Could anyone tell me how to solute the problem?

[BenLunt]

Just from the image, you don't have the HID bit set. HID, when clear, tells the controller to use normal streams. Make sure the HID bit is set.

Second, your Average TRB length is zero. It probably should be 8 at this point.

Did you check the port value to make sure it is a low-speed device? If it is a full-speed device, you will need to adjust a few of those values.

You don't give any other information, so that's about all I got for you.

Ben
- https://www.fysnet.net/the_universal_serial_bus.htm

[BenLunt]

I'm curious if you made any progress.

Since you are using Bochs, did you set it up to send debug reports to the log file?
Using configuration lines such as:

Code: Select all

debug: action=ignore, usb_xhci=report
usb_xhci: port3=mouse, options3="speed:low, debug"

Will send quite a bit of debugging to the log file. For example, by simply using the 'debug' option (shown in the second line above), the following is the output for when the host starts to enumerate a USB floppy drive.

Code: Select all

00016914175d[USBFDD] packet hexdump (8 bytes)
00016914175d[USBFDD] 80 06 00 01 00 00 40 00 
00016914175d[USBFDD] USB_REQ_GET_DESCRIPTOR: Device
00016914175d[USBFDD] packet hexdump (18 bytes)
00016914175d[USBFDD] 12 01 01 01 00 00 00 40-44 06 00 00 00 00 01 02 
00016914175d[USBFDD] 03 01 
00016914331d[USBFDD] Reset
00019913704d[USBFDD] packet hexdump (8 bytes)
00019913704d[USBFDD] 00 05 02 00 00 00 00 00 
00019913704d[USBFDD] USB_REQ_SET_ADDRESS:
00019914611d[USBFDD] packet hexdump (8 bytes)
00019914611d[USBFDD] 80 06 00 01 00 00 12 00 
00019914611d[USBFDD] USB_REQ_GET_DESCRIPTOR: Device
00019914611d[USBFDD] packet hexdump (18 bytes)
00019914611d[USBFDD] 12 01 01 01 00 00 00 40-44 06 00 00 00 00 01 02 
00019914611d[USBFDD] 03 01 

When adding 'usb_xhci=report', as shown above, Bochs will send all access to the xHCI HC to the log file as well (last three lines shown below).

Code: Select all

00019915327d[USBFDD] packet hexdump (39 bytes)
00019915327d[USBFDD] 09 02 27 00 01 01 00 80-FA 09 04 00 00 03 08 04 
00019915327d[USBFDD] 00 00 07 05 81 02 40 00-00 07 05 02 02 40 00 00 
00019915327d[USBFDD] 07 05 83 03 02 00 20 
00019915327d[XHCI  ] IN: Transferred 39 bytes, requested 64 bytes
00019915327d[XHCI  ] Found TRB: address = 0x0000000001fb07b0 0x0000000001fc8850 0x000C0040 0x00010C11  1 (SPD occurred = 1)
00019915327d[XHCI  ] Found TRB: address = 0x0000000001fb07c0 0x0000000001fc8890 0x000A0040 0x00010C11  1 (SPD occurred = 1)

However, with both of these set to debug, a simple example log file, like the one I used to extract these examples, can be quite large, this one being 20Meg in size.

The good this is, if you search for 'e[XHCI ]', this will search for all error lines in the file, so you can see where the error is.

Hope this helps and if you wish to share your bootable image file, I can have a look too.

Ben

[Oython]

Thank you so much for your reply.

Make sure the HID bit is set.

Second, your Average TRB length is zero. It probably should be 8 at this point.

Did you check the port value to make sure it is a low-speed device? If it is a full-speed device, you will need to adjust a few of those values.

Having read your reply, I tried to set the Average TRB length to 8 and set HID bit.But still, it doesn't work and the problem is the same.

I'm curious if you made any progress.

Since you are using Bochs, did you set it up to send debug reports to the log file?

I also tried to display the debuge report on the screen, but it seemed that there were not anything help:

Code: Select all

00663952497d[XHCI  ] read  PCI register 0x00 value 0x00151912 (len=4)
00663952569d[XHCI  ] read  PCI register 0x08 value 0x0C033002 (len=4)
00667827882d[XHCI  ] read  PCI register 0x04 value 0x00100106 (len=4)
00667827954d[XHCI  ] write PCI register 0x04 value 0x00100106 (len=4)
00667828020d[XHCI  ] read  PCI register 0x10 value 0xC4000004 (len=4)
00667828091d[XHCI  ] read  PCI register 0x14 value 0x00000000 (len=4)
00667828173d[XHCI  ] register write to  offset 0x0502:  0x0000000000000100 (len=2)
00667828198d[XHCI  ] register write to  offset 0x0058:  0x0000000000000020 (len=4)
00669594774d[XHCI  ] register write to  offset 0x0050:  0x000000000374A000 (len=4)
00669594993d[XHCI  ] register write to  offset 0x0054:  0x0000000000000000 (len=4)
00686125159d[XHCI  ] register write to  offset 0x0038:  0x0000000000000006 (len=4)
00686125163d[XHCI  ] register write to  offset 0x003C:  0x0000000000000000 (len=4)
00687915060d[XHCI  ] register write to  offset 0x0038:  0x0000000003750001 (len=4)
00687915279d[XHCI  ] register write to  offset 0x003C:  0x0000000000000000 (len=4)
00697994791d[XHCI  ] register write to  offset 0x0628:  0x0000000000000001 (len=4)
00697995014d[XHCI  ] register write to  offset 0x0630:  0x0000000003753000 (len=8)
00697995014d[XHCI  ] Interrupter 00: Event Ring Table (at 0x0000000003753000) has 1 entries:
00697995014d[XHCI  ]  00:  address = 0x0000000003754000  Count = 256
00697995024d[XHCI  ] register write to  offset 0x0638:  0x0000000003754000 (len=8)
00697995118d[XHCI  ] read  PCI register 0x34 value 0x00000050 (len=4)
00697995201d[XHCI  ] read  PCI register 0x50 value 0xC9C30001 (len=4)
00697995283d[XHCI  ] read  PCI register 0x50 value 0xC9C30001 (len=4)
00699350170d[XHCI  ] register write to  offset 0x0624:  0x000000000000038F (len=4)
00699350174d[XHCI  ] register write to  offset 0x0020:  0x0000000000000004 (len=4)
00699350184d[XHCI  ] register write to  offset 0x0620:  0x0000000000000002 (len=4)
00699350213d[XHCI  ] register write to  offset 0x0640:  0x0000000000000000 (len=4)
00699350222d[XHCI  ] register write to  offset 0x0640:  0x0000000000000000 (len=4)
00699350246d[XHCI  ] register write to  offset 0x0660:  0x0000000000000000 (len=4)
00699350255d[XHCI  ] register write to  offset 0x0660:  0x0000000000000000 (len=4)
00699350279d[XHCI  ] register write to  offset 0x0680:  0x0000000000000000 (len=4)
00699350288d[XHCI  ] register write to  offset 0x0680:  0x0000000000000000 (len=4)
00699350312d[XHCI  ] register write to  offset 0x06A0:  0x0000000000000000 (len=4)
00699350321d[XHCI  ] register write to  offset 0x06A0:  0x0000000000000000 (len=4)
00699350345d[XHCI  ] register write to  offset 0x06C0:  0x0000000000000000 (len=4)
00699350354d[XHCI  ] register write to  offset 0x06C0:  0x0000000000000000 (len=4)
00699350378d[XHCI  ] register write to  offset 0x06E0:  0x0000000000000000 (len=4)
00699350387d[XHCI  ] register write to  offset 0x06E0:  0x0000000000000000 (len=4)
00699350411d[XHCI  ] register write to  offset 0x0700:  0x0000000000000000 (len=4)
00699350420d[XHCI  ] register write to  offset 0x0700:  0x0000000000000000 (len=4)
00700682703d[XHCI  ] register write to  offset 0x0020:  0x0000000000000005 (len=4)
00700682729d[XHCI  ] register write to  offset 0x0420:  0x0000000000000010 (len=4)
00700682753d[XHCI  ] register write to  offset 0x0430:  0x0000000000000010 (len=4)
00700682777d[XHCI  ] register write to  offset 0x0440:  0x0000000000000010 (len=4)
00700682801d[XHCI  ] register write to  offset 0x0450:  0x0000000000000010 (len=4)
00700743680d[XHCI  ] Port #3 Status Change Event: ( 1h)
00700743680d[XHCI  ] Write Event TRB: table index: 0, trb index: 0
00700743680d[XHCI  ] Write Event TRB: address = 0x0000000003754000 0x0000000003000000 0x01000000 0x00008800  (type = 34)
00700743680d[XHCI  ] Interrupt Fired.
00700743680d[XHCI  ] Port #4 Status Change Event: ( 1h)
00700743680d[XHCI  ] Write Event TRB: table index: 0, trb index: 1
00700743680d[XHCI  ] Write Event TRB: address = 0x0000000003754010 0x0000000004000000 0x01000000 0x00008800  (type = 34)
00700743680d[XHCI  ] Interrupt Fired.
00704504386d[XHCI  ] register write to  offset 0x0024:  0x0000000000000018 (len=4)
00726314859d[XHCI  ] register write to  offset 0x0440:  0x0000000000000000 (len=4)
00728368233d[XHCI  ] register write to  offset 0x0440:  0x0000000000000010 (len=4)
00732759964d[XHCI  ] register write to  offset 0x0800:  0x0000000000000000 (len=4)
00732759964d[XHCI  ] Command Doorbell Rang
00732759964d[XHCI  ] Dump command trb: 9  (0x0000000000000000 0x00000000 0x00002401) (1)
00732759964d[XHCI  ] Write Event TRB: table index: 0, trb index: 2
00732759964d[XHCI  ] Write Event TRB: address = 0x0000000003754020 0x0000000003750000 0x01000000 0x01008400  (type = 33)
00732759964d[XHCI  ] Interrupt Fired.
00732759964d[XHCI  ] 0x0000000003750000: Command Ring: Found Enable Slot TRB (slot = 1) (returning 1)
00779342821d[XHCI  ] register write to  offset 0x0638:  0x0000000003754038 (len=8)
00779342834d[XHCI  ] register write to  offset 0x0620:  0x0000000000000003 (len=4)
00812793866d[XHCI  ] register write to  offset 0x0024:  0x0000000000000018 (len=4)
00820533343d[XHCI  ] register write to  offset 0x0638:  0x0000000003754048 (len=8)
00820533356d[XHCI  ] register write to  offset 0x0620:  0x0000000000000003 (len=4)
00832395157d[XHCI  ] register write to  offset 0x0800:  0x0000000000000000 (len=4)
00832395157d[XHCI  ] Command Doorbell Rang
00832395157d[XHCI  ] Dump command trb: 11  (0x0000000003758000 0x00000000 0x01002E01) (1)
00832395157d[XHCI  ] Write Event TRB: table index: 0, trb index: 3
00832395157d[XHCI  ] Write Event TRB: address = 0x0000000003754030 0x0000000003750010 0x01000000 0x01008400  (type = 33)
00832395157d[XHCI  ] Interrupt Fired.
00832395157d[XHCI  ] 0x0000000003750010: Command Ring: SetAddress TRB (bsr = 1) (addr = 0) (slot = 1) (returning 1)
00912473867d[XHCI  ] register write to  offset 0x0024:  0x0000000000000018 (len=4)
00921485856d[XHCI  ] register write to  offset 0x0638:  0x0000000003754058 (len=8)
00921485869d[XHCI  ] register write to  offset 0x0620:  0x0000000000000003 (len=4)
00921486009d[XHCI  ] register write to  offset 0x0800:  0x0000000000000000 (len=4)
00921486009d[XHCI  ] Command Doorbell Rang
00921486009d[XHCI  ] Dump command trb: 11  (0x0000000003758000 0x00000000 0x01002C01) (1)
00921486009e[XHCI  ] Invalid speed (0) specified in Speed field of the Slot Context.
00921486009d[XHCI  ] Write Event TRB: table index: 0, trb index: 4
00921486009d[XHCI  ] Write Event TRB: address = 0x0000000003754040 0x0000000003750020 0x04000000 0x01008400  (type = 33)
00921486009d[XHCI  ] Interrupt Fired.
00921486009d[XHCI  ] 0x0000000003750020: Command Ring: SetAddress TRB (bsr = 0) (addr = 2) (slot = 1) (returning 4)
01001994641d[XHCI  ] register write to  offset 0x0024:  0x0000000000000018 (len=4)
01012356883d[XHCI  ] register write to  offset 0x0638:  0x0000000003754068 (len=8)
01012356896d[XHCI  ] register write to  offset 0x0620:  0x0000000000000003 (len=4)

By the way, I found something strange: the port status register the debugger showing is all zero.

the screenshot of the USB debugger

Is this phenomenon right?

[BenLunt]

Hi,

The error is shown in the listing you provided:
(Remember, even though the listing may be quite long, simply searching for "e[XHCI" will search for every line that shows an error associated with the xHCI.)

Code: Select all

00921486009e[XHCI  ] Invalid speed (0) specified in Speed field of the Slot Context.

You are not providing a speed value for the device. Somewhere between the time you show the Slot Context in your first post above to where the code reaches this point, you have cleared (at least) the Speed field. Another possibility is that you now have a bad pointer to a non-existent Slot Context, where coincidently that field happens to be zero.

By the way, I found something strange: the port status register the debugger showing is all zero.

Yes, this is correct behavior, but it probably isn't apparent why. The reason is the USB Debugger breaks and shows the current values *before* it processes the reason for the break.

(I remember it then breaking *after* it processes it so that you can see the results. However, after looking back, apparently, I only added that to the UHCI and not the xHCI. The UHCI breaks *before* and then again *after*. The xHCI does not. I will have to look into why I didn't add this to the xHCI.)

For now, simply continue and when it breaks again, it will show the status of the previous break because of the fact that it breaks *before* it processes the reason for the break. Simply click on the previous TRB within the list and click on "View TRB" to see the result of executing that TRB.

I will have a look and make it more apparent that it breaks *before* instead of after. The UHCI shows the words *before* and *after* in the title of the offending window. It shouldn't be too difficult to add the same function for the xHCI.

Ben

[Oython]

Hello

You are not providing a speed value for the device.

Actually I have tried to set it to 2 for low speed device but it didn't work.I think that it is not the main problem.

By the way, I found something strange: the port status register the debugger showing is all zero.

Yes, this is correct behavior, but it probably isn't apparent why. The reason is the USB Debugger breaks and shows the current values *before* it processes the reason for the break.

It seems that this is not the debugger's problem, but the xHC on BOCHS's.Because I found that the register read on my OS is also ZERO on BOCHS but non-zero on either Vmware or real hardware.

The log of my OS on BOCHS

屏幕截图 2025-10-02 210030.png (2.41 KiB) Viewed 58903 times

It is really confusing.

[BenLunt]

You are not providing a speed value for the device.

Actually I have tried to set it to 2 for low speed device but it didn't work.I think that it is not the main problem.

It may not be the main problem, but it will not proceed without a valid speed value.

It seems that this is not the debugger's problem, but the xHC on BOCHS's. Because I found that the register read on my OS is also ZERO on BOCHS but non-zero on either Vmware or real hardware. It is really confusing. :?

I won't deny that there might be an error in Bochs, but since numerous tests with modern and not-so modern, commercial and non-commercial systems all are successful, let's see what you might be doing differently to get the results you are getting.

1) Did you check to see if the controller is using 32-bit or 64-bit addressing? If 64-bit addressing, did you make sure and clear the high-order parts of the register(s), if applicable.
2) Are you giving the controller physical addresses or virtual addresses?
3) Remember that the count of slots, interrupters, etc., is not static. It can be different for different controllers.
4) Did you use the controller's Capabilities to retrieve the order the register ports are using? It is not standard (though it is normal) for the first to be USB3 and the last to be USB2. It can be in any order. If you are reading from a non-existing or non-connected port register, you can read zero.
5) Did you check the CONTEXT Size field? It can be 64 bytes or 32 bytes.
6) Did you allocate the scratch pad registers? If not, where is the controller writing its scratch to?
7) Did you power the port before trying to read from it. A port can be without power on boot up. An unpowered port will read zero. Read the HCCPARAMS1 register to see if power is always on or can be off.
8) Are you assuming the location of each register set or do you retrieve these offsets from the controller? DOORBELL_OFF, RUNTIME_OFF, etc.
9) Are you aligning the control structures on the specified page boundary? (PAGE_SIZE register) Should default to 4k but can be different.
10) Are you reading all registers as 32- or 64-bit access? Does your complier's optimizer contradict that? Your compiler can optimize the read from:

Code: Select all

  mov  eax,[0x12345678]   ; 32-bit read on 32-bit offset
  and  eax,0xFF

to

Code: Select all

  mov  al,[0x12345678]  ; 8-bit read on 32-bit offset

which will be in error.

Do you have a bootable image to download so that I can run a few tests?

Again, I am not denying it is an error in Bochs, but with all that has been done, I am heavily leaning toward your specific instance is at fault. It may be something very simple, but highly overlooked. Just because it works on VMWare and real hardware, doesn't make it correct. (Case in point)

Ben
- https://www.fysnet.net/the_universal_serial_bus.htm

[Oython]

Thanks for your so detailed reply!

7) Did you power the port before trying to read from it. A port can be without power on boot up. An unpowered port will read zero. Read the HCCPARAMS1 register to see if power is always on or can be off.

I am sorry that I ignored this indeed.After setting the bit PP to 1, I got correct value from the port registers.
And also, my code works on Bochs!However, on real hardware, the problem still remains.
The reason behind the problem is so hard to find that I have spent several month on it.

[BenLunt]

I'm glad you were able to determine what was wrong. I told you it would be something simple and usually overlooked. :-) I've done it many times. I think we all have.

Debugging on real hardware is quite difficult, unless you can afford a USB analyzer. I have a very similar analyzer like the one shown here. It has been extremely helpful in my research, showing exactly what is sent across the wire.

Without an analyzer, the only other advice I can give you is to insert a lot of printf()'s in various places to display the controller's and/or device's state at that particular time. However, you can only print so many lines until they scroll off the screen.

Back in the day, we could plug a null-modem into the serial port and see all of these lines printed, either on the screen or to a file on the other machine. Now that the serial port has gone, it isn't as easy. If you have a working USB stack, you could send it to a thumb drive, but when the device you are debugging is that thumb drive, it doesn't work out so well.

Another option is to print a line or two of information to the screen, with a break identifier (usually just an integer) and pause expecting a keypress to continue. However, this too expects a working HID stack unless you have a PS2 keyboard attached, which followed the serial port's exit from existence as well.

Do you have a working file system within your OS? You can write these lines to a file. Then if you have access to this file, you can view it there. If you do not have access to that file, you will have to shut down, then boot the existing (commercial?) OS to view the file. This works, but takes time and there is a chance of volume corruption if you aren't confident in you file system driver(s). This is where the floppy drive came in. You could write it to the floppy and not worry about accidentally corrupting the volume. But, you can't find many of those anymore either. :-)

Best of luck to you.

[Oython]

Thanks for your suggestions.
I finally find the reason: I ignored the Port Enabled/Disabled(PED) bit of the PortStatusRegister.In fact, the code following is wrong:

Code: Select all

reg |= xxxx

Instead, to prevent writing a 1 to the PED bit, which will lead to disabling the port, it should look like:

Code: Select all

reg = reg & (~0x02) | xxxx 

After correcting the code, I can Address Device now.

I have a very similar analyzer like the one shown here

It's so expensive on that website, but luckily, it's cheap in my country, for which I may buy one.

[BenLunt]

I am glad you found the error and I believe you will find the analyzer very helpful, if you decide to do so.