Re: [PATCH v3 00/12] usb: early: add support for early printk through USB3 debug port

[Dave Young]

Hi,

On 11/11/15 at 09:32am, Lu, Baolu wrote:
> 
> 
> On 11/10/2015 05:39 PM, Dave Young wrote:
> >Hi,
> >
> >On 11/09/15 at 03:38pm, Lu Baolu wrote:
> >>This patch series adds support for early printk through USB3 debug port.
> >>USB3 debug port is described in xHCI specification as an optional extended
> >>capability.
> >>
> >I did a test with your previous patchset with the manually wired cable.
> >debug host detected the remote device, but later the devie automaticlly
> >disconnected and earlyprintk hangs.
> 
> Hi Dave,
> 
> What I have done is:

Retested it, seems it is not stable. I got a sucessful boot with earlyprintk
But only once and there was no "Press Y to continue", I just blindly pressed Y.

The other tests failed.

Since it is not convinience to test, do you have way to enable the dbc
after kernel boot? like echo 1 to a sysfs file to enable it.
> 
> (1) Build a new kernel for debug target with this patch series applied.
> (2) Add "earlyprintk=xdbc" to the kernel option of debug target. The
>      "keep" option for early printk doesn't support yet. (That's my next
>      target.)
> 
> (3) Boot the debug host, and disable USB runtime suspend:
> 
> # echo on > /sys/bus/pci/devices/<xhci_pci_bus_name>/power/control
> # echo on | tee /sys/bus/usb/devices/*/power/control
> 
> (4) Boot the debug target. Check the dmesg message on debug host.
> 
> # tail -f /var/log/kern.log
> 
> Nov 12 01:27:50 allen-ult kernel: [ 1815.983374] usb 4-3: new SuperSpeed USB
> device number 4 using xhci_hcd
> Nov 12 01:27:50 allen-ult kernel: [ 1815.999595] usb 4-3: LPM exit latency
> is zeroed, disabling LPM.
> Nov 12 01:27:50 allen-ult kernel: [ 1815.999899] usb 4-3: New USB device
> found, idVendor=1d6b, idProduct=0004
> Nov 12 01:27:50 allen-ult kernel: [ 1815.999902] usb 4-3: New USB device
> strings: Mfr=1, Product=2, SerialNumber=3
> Nov 12 01:27:50 allen-ult kernel: [ 1815.999903] usb 4-3: Product: Remote
> GDB
> Nov 12 01:27:50 allen-ult kernel: [ 1815.999904] usb 4-3: Manufacturer:
> Linux
> Nov 12 01:27:50 allen-ult kernel: [ 1815.999905] usb 4-3: SerialNumber: 0001
> Nov 12 01:27:50 allen-ult kernel: [ 1816.000240] usb_debug 4-3:1.0: xhci_dbc
> converter detected
> Nov 12 01:27:50 allen-ult kernel: [ 1816.000360] usb 4-3: xhci_dbc converter
> now attached to ttyUSB0
> 
> (5) Host has completed enumeration of debug device. Start "minicom" on debug
> host.
> 

Most times I have no chance to run minicom before the usb disconnection here.

