canonical-certification-server fails the usb-storage-preinserted test, even though a USB stick is indeed plugged in

[Kent Baxley]

On two runs of canonical-certification-server on two different systems, the usb-storage-preinserted test failed both times, even though a USB stick was plugged into the server before the tests were kicked off.

Other tests in the certification suite do seem to detect the USB device, flag it as removable, and don't run any tests on that device (which is expected).

This is the error I get on both systems when the test was run:

https://certification.canonical.com/hardware/201209-11626/submission/97008/test/163/result/7166592/

Steps to reproduce:
1) Install 14.04 server daily build
2) Install canonical-certification-server 0.17.7+bzr2718+2014022 (this also failed with the previous version)
3) kick off the test and have the usb-storage-preinserted test run
4) note failure when the results are published.

[Daniel Manrique (roadmr)]

Hi Kent,

On one of these systems, could you please plug in a USB stick and run:

/usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -l usb

please paste the output here.

Also please run this and paste the output, to see if you have udisks installed:

$ dpkg --list udisk*

Thanks!

[Kent Baxley (kentb)]

Hey Daniel,

Here you go:

# /usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -l usb
/usr/lib/python3/dist-packages/checkbox_support/dbus/__init__.py:51: PyGIDeprecationWarning: MainLoop is deprecated; use GLib.MainLoop instead
  loop = GObject.MainLoop()
ERROR:root:No removable drives were detected, aborting

Also, udisks is not installed on the SUT. If I install it, it doesn't seem to make a difference in the outcome. Here's the listing *after* I installed udisks by hand:

# sudo dpkg -l udisks*
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-===================================-======================-======================-===========================================================================
ii udisks 1.0.4-8ubuntu1 amd64 storage media interface
ii udisks2 2.1.2-1 amd64 D-BUS service to access and manipulate storage devices

Hope this helps, and please let me know if there's anything else I can capture for you.

[Kent Baxley (kentb)]

To clarify, udisks2 was already on the system.

[Daniel Manrique (roadmr)]

Hi Kent,

Thanks! this is very strange, why are no disks reported? if you have udisks2 that should be enough, udisks 1.x is not necessary.

Could you please run this with the usb stick inserted:

udisksctl dump > with-stick.txt

Then this with the usb stick removed:

udisksctl dump > without-stick.txt

and attach both txt files for me to look at? (we're not really looking at insert/remove behavior here, but it'll be helpful to look at the differences).

Thanks again!

[Kent Baxley (kentb)]

output with usb stick removed

[Kent Baxley (kentb)]

Latest canonical-certification-server packages sent to me via Daniel looks to have fixed this.

We are good to go with version
0.17.8+bzr2735+2014022

[Kent Baxley (kentb)]

I spoke too soon. I have 3 machines that failed the pre-insert test today. I would upload them to the c3 site but there are issues with results showing all zeros at the moment at submission time.

The error is the same on each machine:

 /usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -l usb
/usr/lib/python3/dist-packages/checkbox_support/dbus/__init__.py:51: PyGIDeprecationWarning: MainLoop is deprecated; use GLib.MainLoop instead
  loop = GObject.MainLoop()
ERROR:root:No removable drives were detected, aborting

[Kent Baxley (kentb)]

I am also using the 0.17.8+bzr2735+2014022 version of canonical-certification-server

[Daniel Manrique (roadmr)]

OK, I'll have a look at the diagnostic files you sent to figure this out. Thanks!

[Jeff Lane  (bladernr)]

This is strange, here it is on my 1U at home:
ubuntu@supermicro:~$ /usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -l usb
/usr/lib/python3/dist-packages/checkbox_support/dbus/__init__.py:51: PyGIDeprecationWarning: MainLoop is deprecated; use GLib.MainLoop instead
  loop = GObject.MainLoop()
--------------------
Removable devices currently mounted:
None
Removable devices currently not mounted:
/dev/sdb5
/dev/sdb1
--------------------
 (I threw in a USB stick that apparently has two partitions on it)

and here's the test running manually...
ubuntu@supermicro:~$ sudo /usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -s 268400000 usb
/usr/lib/python3/dist-packages/checkbox_support/dbus/__init__.py:51: PyGIDeprecationWarning: MainLoop is deprecated; use GLib.MainLoop instead
  loop = GObject.MainLoop()
Found the following mounted usb partitions:
    /dev/sdb1 : /tmp/tmp0o7hwrye : 480000000 bits/s
    /dev/sdb5 : /tmp/tmp86iqw2nf : 480000000 bits/s
