Bug 12214

Summary: [TC 1059] [test_parselogs] failed on MMAX64 (Turbot, WIC image) : usb 1-3: device descriptor read/64, error -71
Product: [Build System, Metadata & Runtime] BSPs Reporter: Jair Gonzalez <jair.de.jesus.gonzalez.plascencia>
Component: bsps-runtimeAssignee: nagarajagopal <nagarajagopalx.velu>
Status: RESOLVED FIXED QA Contact: pravin <pravin.shankarx.patil>
Severity: normal    
Priority: Medium CC: ee.peng.yeoh, nagarajagopalx.velu, yp.kernel.watcher, yp.watcher
Version: 2.4   
Target Milestone: 4.99   
Hardware: MinnowBoard Max   
OS: x86_64   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Don't know
Attachments:
Description Flags
2.4_M4_rc2_genericx86-64_MTurbot_sato-sdk-WIC.log none

Description Jair Gonzalez 2017-10-10 20:06:49 UTC 
STATUS: FAILED
BUILD: 2.4 M4: rc2-da05a01423a60a23cd1073eb0ad3776e5bf4f2a8
ENVIRONMENT: genericx86-64-WIC on MMAX64 (Turbot)
STEPS TO REPRODUCE: 
  
 Parse dmesg log and all log files in /var/log for keywords like: "error" , "failed" , "cannot", "can't" etc.
Filter out the known and invalid errors or errors that appear in certain situations and need to be ignored.

EXPECTED OUTCOME: 
  
 No errors or fails should be present in logs

ACTUAL OUTCOME:

 Multiple errors like the following:

----------------------
Central error: [    4.043365] usb 1-3: device descriptor read/64, error -71
***********************
[    3.442604] md: Waiting for all devices to be available before autodetect
[    3.449073] md: If you don't use raid, use raid=noautodetect
[    3.457167] md: Autodetecting RAID arrays.
[    3.460444] md: autorun ...
[    3.462151] md: ... autorun DONE.
[    3.464890] Waiting for root device PARTUUID=d4a9645c-fcaf-48ad-8b86-9bc272a1c2ef...
[    3.512308] usb 1-2: new high-speed USB device number 3 using xhci_hcd
[    3.708583] usb-storage 1-2:1.0: USB Mass Storage device detected
[    3.718388] scsi host0: usb-storage 1-2:1.0
[    3.878283] usb 1-3: new low-speed USB device number 4 using xhci_hcd
[    4.043365] usb 1-3: device descriptor read/64, error -71
[    4.309369] usb 1-3: device descriptor read/64, error -71
[    4.578379] usb 1-3: new low-speed USB device number 5 using xhci_hcd
[    4.743486] usb 1-3: device descriptor read/64, error -71
[    4.847939] scsi 0:0:0:0: Direct-Access     Kingston DataTraveler 3.0 PMAP PQ: 0 ANSI: 6
[    5.012912] usb 1-3: device descriptor read/64, error -71
[    5.281886] usb 1-3: new low-speed USB device number 6 using xhci_hcd
[    5.288484] usb 1-3: Device not responding to setup address.
[    5.493654] sd 0:0:0:0: [sda] 15155200 512-byte logical blocks: (7.76 GB/7.23 GiB)
[    5.503016] usb 1-3: Device not responding to setup address.
[    5.508302] sd 0:0:0:0: [sda] Write Protect is off

***********************
Central error: [    4.743486] usb 1-3: device descriptor read/64, error -71
***********************
[    3.460444] md: autorun ...
[    3.462151] md: ... autorun DONE.
[    3.464890] Waiting for root device PARTUUID=d4a9645c-fcaf-48ad-8b86-9bc272a1c2ef...
[    3.512308] usb 1-2: new high-speed USB device number 3 using xhci_hcd
[    3.708583] usb-storage 1-2:1.0: USB Mass Storage device detected
[    3.718388] scsi host0: usb-storage 1-2:1.0
[    3.878283] usb 1-3: new low-speed USB device number 4 using xhci_hcd
[    4.043365] usb 1-3: device descriptor read/64, error -71
[    4.309369] usb 1-3: device descriptor read/64, error -71
[    4.578379] usb 1-3: new low-speed USB device number 5 using xhci_hcd
[    4.743486] usb 1-3: device descriptor read/64, error -71
[    4.847939] scsi 0:0:0:0: Direct-Access     Kingston DataTraveler 3.0 PMAP PQ: 0 ANSI: 6
[    5.012912] usb 1-3: device descriptor read/64, error -71
[    5.281886] usb 1-3: new low-speed USB device number 6 using xhci_hcd
[    5.288484] usb 1-3: Device not responding to setup address.
[    5.493654] sd 0:0:0:0: [sda] 15155200 512-byte logical blocks: (7.76 GB/7.23 GiB)
[    5.503016] usb 1-3: Device not responding to setup address.
[    5.508302] sd 0:0:0:0: [sda] Write Protect is off
[    5.512348] sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00
[    5.514905] sd 0:0:0:0: [sda] No Caching mode page found
[    5.519533] sd 0:0:0:0: [sda] Assuming drive cache: write through
Comment 1 Jair Gonzalez 2017-10-10 20:12:22 UTC 
Created attachment 4069 [details]
2.4_M4_rc2_genericx86-64_MTurbot_sato-sdk-WIC.log
Comment 2 Jair Gonzalez 2017-10-10 20:15:12 UTC 
For more reference, I found the following old thread on the Ubuntu forums, mentioning CONFIG_USB_SUSPEND as a probable cause for this error.
https://ubuntuforums.org/showthread.php?t=797789
Comment 3 Anuj Mittal 2018-05-28 03:50:57 UTC 
Ee Peng, can you please help verify if this is still a problem? I can't reproduce this.
Comment 4 nagarajagopal 2018-06-06 03:54:48 UTC 
 I found "failed" present in parse dmesg log file.
 Below find the failed message in log file,

  [    1.049243] pci 0000:00:1c.0: BAR 15: assigned [mem 0x90e00000-0x90ffffff 64bit pref]
