Seeing high rate of unlock failures in krillin smoke testing

[Francis Ginther]

This problem was seen 14 times over images 129-134 from ubuntu-touch/devel-proposed on krillin:

[console]
+ reboot-and-unlock.sh
13 KB/s (1049 bytes in 0.078s)
INFO:reboot-and-wait:Restarting device... wait
INFO:reboot-and-wait:Restarting device... wait complete
INFO:reboot-and-wait:Waiting for networking to become active...
PING launchpad.net (91.189.89.223) 56(84) bytes of data.
INFO:reboot-and-wait:Network is active
I: Unlock attempt 1 failed, script output: 'Error: Timeout was reached
'
I: Unlock attempt 2 failed, script output: 'Error: Timeout was reached
'
I: Unlock attempt 3 failed, script output: 'Error: Timeout was reached
'
I: Unlock attempt 4 failed, script output: 'Error: Timeout was reached
'
I: Unlock attempt 5 failed, script output: 'Error: Timeout was reached
'
I: Too many unlock failures, giving up
[/console]

The smoke tests do reboot the phone between test suites, so it ends up rebooting the phone a few dozen times during a full run. Looking back through prior logs, I see this older examples of this, but it appears to be a little more frequent over the past week. Perhaps this is related to https://bugs.launchpad.net/ubuntu/+source/unity8/+bug/1421009 ?

Here are some examples:
image 134
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/538/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/537/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/535/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/534/console
image 133
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/528/console
image 132
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/524/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/523/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/522/console
image 131
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/521/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/519/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/518/console
image 130
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/516/console
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/515/console
image 129
http://dev-jenkins.ubuntu-ci:8080/job/vivid-touch-krillin-smoke-daily/513/console

[Michael Terry (mterry)]

So yeah, this looks exactly like a more frequent bug 1421009, which was due to a dbus mutex hang.

Here are some possibly related dbus hang bugs:

Bug 1421009 (vivid, basically same bug as this one)
Bug 1417773 (RTM)
Bug 1421308 (vivid?)

The most reliable reproducer of the bunch is bug 1421009, which involves reflashing a bunch.

And it also suggests the earliest sign of the bug as vivid image 106.

[Michael Terry (mterry)]

Kevin, I'm assigning to you just so you can farm out to someone else. I don't think this is a bug in the unity8 layer, but rather lower-level. It just needs some investigative work.