--------------------
/dev/sdb1 (Total Data Size / iteration: 255.9662 MB):
WARNING:root:[Iteration 0] Parent and Child copy hashes mismatch on /tmp/tmp0o7hwrye/tmpzgt5hdva.0!
WARNING:root: Parent hash: 0d9cf2ea426c80c091fdae9a0f52e9f7
WARNING:root: Child hash: 272117014235fe71e010d08cba0688ff
 [Iteration 0] Average Speed: 3.2519
 Summary:
  Total Data Attempted: 255.9662 MB
  Total Time to write: 78.7139 secs
  Average Write Time: 78.7139 secs
  Average Write Speed: 3.2519 MB/s
/dev/sdb5 (Total Data Size / iteration: 255.9662 MB):
 [Iteration 0] Average Speed: 5.9514
 Summary:
  Total Data Attempted: 255.9662 MB
  Total Time to write: 43.0096 secs
  Average Write Time: 43.0096 secs
  Average Write Speed: 5.9514 MB/s
WARNING:root:Completed 1 test iterations, but there were errors

Now some versions:
ii plainbox-insecure-policy 0.6~dev+bzr2863+pkg2~ubuntu14.04.1
ii plainbox-provider-certification-server 0.1~dev+bzr2863+pkg4~ubuntu14.04.1
ii plainbox-provider-checkbox 0.4~dev+bzr2863+pkg1~ubuntu14.04.1
ii plainbox-provider-resource-generic 0.3~dev+bzr2863+pkg2~ubuntu14.04.1
ii python3-plainbox 0.6~dev+bzr2863+pkg2~ubuntu14.04.1
ii checkbox-ng 0.3~dev+bzr2869+pkg1~ubuntu14.04.1
ii plainbox-provider-checkbox 0.4~dev+bzr2863+pkg1~ubuntu14.04.1
ii python3-checkbox-ng 0.3~dev+bzr2869+pkg1~ubuntu14.04.1
ii python3-checkbox-support 0.2~dev+bzr2863+pkg1~ubuntu14.04.1

[Jeff Lane  (bladernr)]

And here's the result from running inside of c-c-s (installed using checkbox-ng and plainbox-provider-certification-server)
==========================[ Loading Jobs Definition ]===========================
===============================[ Authentication ]===============================
Estimated duration is 98.11 for automated jobs.
Estimated duration cannot be determined for manual jobs.
==============================[ Running All Jobs ]==============================
---------[ 2013.com.canonical.certification::usb3/storage-preinserted ]---------
Outcome: not-supported
----------------[ 2013.com.canonical.certification::usb/detect ]----------------
Detects and shows USB devices attached to this system.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Running... (output in /home/ubuntu/.cache/plainbox/sessions/pbox-z62udmi3.session/2013.com.canonical.certification__usb_detect.*)
Outcome: pass
---------[ 2013.com.canonical.certification::usb/storage-preinserted ]----------
This is an automated version of usb/storage-automated and assumes that the
server has usb storage devices plugged in prior to checkbox execution. It
is intended for servers and SRU automated testing.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Running... (output in /home/ubuntu/.cache/plainbox/sessions/pbox-z62udmi3.session/2013.com.canonical.certification__usb_storage-preinserted.*)
Outcome: fail
==================================[ Results ]===================================
2013.com.canonical.certification::__benchmarks__: pass
2013.com.canonical.certification::__cpu__: pass
2013.com.canonical.certification::__disk__: pass
2013.com.canonical.certification::__ethernet__: pass
2013.com.canonical.certification::__floppy__: pass
2013.com.canonical.certification::__info__: pass
2013.com.canonical.certification::__memory__: pass
2013.com.canonical.certification::__miscellanea__: pass
2013.com.canonical.certification::__optical__: pass
2013.com.canonical.certification::__power-management__: pass
2013.com.canonical.certification::__stress__: pass
2013.com.canonical.certification::__usb__: pass
2013.com.canonical.certification::__virtualization__: pass
2013.com.canonical.certification::benchmarks/disk/hdparm-cache-read: pass
2013.com.canonical.certification::benchmarks/disk/hdparm-read: pass
2013.com.canonical.certification::block_device: pass
2013.com.canonical.certification::cdimage: pass
2013.com.canonical.certification::cpuinfo: pass
2013.com.canonical.certification::device: pass
2013.com.canonical.certification::disk/read_performance: pass
2013.com.canonical.certification::disk/smart: not-supported
2013.com.canonical.certification::disk/stats: pass
2013.com.canonical.certification::disk/storage_devices: pass
2013.com.canonical.certification::dmi: pass
2013.com.canonical.certification::dpkg: pass
2013.com.canonical.certification::efi: pass
2013.com.canonical.certification::environment: pass
2013.com.canonical.certification::ethernet/multi_nic: pass
2013.com.canonical.certification::floppy/check: not-supported
2013.com.canonical.certification::info/hdparm: pass
2013.com.canonical.certification::lsb: pass
2013.com.canonical.certification::meminfo: pass
2013.com.can...

