Re: [RFC][PATCH 2/3] usb: roles: Add usb role switch notifier.

[Hans de Goede]

Hi John,

Sorry for being a bit slow to respond.

On 22-10-2019 07:58, John Stultz wrote:
> On Fri, Oct 18, 2019 at 2:05 PM Hans de Goede <hdegoede@xxxxxxxxxx> wrote:
> > On 18-10-2019 22:37, John Stultz wrote:
> > > At least, with the current driver, the functionality is working as
> > > expected: remove the USB-C cable, and devices connected to the hub
> > > power on, plug something into the USB-C port and devices plugged into
> > > the hub shutdown.
> > >
> > > But maybe I'm missing what you mean?
> >
> > Ok, so double checking the schematic I do see separate Vbus-es for the
> > TypeC port and the TypeA ports, with the TypeC port one being controlled
> > by GPIO_202_VBUS_TYPEC. So ideally that gpio would be  controlled to
> > enable/disable vbus by the tcpm framework.
>
> So I've given this a shot, adding a gpio regulator for the type-c
> vbus, and added a set_vbus hook to the tcpci_rt1711 with logic to
> enable and disable the regulator depending on the source state.  I've
> also added some debug logic to check the regulator disabling/enabling
> is working properly. However, doing the type-c vbus control via the
> tcpm logic doesn't seem to be working properly.
>
> The issue seems to be when the USB-C cable is unplugged the device
> goes into ROLE_NONE, we switch to the on-board hub. Then when we
> connect a USB-C hub to the type-c port, we switch to ROLE_HOST, and
> power on the regulator, and that starts to power on the USB-C hub
> devices. However, since this disconnects/powers down the on-board hub,
> we see the on-board hub device disconnect. I'm guessing the hub
> disconnection causes some confusion in the state machine, as then I
> see the state change from state change SRC_ATTACHED -> SRC_UNATTACHED,
> and set_vbus is immediately called with source=0 and the regulator is
> disabled, and we switch back to ROLE_NONE (which powers on the onboard
> hub).  The system then seems to quickly oscillate between the
> ROLE_HOST and ROLE_NONE switching the regulator on and off fairly
> quickly (see log below for more details) and never really settling for
> one state or the other.
>
> Any off-hand thoughts on what might be going wrong here?

Sorry no clue.

> I'm fine to
> continue digging and working on this approach, but I also don't want
> to have to pollute the core code too much for this oddball hardware
> (esp since doing the vbus control in the role-switch intermediary does
> work ok - or at least better then this approach so far).

Given the special nature of the hardware I'm fine with the OTG intermediary
approach here. IMHO it is fine to just stick with that and to not spend
too much time on this.

Regards,

Hans

