USB Hub Overcurrent (usb_hub.c.diff)

[archimedes.gaviola_gmail.com]

Summary

This submitted diff file is based from the discussion here https://lists.freebsd.org/archives/freebsd-arm/2022-May/001329.html on adding extended lines of code in usb_hub.c to be able to further handle USB devices when over-current condition is experienced.

As a background, the existing code will shut-off the USB hub port(s) right away after encountering overcurrent and these code extensions will give chance to USB devices by turning on the USB hub port power by calling usbd_req_set_port_feature() with UHF_PORT_POWER argument. Turning on the USB hub port power will verify if the current gets normalized when a USB device is already plugged-in to a port because unlike the first time when the USB device is inserted, there's a tendency of an abrupt current being introduced to the system. So, when there's overcurrent situation and when the USB device status is normal, the wPortChange value will just change from 0x0008 (UPS_C_OVERCURRENT_INDICATOR) to 0x0001 (UPS_C_CONNECT_STATUS) otherwise when the USB device status is not normal, it will be re-validated for overcurrent situation thus calling again the usbd_req_clear_port_feature() with UHF_C_PORT_OVER_CURRENT argument to sets the ports power to shut-off.

[• hselasky]

Please update your patch! There is an "update diff" selection in the "menu".

BTW: You should use:

usb_port_powerup_delay

from

usb_debug.h

And not the XXX_spec value.

[archimedes.gaviola_gmail.com]

Added sleep in the code before turning-on the power.

[archimedes.gaviola_gmail.com]

In D35146#796851, @hselasky wrote:

Please update your patch! There is an "update diff" selection in the "menu".

BTW: You should use:

usb_port_powerup_delay

from

usb_debug.h

And not the XXX_spec value.

Thank you very much Hans! This is noted, the updated diff is now using usb_port_powerup_delay parameter. On my way recompiling the kernel for re-test.

[• hselasky]

/usr/src/sys/dev/usb/usb_hub.c

1051

FreeBSD Style: 4-space indent when you wrap long lines

The pause should be after UHF_PORT_POWER .

1056

Is there some kind of fail-safe mechanism here?

How many times can we re-turn on power again? Forever?

[• hselasky]

I suggest you add a counter which resets on overcurrent not set, and counts to 3 before giving up power on.

We don't want to cause a fire :-)

[archimedes.gaviola_gmail.com]

In D35146#796859, @hselasky wrote:

I suggest you add a counter which resets on overcurrent not set, and counts to 3 before giving up power on.

We don't want to cause a fire :-)

Oh my... this is noted. Let me figure-out the code again and revise.

[archimedes.gaviola_gmail.com]

In D35146#796860, @archimedes.gaviola_gmail.com wrote:

In D35146#796859, @hselasky wrote:

I suggest you add a counter which resets on overcurrent not set, and counts to 3 before giving up power on.

We don't want to cause a fire :-)

Oh my... this is noted. Let me figure-out the code again and revise.

Honestly, last night when I read your comment on "causing fire" I was really alarmed having these added codes if it's really safe and I thinking if it is harmful because my RPi 3B whom I used for this testing are running 24-hours for the past 3 weeks now with my PL2303 device attached. Almost every night I perform kernel re-compiling and up to now it's still normal and operational.

/usr/src/sys/dev/usb/usb_hub.c

1051

Noted on the 4-space indent, thanks!

Re-organizing the code on putting the pause after UHF_PORT_POWER will not turn-on my PL2303 device unless I unplug it and then execute the "usbconfig reset" command then plug it back again. This is the experience.

1056

Yes, the fail-safe mechanism are the lines covering from 1060-1070 on re-validating overcurrent if it still exists. The uhub_read_port_status(sc, portno) will always notify if the existence of the UPS_C_OVERCURRENT_INDICATOR with 0x0008 value. If UPS_C_OVERCURRENT_INDICATOR still exists then it will execute usbd_req_clear_port_feature() function to shut-off the ports again but once it's non-existing as per validation in the if-statement (sc->sc_st.port_change & UPS_C_OVERCURRENT_INDICATOR) then it will exit.

As per re-testing observation with verbose generated logs (hw.usb.uhub.debug=17) re-turn on power happened only once in port-by-port basis. It's not forever as you can see in the logs below for RPi 3B and 4B.

With RPi 3B (power is ganged on port 2 so all the ports are activated once up),
uhub_read_port_status: port 2, wPortStatus=0x0000, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Overcurrent on port 2.
uhub_explore: Turn on power on port 2.