[Jeff Lane  (bladernr)]

This is the filesystem on my screwy working key

Disk /dev/sdb: 4063 MB, 4063232000 bytes
125 heads, 62 sectors/track, 1024 cylinders, total 7936000 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk identifier: 0x000ecf5f

   Device Boot Start End Blocks Id System
/dev/sdb1 1 195312 97656 83 Linux
/dev/sdb2 196608 499711 151552 83 Linux
/dev/sdb3 499712 7935999 3718144 f W95 Ext'd (LBA)
/dev/sdb5 501760 7935999 3717120 83 Linux

[Kent Baxley (kentb)]

Just adding what was discussed on irc:

It looks like it depends on the USB stick. I have 7 of them, and 4 of them will work satisfactorily for the test suite.

The 4 that pass are of varying quality (two were expensive and higher-quality, while two of them were cheap-o brands).

The 3 that never work are also cheaper-quality devices (i.e. freebies or stuff you buy on the endcap at Wal-Mart). Even though the c-c-s test failed these devices, they, for all intents and purposes, work just fine otherwise as a storage device. I can mount, read, write, etc.

All are basically set up the same:

one partition, all formatted with mkfs.vfat. Sizes vary from 4 to 8 to 16GB.

I'll continue testing with the 4 known good ones and before kicking off the tests on the SUT I'll run the usb storage test by hand to make sure it is happy with the device in question. I'll avoid using the others for now.

I'll be glad to supply any other information if you guys want it.

Thanks.

[Daniel Manrique (roadmr)]

Hello!

Jeff, my interpretation of your results is that your USB key is indeed suffering from data corruption. Do you see this with all keys, or just this one? would it be possible for you to reformat the faulty key and see if that helps? If so, that looks to me like a different issue from Kent's, which is about the key just not being found.

[Daniel Manrique (roadmr)]

Kent, I looked at the data you sent (sorry for the delay). I think I know why your USB keys are not detected.

You're specifying to look for only usb storage devices, which should skip memory cards and card readers. We use some interesting heuristics for this. One of them says this:

    # Treat any device that contains the word 'Generic' in the vendor string as
    # a memory card reader.
    #
    # XXX: This seems odd but strangely enough seems to gets the job done. I
    # guess if I should start filing tons of bugs/patches on udev/udisks2 to
    # just have a few more rules and make this rule obsolete.
    if GENERIC_RE.search(vendor):
        return True

here's an excerpt of udisks data for your USB device:

/org/freedesktop/UDisks2/drives/Generic_Flash_Disk_AF52CE66:
  org.freedesktop.UDisks2.Drive:
    Id: Generic-Flash-Disk-AF52CE66
    MediaRemovable: true
    Model: Flash Disk
    Vendor: Generic

Vendor is "Generic", which I think is making the script think it's a memory card and thus ignoring it for USB stickness purposes.

To be 100% certain that's the cause:

1- Please run /usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -l usb --memorycard, I expect this should show the USB stick, as it essentially reverses the logic to discard memory cards.
2- Check whether all the failing sticks have the same Vendor: Generic string (and you can also check that *working* sticks *don't* have this. An easy way to do it is to plug in the stick, then
 udisksctl dump |grep Vendor:

If this is the case, I see two possible solutions:

- Don't use memory sticks with Vendor: Generic :(
- We can look at updating our logic to accomodate this, this will need a bit of research, testing and coding since we need to find something that distinguishes your USB stick from a card reader that shows itself as "Generic". It may not even be possible.

I'll set as Incomplete pending youf confirmation of the two steps I put in the numbered list above.

[Kent Baxley (kentb)]

Good Find! Your analysis is correct.

All of the USB sticks that didn't work do indeed have "Geneirc" in their Vendor name, while the ones that work have something else (Patriot Memory, SMI, etc.).

On the usb sticks that don't work (i.e. have "Generic" vendors), if I go back to the SUT and run:

/usr/lib/plainbox-providers-1/checkbox/bin/removable_storage_test -l usb --memorycard

The test will see the device.

So, that indeed looks to be the case. I'll set aside all of my USB sticks with 'Generic' Vendor information for the time being.

Thanks for all the research!

[Daniel Manrique (roadmr)]

Work to do on this one:

We need to compare device information from a USB stick like Kent's (that has Vendor: Generic) with a USB memory reader, which prompted addition of the heuristic I show in comment #16, and see if we can somehow tell them apart, to fine-tune the heuristic to not mistake USB sticks for memory cards.

Kent provided udisksctl dump data for his USB, we need to find something similar for one of those "generic" card readers. Maybe Zygmunt who authored the storage test originally, has access to one such device.

If we find no way to tell them apart, then at least showing a message indicating that "Generic" devices can't be reliably identified, so the user knows his test device is likely to not work, would be a reasonable compromise. The current situation where there's no explanation is definitely not OK.

[Jeff Lane  (bladernr)]

Yeah, just to clarify, my brief contribution was simply an "Unable to recreate here" not presenting a different bug. I know that key is wonky... :) it's fairly old and to be honest, I'm surprised it still works. Heh...