> 
> Welcome to minicom 2.7
> 
> OPTIONS: I18n
> Compiled on Jan  1 2014, 17:13:19.
> Port /dev/ttyUSB0, 01:28:02
> 
> Press CTRL-A Z for help on special keys
> 
> Press Y to continue...
> 
> (6) You should be able to see "Press Y to continue..." (if not, try pressing
> Enter key)
> Press Y key, debug target should go ahead with boot and early boot messages
> should show in mincom.
> 
> Press Y to continue...
> [    0.000000] Initializing cgroup subsys cpuset
> [    0.000000] Initializing cgroup subsys cpu
> [    0.000000] Initializing cgroup subsys cpuacct
> [    0.000000] Linux version 4.3.0-rc7+ (allen@blu-skl) (gcc version 4.8.4
> (Ubuntu 4.8.4-2ubuntu1~14.04) 5
> [    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-4.3.0-rc7+
> root=UUID=5a2fb856-0238-4b6e-aa45-beeccb7
> [    0.000000] KERNEL supported cpus:
> 
> [...skipped...]
> 
> [    0.000000]  Offload RCU callbacks from CPUs: 0-7.
> [    0.000000] Console: colour dummy device 80x25
> [    0.000000] console [tty0] enabled
> [    0.000000] bootconsole [earlyxdbc0] disabled
> 
> 
> So "the devie automaticlly disconnected and earlyprintk hangs" happens in
> which step?
> 

Here is some log on host side.

[ 1568.052135] usb 2-2: new SuperSpeed USB device number 5 using xhci_hcd
[ 1568.063416] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1568.063750] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1568.063751] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1568.063752] usb 2-2: Product: Remote GDB
[ 1568.063753] usb 2-2: Manufacturer: Linux
[ 1568.063754] usb 2-2: SerialNumber: 0001
[ 1568.065580] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1568.066309] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1580.464706] usb 2-2: USB disconnect, device number 5
[ 1580.464996] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1580.465062] usb_debug 2-2:1.0: device disconnected
[ 1580.670743] usb 2-2: new SuperSpeed USB device number 6 using xhci_hcd
[ 1580.682068] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1580.682667] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1580.682672] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1580.682675] usb 2-2: Product: Remote GDB
[ 1580.682678] usb 2-2: Manufacturer: Linux
[ 1580.682681] usb 2-2: SerialNumber: 0001
[ 1580.685190] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1580.687106] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1586.751477] usb 2-2: USB disconnect, device number 6
[ 1586.754248] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1586.754287] usb_debug 2-2:1.0: device disconnected
[ 1586.960399] usb 2-2: new SuperSpeed USB device number 7 using xhci_hcd
[ 1586.971562] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1586.971916] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1586.971918] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1586.971919] usb 2-2: Product: Remote GDB
[ 1586.971921] usb 2-2: Manufacturer: Linux
[ 1586.971922] usb 2-2: SerialNumber: 0001
[ 1586.973140] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1586.973939] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1616.615418] usb 2-2: USB disconnect, device number 7
[ 1616.617865] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1616.617918] usb_debug 2-2:1.0: device disconnected
[ 1616.823351] usb 2-2: new SuperSpeed USB device number 8 using xhci_hcd
[ 1616.834520] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1616.834856] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1616.834858] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1616.834859] usb 2-2: Product: Remote GDB
[ 1616.834860] usb 2-2: Manufacturer: Linux
[ 1616.834860] usb 2-2: SerialNumber: 0001
[ 1616.836715] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1616.837327] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1622.719311] usb 2-2: USB disconnect, device number 8
[ 1622.721962] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1622.721995] usb_debug 2-2:1.0: device disconnected
[ 1622.928226] usb 2-2: new SuperSpeed USB device number 9 using xhci_hcd
[ 1622.939383] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1622.939714] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1622.939715] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1622.939716] usb 2-2: Product: Remote GDB
[ 1622.939717] usb 2-2: Manufacturer: Linux
[ 1622.939718] usb 2-2: SerialNumber: 0001
[ 1622.941593] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1622.942187] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1631.312112] usb 2-2: USB disconnect, device number 9
[ 1631.315427] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1631.315465] usb_debug 2-2:1.0: device disconnected
[ 1631.521007] usb 2-2: new SuperSpeed USB device number 10 using xhci_hcd
[ 1631.532212] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1631.532544] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1631.532545] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1631.532546] usb 2-2: Product: Remote GDB
[ 1631.532547] usb 2-2: Manufacturer: Linux
[ 1631.532548] usb 2-2: SerialNumber: 0001
[ 1631.534413] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1631.535117] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1633.252488] usb 2-2: USB disconnect, device number 10
[ 1633.255279] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1633.255314] usb_debug 2-2:1.0: device disconnected
[ 1633.461411] usb 2-2: new SuperSpeed USB device number 11 using xhci_hcd
[ 1633.472598] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1633.472932] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1633.472933] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1633.472934] usb 2-2: Product: Remote GDB
[ 1633.472935] usb 2-2: Manufacturer: Linux
[ 1633.472936] usb 2-2: SerialNumber: 0001
[ 1633.473987] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1633.474624] usb 2-2: xhci_dbc converter now attached to ttyUSB0
[ 1633.900927] usb 2-2: USB disconnect, device number 11
[ 1633.901176] xhci_dbc ttyUSB0: xhci_dbc converter now disconnected from ttyUSB0
[ 1633.901226] usb_debug 2-2:1.0: device disconnected
[ 1634.106831] usb 2-2: new SuperSpeed USB device number 12 using xhci_hcd
[ 1634.117987] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[ 1634.118328] usb 2-2: New USB device found, idVendor=1d6b, idProduct=0004
[ 1634.118329] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1634.118330] usb 2-2: Product: Remote GDB
[ 1634.118331] usb 2-2: Manufacturer: Linux
[ 1634.118332] usb 2-2: SerialNumber: 0001
[ 1634.120194] usb_debug 2-2:1.0: xhci_dbc converter detected
[ 1634.120949] usb 2-2: xhci_dbc converter now attached to ttyUSB0

Thanks
Dave
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/