[    1.056582] pci 0000:00:1c.1: BAR 15: no space for [mem size 0x00200000 64bit pref]
[    1.063716] pci 0000:00:1c.1: BAR 15: failed to assign [mem size 0x00200000 64bit pref]
[    1.071254] pci 0000:00:1c.2: BAR 15: no space for [mem size 0x00200000 64bit pref]
[    1.078385] pci 0000:00:1c.2: BAR 15: failed to assign [mem size 0x00200000 64bit pref]
[    1.085911] pci 0000:00:1c.3: BAR 14: no space for [mem size 0x00200000]
[    1.091976] pci 0000:00:1c.3: BAR 14: failed to assign [mem size 0x00200000]
[    1.098438] pci 0000:00:1c.3: BAR 15: no space for [mem size 0x00200000 64bit pref]
[    1.105571] pci 0000:00:1c.3: BAR 15: failed to assign [mem size 0x00200000 64bit pref]
[    1.113095] pci 0000:00:1c.0: BAR 13: assigned [io  0x4000-0x4fff]
[    1.118579] pci 0000:00:1c.3: BAR 13: assigned [io  0x5000-0x5fff]
[    1.124068] pci 0000:00:1c.3: BAR 14: assigned [mem 0x90c00000-0x90dfffff]
[    1.130333] pci 0000:00:1c.3: BAR 15: assigned [mem 0x90e00000-0x90ffffff 64bit pref]
[    1.137670] pci 0000:00:1c.2: BAR 15: no space for [mem size 0x00200000 64bit pref]
[    1.144803] pci 0000:00:1c.2: BAR 15: failed to assign [mem size 0x00200000 64bit pref]
[    1.152334] pci 0000:00:1c.1: BAR 15: no space for [mem size 0x00200000 64bit pref]
[    1.159459] pci 0000:00:1c.1: BAR 15: failed to assign [mem size 0x00200000 64bit pref]
[    1.166985] pci 0000:00:1c.0: BAR 14: no space for [mem size 0x00200000]
[    1.173050] pci 0000:00:1c.0: BAR 14: failed to assign [mem size 0x00200000]
[    1.179510] pci 0000:00:1c.0: BAR 15: no space for [mem size 0x00200000 64bit pref]
[    1.186644] pci 0000:00:1c.0: BAR 15: failed to assign [mem size 0x00200000 64bit pref]
[    1.194168] pci 0000:00:1c.0: PCI bridge to [bus 01]
[    1.198289] pci 0000:00:1c.0:   bridge window [io  0x4000-0x4fff]
Comment 5 yeoh ee peng 2018-06-06 06:11:38 UTC 
(In reply to comment #4)
>  I found "failed" present in parse dmesg log file.
>  Below find the failed message in log file,
> 
>   [    1.049243] pci 0000:00:1c.0: BAR 15: assigned [mem
> 0x90e00000-0x90ffffff 64bit pref]
> [    1.056582] pci 0000:00:1c.1: BAR 15: no space for [mem size 0x00200000
> 64bit pref]
> [    1.063716] pci 0000:00:1c.1: BAR 15: failed to assign [mem size
> 0x00200000 64bit pref]
> [    1.071254] pci 0000:00:1c.2: BAR 15: no space for [mem size 0x00200000
> 64bit pref]
> [    1.078385] pci 0000:00:1c.2: BAR 15: failed to assign [mem size
> 0x00200000 64bit pref]
> [    1.085911] pci 0000:00:1c.3: BAR 14: no space for [mem size 0x00200000]
> [    1.091976] pci 0000:00:1c.3: BAR 14: failed to assign [mem size
> 0x00200000]
> [    1.098438] pci 0000:00:1c.3: BAR 15: no space for [mem size 0x00200000
> 64bit pref]
> [    1.105571] pci 0000:00:1c.3: BAR 15: failed to assign [mem size
> 0x00200000 64bit pref]
> [    1.113095] pci 0000:00:1c.0: BAR 13: assigned [io  0x4000-0x4fff]
> [    1.118579] pci 0000:00:1c.3: BAR 13: assigned [io  0x5000-0x5fff]
> [    1.124068] pci 0000:00:1c.3: BAR 14: assigned [mem 0x90c00000-0x90dfffff]
> [    1.130333] pci 0000:00:1c.3: BAR 15: assigned [mem 0x90e00000-0x90ffffff
> 64bit pref]
> [    1.137670] pci 0000:00:1c.2: BAR 15: no space for [mem size 0x00200000
> 64bit pref]
> [    1.144803] pci 0000:00:1c.2: BAR 15: failed to assign [mem size
> 0x00200000 64bit pref]
> [    1.152334] pci 0000:00:1c.1: BAR 15: no space for [mem size 0x00200000
> 64bit pref]
> [    1.159459] pci 0000:00:1c.1: BAR 15: failed to assign [mem size
> 0x00200000 64bit pref]
> [    1.166985] pci 0000:00:1c.0: BAR 14: no space for [mem size 0x00200000]
> [    1.173050] pci 0000:00:1c.0: BAR 14: failed to assign [mem size
> 0x00200000]
> [    1.179510] pci 0000:00:1c.0: BAR 15: no space for [mem size 0x00200000
> 64bit pref]
> [    1.186644] pci 0000:00:1c.0: BAR 15: failed to assign [mem size
> 0x00200000 64bit pref]
> [    1.194168] pci 0000:00:1c.0: PCI bridge to [bus 01]
> [    1.198289] pci 0000:00:1c.0:   bridge window [io  0x4000-0x4fff]

Hi Raj,

Could you share with us the environments that you used for the verification above? Image? Hardware? 

Did you try to use parselogs.ParseLogsTest.test_parselogs from testimage to verify this?
Comment 6 nagarajagopal 2018-06-06 06:45:48 UTC 
Hi Ee Peng,

BUILD: 2.4 : rc2-da05a01423a60a23cd1073eb0ad3776e5bf4f2a8
ENVIRONMENT: genericx86-64-WIC 
HARDWARE :  Minnow Max64 (Turbot)

Below steps used to reproduce the issue,
 used above commit id to checkout and build to generated WIC image.
 make bootable USB with "core-image-sato-sdk-genericx86-64.wic" image.
 Booting the USB in Minnow Max 64 Turbot.
 run "dmesg" and check dmesg log file in /var/log/ path.

i did not try "parselogs.ParseLogsTest.test_parselogs" to verify,
How to use  parselogs.ParseLogsTest.test_parselogs to verify this image ?
Comment 7 yeoh ee peng 2018-06-06 08:12:06 UTC 
(In reply to comment #6)
> Hi Ee Peng,
> 
> BUILD: 2.4 : rc2-da05a01423a60a23cd1073eb0ad3776e5bf4f2a8
> ENVIRONMENT: genericx86-64-WIC 
> HARDWARE :  Minnow Max64 (Turbot)
> 
> Below steps used to reproduce the issue,
>  used above commit id to checkout and build to generated WIC image.
>  make bootable USB with "core-image-sato-sdk-genericx86-64.wic" image.
>  Booting the USB in Minnow Max 64 Turbot.
>  run "dmesg" and check dmesg log file in /var/log/ path.
> 
> i did not try "parselogs.ParseLogsTest.test_parselogs" to verify,
> How to use  parselogs.ParseLogsTest.test_parselogs to verify this image ?

Hi Raj,

Could you help to verify this using QA yocto-2.4.3.rc2?

To run testimage, you can follow the instructions in below. 
https://wiki.yoctoproject.org/wiki/BSP_Test_Plan
Add below configurations in local.conf, execute bitbake <image> -c testimage
INHERIT += "testimage"
TEST_TARGET = "simpleremote"
TEST_SERVER_IP = <host IP>
TEST_TARGET_IP = <system under test IP>
TEST_SUITES = "ping ssh parselogs"

This will only run parselogs automated tests.
Comment 8 yeoh ee peng 2018-07-02 09:41:55 UTC 
This is no longer reproducible on most recent 2.4.3.rc2 testing on MinnowMax64.