> thanks
> -john
>
>
> Starts in ROLE_NONE with nothing connected to type-c port, with the
> on-board hub powered on, then we connect a type-c usb hub.
>
> [   57.828323] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   58.031325] JDB: state change SRC_ATTACH_WAIT -> SNK_TRY [delayed 200 ms]
> [   58.031525] JDB: tcpm_state_machine_work state chage: SNK_TRY->SNK_TRY
> [   58.135273] JDB: state change SNK_TRY -> SNK_TRY_WAIT [delayed 100 ms]
> [   58.135296] JDB: tcpm_state_machine_work state chage:
> SNK_TRY_WAIT->SRC_TRYWAIT
> [   58.149344] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT->SRC_TRYWAIT
> [   58.251273] JDB: state change SRC_TRYWAIT -> SRC_TRYWAIT_UNATTACHED
> [delayed 100 ms]
> [   58.251297] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT_UNATTACHED->SNK_UNATTACHED
> [   58.269076] JDB: tcpm_state_machine_work state chage:
> SNK_UNATTACHED->TOGGLING
> [   58.276789] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   58.323506] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   58.527310] JDB: state change SRC_ATTACH_WAIT -> SRC_ATTACHED
> [delayed 200 ms]
> [   58.527788] JDB: hub_usb_role_switch_set switching to ROLE_HOST!
> [   58.541555] usb usb1-port1: disabled by hub (EMI?), re-enabling...
> [   58.548654] usb 1-1: USB disconnect, device number 2
> [   58.554077] usb 1-1.5: USB disconnect, device number 3
> [   58.560133] JDB: rt1711h_set_vbus  source: 1 sink: 0
> [   58.565377] JDB: rt1711h_set_vbus enabling regulator!
> [   58.570495] type-c-vbus-current-regulator:  being enabled! JDB!
> [   58.586202] type-c-vbus-current-regulator:  enabled successfully?! JDB!
> [   58.602350] rt1711h_set_vbus: vbus := On
> [   58.602354] rt1711h_set_vbus: charge is already Off
> [   58.747321] usb 2-1: USB disconnect, device number 2
> [   58.819706] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACHED->SRC_ATTACHED
> [   58.871270] usb 1-1: new high-speed USB device number 4 using xhci-hcd
> [   59.030402] usb 1-1: New USB device found, idVendor=2109,
> idProduct=2813, bcdDevice=90.11
> [   59.038677] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [   59.045881] usb 1-1: Product: USB2.0 Hub
> [   59.049838] usb 1-1: Manufacturer: VIA Labs, Inc.
> [   59.104926] hub 1-1:1.0: USB hub found
> [   59.109112] hub 1-1:1.0: 4 ports detected
> [   59.327259] JDB: state change SRC_ATTACHED -> SRC_UNATTACHED [delayed 480 ms]
> [   59.327710] JDB: rt1711h_set_vbus  source: 0 sink: 0
> [   59.340022] JDB: rt1711h_set_vbus disabling regulator!
> [   59.345296] type-c-vbus-current-regulator:  disabled successfully?!
> JDB! (ret=0)
> [   59.353458] rt1711h_set_vbus: vbus := Off
> [   59.353465] rt1711h_set_vbus: charge is already Off
> [   59.483278] usb 1-1.1: new low-speed USB device number 5 using xhci-hcd
> [   59.571494] JDB: hub_usb_role_switch_set switching to ROLE_NONE!
> [   59.577810] usb 1-1: USB disconnect, device number 4
> [   59.586675] JDB: tcpm_state_machine_work state chage:
> SRC_UNATTACHED->TOGGLING
> [   59.593896] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   59.600757] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   59.627362] usb 1-1.1: Device not responding to setup address.
> [   59.661413] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   59.839438] usb 1-1.1: Device not responding to setup address.
> [   59.863252] JDB: state change SRC_ATTACH_WAIT -> SNK_TRY [delayed 200 ms]
> [   59.863428] JDB: tcpm_state_machine_work state chage: SNK_TRY->SNK_TRY
> [   59.967359] JDB: state change SNK_TRY -> SNK_TRY_WAIT [delayed 100 ms]
> [   59.967383] JDB: tcpm_state_machine_work state chage:
> SNK_TRY_WAIT->SRC_TRYWAIT
> [   59.981452] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT->SRC_TRYWAIT
> [   60.051272] usb 1-1.1: device not accepting address 5, error -71
> [   60.083337] JDB: state change SRC_TRYWAIT -> SRC_TRYWAIT_UNATTACHED
> [delayed 100 ms]
> [   60.083365] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT_UNATTACHED->SNK_UNATTACHED
> [   60.101151] JDB: tcpm_state_machine_work state chage:
> SNK_UNATTACHED->TOGGLING
> [   60.108462] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   60.155642] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   60.183338] usb 2-1: new SuperSpeed Gen 1 USB device number 3 using xhci-hcd
> [   60.207782] usb 1-1-port1: attempt power cycle
> [   60.212603] usb 2-1: New USB device found, idVendor=0424,
> idProduct=5734, bcdDevice= 2.02
> [   60.220923] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=0
> [   60.228147] usb 2-1: Product: USB5734
> [   60.231883] usb 2-1: Manufacturer: Microchip Tech
> [   60.256450] hub 2-1:1.0: USB hub found
> [   60.260360] hub 2-1:1.0: 5 ports detected
> [   60.359385] JDB: state change SRC_ATTACH_WAIT -> SRC_ATTACHED
> [delayed 200 ms]
> [   60.359853] JDB: hub_usb_role_switch_set switching to ROLE_HOST!
> [   60.374310] JDB: rt1711h_set_vbus  source: 1 sink: 0
> [   60.379386] JDB: rt1711h_set_vbus enabling regulator!
> [   60.384485] type-c-vbus-current-regulator:  being enabled! JDB!
> [   60.390552] hub 2-1:1.0: hub_ext_port_status failed (err = -71)
> [   60.396544] type-c-vbus-current-regulator:  enabled successfully?! JDB!
> [   60.403538] usb 2-1: Failed to suspend device, error -71
> [   60.403694] usb 2-1: USB disconnect, device number 3
> [   60.413841] rt1711h_set_vbus: vbus := On
> [   60.413844] rt1711h_set_vbus: charge is already Off
> [   60.631357] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACHED->SRC_ATTACHED
> [   60.815285] usb 1-1: new high-speed USB device number 9 using xhci-hcd
> [   60.969662] usb 1-1: New USB device found, idVendor=2109,
> idProduct=2813, bcdDevice=90.11
> [   60.977964] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [   60.985156] usb 1-1: Product: USB2.0 Hub
> [   60.989419] usb 1-1: Manufacturer: VIA Labs, Inc.
> [   61.056894] hub 1-1:1.0: USB hub found
> [   61.061194] hub 1-1:1.0: 4 ports detected
> [   61.119310] JDB: state change SRC_ATTACHED -> SRC_UNATTACHED [delayed 480 ms]
> [   61.119759] JDB: rt1711h_set_vbus  source: 0 sink: 0
> [   61.131951] JDB: rt1711h_set_vbus disabling regulator!
> [   61.137141] type-c-vbus-current-regulator:  disabled successfully?!
> JDB! (ret=0)
> [   61.145007] rt1711h_set_vbus: vbus := Off
> [   61.145010] rt1711h_set_vbus: charge is already Off
> [   61.362956] JDB: hub_usb_role_switch_set switching to ROLE_NONE!
> [   61.374082] usb 1-1: USB disconnect, device number 9
> [   61.380600] JDB: tcpm_state_machine_work state chage:
> SRC_UNATTACHED->TOGGLING
> [   61.390394] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   61.397257] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   61.419292] usb 1-1.1: new low-speed USB device number 10 using xhci-hcd
> [   61.427378] usb 1-1-port1: attempt power cycle
> [   61.452874] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   61.655250] JDB: state change SRC_ATTACH_WAIT -> SNK_TRY [delayed 200 ms]
> [   61.655398] JDB: tcpm_state_machine_work state chage: SNK_TRY->SNK_TRY
> [   61.723383] usb 2-1: new SuperSpeed Gen 1 USB device number 4 using xhci-hcd
> [   61.748163] usb 2-1: New USB device found, idVendor=0424,
> idProduct=5734, bcdDevice= 2.02
> [   61.757846] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=0
> [   61.763291] JDB: state change SNK_TRY -> SNK_TRY_WAIT [delayed 100 ms]
> [   61.763317] JDB: tcpm_state_machine_work state chage:
> SNK_TRY_WAIT->SRC_TRYWAIT
> [   61.766781] usb 2-1: Product: USB5734
> [   61.782560] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT->SRC_TRYWAIT
> [   61.790221] usb 2-1: Manufacturer: Microchip Tech
> [   61.824476] hub 2-1:1.0: USB hub found
> [   61.828701] hub 2-1:1.0: 5 ports detected
> [   61.883350] JDB: state change SRC_TRYWAIT -> SRC_TRYWAIT_UNATTACHED
> [delayed 100 ms]
> [   61.883378] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT_UNATTACHED->SNK_UNATTACHED
> [   61.901040] JDB: tcpm_state_machine_work state chage:
> SNK_UNATTACHED->TOGGLING
> [   61.909513] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   61.955483] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   62.035296] usb 1-1: new high-speed USB device number 14 using xhci-hcd
> [   62.159263] JDB: state change SRC_ATTACH_WAIT -> SRC_ATTACHED
> [delayed 200 ms]
> [   62.159750] JDB: hub_usb_role_switch_set switching to ROLE_HOST!
> [   62.174502] JDB: rt1711h_set_vbus  source: 1 sink: 0
> [   62.179534] JDB: rt1711h_set_vbus enabling regulator!
> [   62.185067] type-c-vbus-current-regulator:  being enabled! JDB!
> [   62.191039] type-c-vbus-current-regulator:  enabled successfully?! JDB!
> [   62.198180] usb 1-1: device descriptor read/all, error -71
> [   62.203769] rt1711h_set_vbus: vbus := On
> [   62.203775] rt1711h_set_vbus: charge is already Off
> [   62.351356] usb 2-1: USB disconnect, device number 4
> [   62.421558] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACHED->SRC_ATTACHED
> [   62.543282] usb 1-1: new high-speed USB device number 15 using xhci-hcd
> [   62.696916] usb 1-1: New USB device found, idVendor=2109,
> idProduct=2813, bcdDevice=90.11
> [   62.705142] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [   62.712616] usb 1-1: Product: USB2.0 Hub
> [   62.716595] usb 1-1: Manufacturer: VIA Labs, Inc.
> [   62.784743] hub 1-1:1.0: USB hub found
> [   62.788841] hub 1-1:1.0: 4 ports detected
> [   62.911249] JDB: state change SRC_ATTACHED -> SRC_UNATTACHED [delayed 480 ms]
> [   62.911598] JDB: rt1711h_set_vbus  source: 0 sink: 0
> [   62.923769] JDB: rt1711h_set_vbus disabling regulator!
> [   62.928940] type-c-vbus-current-regulator:  disabled successfully?!
> JDB! (ret=0)
> [   62.936711] rt1711h_set_vbus: vbus := Off
> [   62.936714] rt1711h_set_vbus: charge is already Off
> [   63.143272] usb 1-1.1: new low-speed USB device number 16 using xhci-hcd
> [   63.154684] JDB: hub_usb_role_switch_set switching to ROLE_NONE!
> [   63.160941] usb 1-1-port1: cannot reset (err = -71)
> [   63.161185] usb 1-1: USB disconnect, device number 15
> [   63.171398] JDB: tcpm_state_machine_work state chage:
> SRC_UNATTACHED->TOGGLING
> [   63.175823] usb 1-1-port1: attempt power cycle
> [   63.181995] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   63.182155] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   63.244450] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   63.447246] JDB: state change SRC_ATTACH_WAIT -> SNK_TRY [delayed 200 ms]
> [   63.447391] JDB: tcpm_state_machine_work state chage: SNK_TRY->SNK_TRY
> [   63.507335] usb 2-1: new SuperSpeed Gen 1 USB device number 5 using xhci-hcd
> [   63.532130] usb 2-1: New USB device found, idVendor=0424,
> idProduct=5734, bcdDevice= 2.02
> [   63.542169] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=0
> [   63.549402] usb 2-1: Product: USB5734
> [   63.551286] JDB: state change SNK_TRY -> SNK_TRY_WAIT [delayed 100 ms]
> [   63.551313] JDB: tcpm_state_machine_work state chage:
> SNK_TRY_WAIT->SRC_TRYWAIT
> [   63.554868] usb 2-1: Manufacturer: Microchip Tech
> [   63.571708] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT->SRC_TRYWAIT
> [   63.600310] hub 2-1:1.0: USB hub found
> [   63.604194] hub 2-1:1.0: 5 ports detected
> [   63.675303] JDB: state change SRC_TRYWAIT -> SRC_TRYWAIT_UNATTACHED
> [delayed 100 ms]
> [   63.675331] JDB: tcpm_state_machine_work state chage:
> SRC_TRYWAIT_UNATTACHED->SNK_UNATTACHED
> [   63.693027] JDB: tcpm_state_machine_work state chage:
> SNK_UNATTACHED->TOGGLING
> [   63.701676] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   63.747517] JDB: tcpm_state_machine_work state chage:
> SRC_ATTACH_WAIT->SRC_ATTACH_WAIT
> [   63.827281] usb 1-1: new high-speed USB device number 20 using xhci-hcd
> [   63.941498] JDB: tcpm_state_machine_work state chage:
> SRC_UNATTACHED->TOGGLING
> [   63.948872] JDB: tcpm_state_machine_work state chage: TOGGLING->TOGGLING
> [   63.979728] usb 1-1: New USB device found, idVendor=0424,
> idProduct=2734, bcdDevice= 2.02
> [   63.988033] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [   63.995636] usb 1-1: Product: USB2734
> [   63.999540] usb 1-1: Manufacturer: Microchip Tech
> [   64.064532] hub 1-1:1.0: USB hub found
> [   64.068557] hub 1-1:1.0: 5 ports detected
> [   64.415290] usb 1-1.5: new high-speed USB device number 21 using xhci-hcd
> [   64.520307] usb 1-1.5: New USB device found, idVendor=0424,
> idProduct=2740, bcdDevice= 2.00
> [   64.528969] usb 1-1.5: New USB device strings: Mfr=1, Product=2,
> SerialNumber=0
> [   64.536345] usb 1-1.5: Product: Hub Controller
> [   64.540828] usb 1-1.5: Manufacturer: Microchip Tech