With RPi 4B,
uhub_read_port_status: port 2, wPortStatus=0x0680, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Overcurrent on port 2.
uhub_explore: Turn on power on port 2.
uhub_read_port_status: port 2, wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_read_port_status: port 3, wPortStatus=0x0680, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Overcurrent on port 3.
uhub_explore: Turn on power on port 3.
uhub_read_port_status: port 3, wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_read_port_status: port 4, wPortStatus=0x0680, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Overcurrent on port 4.
uhub_explore: Turn on power on port 4.
uhub_read_port_status: port 4, wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_read_port_status: port 5, wPortStatus=0x0680, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Overcurrent on port 5.
uhub_explore: Turn on power on port 5.
uhub_read_port_status: port 5, wPortStatus=0x06a0, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_read_port_status: port 1, wPortStatus=0x0403, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: udev=0xffffa0000e8d6000 addr=1
uhub_read_port_status: port 1, wPortStatus=0x0000, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Overcurrent on port 1.
uhub_explore: Turn on power on port 1.
uhub_read_port_status: port 1, wPortStatus=0x0101, wPortChange=0x0001, err=USB_ERR_NORMAL_COMPLETION
uhub_reattach_port: reattaching port 1
uhub_read_port_status: port 1, wPortStatus=0x0101, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION

[archimedes.gaviola_gmail.com]

/usr/src/sys/dev/usb/usb_hub.c

1051

Noted on the 4-space indent, thanks!

Re-organizing the code on putting the pause after UHF_PORT_POWER will not turn-on my PL2303 device unless I unplug it and then execute the "usbconfig reset" command then plug it back again. This is the experience.

Okay, so to understand better the behavior with pause code placed after UHF_PORT_POWER I added temporary checkpoints to track the flow of the wPortChange value. It turns out that wPortChange missed or didn't transition from UPS_C_OVERCURRENT_INDICATOR (0x0008) to UPS_C_CONNECT_STATUS (0x0001) when hitting the pause code to 300ms (lines 1060-1064) which leads to fallback to overcurrent condition and then shut-off its ports power. Sharing the temporarily revise code for reference.

1038                 err = uhub_read_port_status(sc, portno);
1039                 if (err != USB_ERR_NORMAL_COMPLETION)
1040                         retval = err;
1041
1042                 DPRINTF("Checkpoint-#1 wPortChange value is %u.\n", sc->sc_st.port_change);
1043                 if (sc->sc_st.port_change & UPS_C_OVERCURRENT_INDICATOR) {
1044                         DPRINTF("Checkpoint-#2 wPortChange value is %u.\n", sc->sc_st.port_change);
1045                         DPRINTF("Overcurrent on port %u.\n", portno);
1046                         err = usbd_req_clear_port_feature(
1047                             udev, NULL, portno, UHF_C_PORT_OVER_CURRENT);
1048                         if (err != USB_ERR_NORMAL_COMPLETION)
1049                                 retval = err;
1050
1051                         /* Turn on hub port power if current get normalized. */
1052                         DPRINTF("Checkpoint-#3 wPortChange value is %u.\n", sc->sc_st.port_change);
1053                         DPRINTF("Turn on power on port %d.\n", portno);
1054                         err = usbd_req_set_port_feature(
1055                             udev, NULL, portno, UHF_PORT_POWER);
1056                         if (err != USB_ERR_NORMAL_COMPLETION)
1057                                 retval = err;
1058
1059                         /* Wait for power to come back on. */
1060                         DPRINTF("Checkpoint-#4 wPortChange value is %u.\n", sc->sc_st.port_change);
1061                         DPRINTF("USB_MS_TO_TICKS(usb_port_powerup_delay) for 300 ms.");
1062                         usb_pause_mtx(NULL,
1063                             USB_MS_TO_TICKS(usb_port_powerup_delay));
1064                         DPRINTF("Checkpoint-#5 wPortChange value is %u.\n", sc->sc_st.port_change);
1065
1066                         /* Re-validate if overcurrent still exists. */
1067                         DPRINTF("Checkpoint-#6 wPortChange value is %u.\n", sc->sc_st.port_change);
1068                         err = uhub_read_port_status(sc, portno);
1069                         if (err != USB_ERR_NORMAL_COMPLETION)
1070                             retval = err;
1071                         DPRINTF("Checkpoint-#7 wPortChange value is %u.\n", sc->sc_st.port_change);
1072                         if (sc->sc_st.port_change & UPS_C_OVERCURRENT_INDICATOR) {
1073                                 DPRINTF("Checkpoint-#8 wPortChnage value is %u.\n", sc->sc_st.port_change);
1074                                 DPRINTF("Overcurrent condition on port %u.\n", portno);
1075                                 err = usbd_req_clear_port_feature(
1076                                     udev, NULL, portno, UHF_C_PORT_OVER_CURRENT);
1077                                 if (err != USB_ERR_NORMAL_COMPLETION)
1078                                         retval = err;
1079                                 DPRINTF("Checkpoint-#9 wPortChange value is %u.\n", sc->sc_st.port_change);
1080                         }
1081                         DPRINTF("Checkpoint-#10 wPortChange value is %u.\n", sc->sc_st.port_change);
1082                 }