[Mark W Wenning (mwenning)]

Got a similar error running cert on a Dell PowerEdge T20. However, the bug still shows up with Kent's "good" usb3 drive
In the case with my elcheapo Patriot USB 3 drive, the Vendor shows up as blank.
I am running the whole test again and will submit it to certification.canonical.com and paste the link here.
Let me know if you want me to collect any other data.

ubuntu@T20:/usr/lib/2013.com.canonical.certification:checkbox/bin$ ./removable_storage_test -l usb --memorycard
ERROR:root:No removable drives were detected, aborting
ubuntu@T20:/usr/lib/2013.com.canonical.certification:checkbox/bin$

ubuntu@T20:/usr/lib/2013.com.canonical.certification:checkbox/bin$ ./removable_storage_test -l usb
--------------------
Removable devices currently mounted:
None
Removable devices currently not mounted:
/dev/sdb1
--------------------

My elcheapo 3.0 flashdrive:
ubuntu@T20:/usr/lib/2013.com.canonical.certification:checkbox/bin$ udisksctl dump | grep Vendor:
    Vendor:
    Vendor:

Add Kent's "good" one:
ubuntu@T20:/usr/lib/2013.com.canonical.certification:checkbox/bin$ udisksctl dump | grep Vendor:
    Vendor:
    Vendor: Patriot Memory
    Vendor:

[Mark W Wenning (mwenning)]

Ran cert test again with my elcheapo USB 3.0 and Kent's "good" one.
Probably should write up a new bug, usb3 drives are showing up, they are just failing the 7 MB/s threshold on this box.

https://certification.canonical.com/hardware/201402-14632/submission/99341/ # my elcheapo usb3.0 stick

https://certification.canonical.com/hardware/201402-14632/submission/99342/ # Kent's "good" one.

[Daniel Manrique (roadmr)]

Hi Mark,

If it's a matter of just failing the threshold, you may be interested in https://bugs.launchpad.net/plainbox-provider-checkbox/+bug/1313581, which changed the way we test for USB 3.0; basically we no longer check a specific transfer speed threshold, which as seen here, is unreliable.

I think this will not affect this particular bug (bug 1285770), because the "work to do" is already outlined on comment #18.

But if you updated your packages to the most recent and are still seeing the same "threshold failed" behavior, maybe we can file a new bug because perhaps we still need to update the *job* definitions to account for the updates in the test.

[Daniel Manrique (roadmr)]

See https://bugs.launchpad.net/plainbox-provider-checkbox/+bug/1331528 as filed by Mark.

[Jeff Lane  (bladernr)]

This is an old bug, gonna close it out, no one has complained about this behaviour in a long time.

[Rod Smith (rodsmith)]

FWIW, Jeff, I've got a USB drive that reports as "Generic" and therefore produces this behavior. Here's a submission using this drive:

https://certification.canonical.com/hardware/201409-15506/submission/113323/test-results/

Here's a run on the same computer with PNY-brand media:

https://certification.canonical.com/hardware/201409-15506/submission/113325/test-results/

Since I've got an affected USB drive, I could tackle this bug if you like, or plug it into betelnut in Lexington or send it to somebody else to tackle it if that's preferable.

That said, my drive is an el-cheapo thing I bought on eBay; IIRC, it's one of two I bought from a Chinese seller, and the one I bought with it has long since died, so the quality is suspect. Thus, it may be better to tell people to buy brand-name devices rather than try to save $1 on no-name goods.