And here's the logs.

uhub_intr_callback:
usb_needs_explore:
usb_bus_powerd: bus=0xffff000089394000
uhub_explore: udev=0xffffa00001124000 addr=1
uhub_read_port_status: port 1, wPortStatus=0x0503, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#1 wPortChange value is 0.
uhub_explore: udev=0xffffa000015c5000 addr=2
uhub_read_port_status: port 1, wPortStatus=0x0503, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#1 wPortChange value is 0.
uhub_read_port_status: port 2, wPortStatus=0x0000, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#1 wPortChange value is 8.
uhub_explore: Checkpoint-#2 wPortChange value is 8.
uhub_explore: Overcurrent on port 2.
uhub_explore: Checkpoint-#3 wPortChange value is 8.
uhub_explore: Turn on power on port 2.
uhub_explore: Checkpoint-#4 wPortChange value is 8.
uhub_explore: USB_MS_TO_TICKS(usb_port_powerup_delay) for 300 ms.uhub_intr_callback:
usb_needs_explore:
uhub_explore: Checkpoint-#5 wPortChange value is 8.
uhub_explore: Checkpoint-#6 wPortChange value is 8.
uhub_read_port_status: port 2, wPortStatus=0x0000, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#7 wPortChange value is 8.
uhub_explore: Checkpoint-#8 wPortChnage value is 8.
uhub_explore: Overcurrent condition on port 2.
uhub_explore: Checkpoint-#9 wPortChange value is 8.
uhub_explore: Checkpoint-#10 wPortChange value is 8.

[archimedes.gaviola_gmail.com]

In D35146#796859, @hselasky wrote:

I suggest you add a counter which resets on overcurrent not set, and counts to 3 before giving up power on.

Hans, can you further explain this "overcurrent not set"? I'm reading the USB 2.0 specifications here http://sdpha2.ucsd.edu/Lab_Equip_Manuals/usb_20.pdf on the last paragraph on page 339 with continuation on page 340. Thank you so much!

[archimedes.gaviola_gmail.com]

/usr/src/sys/dev/usb/usb_hub.c

1051

Here's also the behavior when my PL2303 device is unplug and then perform "usbconfig reset" and then plug back PL2303 device again. In the captured logs, checkpoint #7 is already showing the transitioned value of wPortChange to 1 from 8. This also traverses the pause code 300ms.

uhub_intr_callback:
usb_needs_explore:
usb_bus_powerd: bus=0xffff000089394000
uhub_explore: udev=0xffffa00001124000 addr=1
uhub_read_port_status: port 1, wPortStatus=0x0503, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#1 wPortChange value is 0.
uhub_explore: udev=0xffffa000015c5000 addr=2
uhub_read_port_status: port 1, wPortStatus=0x0503, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#1 wPortChange value is 0.
uhub_read_port_status: port 2, wPortStatus=0x0000, wPortChange=0x0008, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#1 wPortChange value is 8.
uhub_explore: Checkpoint-#2 wPortChange value is 8.
uhub_explore: Overcurrent on port 2.
uhub_reset_tt_callback: TT buffer reset
uhub_explore: Checkpoint-#3 wPortChange value is 8.
uhub_reset_tt_callback: TT buffer reset
uhub_explore: Turn on power on port 2.
uhub_reset_tt_callback: TT buffer reset
uhub_explore: Checkpoint-#4 wPortChange value is 8.
uhub_explore: USB_MS_TO_TICKS(usb_port_powerup_delay) for 300 ms.usb_needs_explore:
uhub_intr_callback:
usb_needs_explore:
uhub_explore: Checkpoint-#5 wPortChange value is 8.
uhub_explore: Checkpoint-#6 wPortChange value is 8.
uhub_read_port_status: port 2, wPortStatus=0x0101, wPortChange=0x0001, err=USB_ERR_NORMAL_COMPLETION
uhub_explore: Checkpoint-#7 wPortChange value is 1.
uhub_explore: Checkpoint-#10 wPortChange value is 1.
uhub_reattach_port: reattaching port 2
uhub_read_port_status: port 2, wPortStatus=0x0101, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
uhub_reattach_port: Port 2 is in Host Mode
uhub_intr_callback:
usb_needs_explore:
uhub_intr_callback:
usb_needs_explore:
uhub_read_port_status: port 2, wPortStatus=0x0103, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION
usb_bus_port_set_device: bus 0xffff000089394000 devices[6] = 0xffffa00024123000
ugen1.6: <Prolific Technology Inc. USB-Serial Controller> at usbus1

[• hselasky]

I'll get back to you tomorrow. Not working today :-)

[archimedes.gaviola_gmail.com]

In D35146#798139, @hselasky wrote:

I'll get back to you tomorrow. Not working today :-)

Thank you so much Hans! :-) It's weekend so no rush for this, do it in your available and convenient time.

[• hselasky]

I see.

Can you upload the patch with context:

diff -U 999999 sys/dev/usb/usb_hub.c.orig sys/dev/usb/usb_hub.c > usb.diff

--HPS

[• hselasky]

I wonder why there is an overcurrent event happening in the first place ....

[• hselasky]

Hans, can you further explain this "overcurrent not set"? I'm reading the USB 2.0 specifications here http://sdpha2.ucsd.edu/Lab_Equip_Manuals/usb_20.pdf on the last paragraph on page 339 with continuation on page 340.

Did you find an answer?

[archimedes.gaviola_gmail.com]

Changes:

• usb_pause_mtx() function is placed after UHF_PORT_POWER.
• diff enabled in more context output (diff -U 999999)

[archimedes.gaviola_gmail.com]

In D35146#798320, @hselasky wrote:

I see.

Can you upload the patch with context:

diff -U 999999 sys/dev/usb/usb_hub.c.orig sys/dev/usb/usb_hub.c > usb.diff

--HPS

Hans, just a while ago I upload usb.diff file.

[archimedes.gaviola_gmail.com]

In D35146#798321, @hselasky wrote:

I wonder why there is an overcurrent event happening in the first place ....

My theory is that overcurrent occurs due to USB port power pins first contact with the USB device (PL2303) power pins. There is an abrupt outgoing current happening during this first contact of pins and after some period it slows down and normalized since the power pins are already in contact with each other.

As a background, here's the Prolific PL2303 device that I'm talking about https://filebin.net/g8rj54rzkj5q7kd0, the device showing "VFD Display PD220" which is currently connected to one of the USB ports of my RPi 3B.

[archimedes.gaviola_gmail.com]

In D35146#798323, @hselasky wrote:

Hans, can you further explain this "overcurrent not set"? I'm reading the USB 2.0 specifications here http://sdpha2.ucsd.edu/Lab_Equip_Manuals/usb_20.pdf on the last paragraph on page 339 with continuation on page 340.

Did you find an answer?

I tried asserting port reset with UHF_PORT_RESET placed after the 3ms pause code but to no avail, it did not work.

+ /* Assert port reset. */
+ err = usbd_req_set_port_feature(
+ udev, NULL, portno, UHF_PORT_RESET);
+ DPRINTF("Assert port reset on %u.\n", portno);
+ if (err != USB_ERR_NORMAL_COMPLETION)
+ retval = err;

[archimedes.gaviola_gmail.com]

In D35146#798384, @archimedes.gaviola_gmail.com wrote:

In D35146#798321, @hselasky wrote:

I wonder why there is an overcurrent event happening in the first place ....

My theory is that overcurrent occurs due to USB port power pins first contact with the USB device (PL2303) power pins. There is an abrupt outgoing current happening during this first contact of pins and after some period it slows down and normalized since the power pins are already in contact with each other.

As a background, here's the Prolific PL2303 device that I'm talking about https://filebin.net/g8rj54rzkj5q7kd0, the device showing "VFD Display PD220" which is currently connected to one of the USB ports of my RPi 3B.

I also added a new photo (IMG-1588.JPG) here https://filebin.net/g8rj54rzkj5q7kd0 showing an operational device file /dev/cuaU0 and a working uplcom(4) driver. This PL2303 device is physically attached between the yellow Ethernet cable and the USB keyboard.