[power-management/suspend_30_cycles_with_reboots] Need to wake system up manually often

[Jerry Kao]

Title: [power-management/suspend_30_cycles_with_reboots] Need to wake system up manually often

Summary:
When running test case power-management/suspend_30_cycles_with_reboots, system should be suspend for 30 cycles -> reboot -> suspend for 30 cycles -> reboot -> suspend for 30 cycles automatically.
But when I test, system does not wake up automatically. I have to press power buttom to wake it up manually. Normally system should resume from suspend in 5 seconds (with new test method : pm_test). It happen about 10 times.
After test done, I cannot check how many times suspend test exedcute exactly. In previous test case with fwts, we can check fwts results.log for each suspend of 30 cycles.

This maybe a timing issue.
As HWE suggest for s3 test with fwts, system should be waked up for 90+ seconds.
This verifies BIOS and kernel modules' suspend and resume functions. Suggested command:--s3-min-delay=60 --s3-max-delay=90 --s3-sleep-delay=90
https://wiki.canonical.com/PES/Engineering/HardwareEnablement/FWTS/TestSuggestions

Steps: run checkboox test case power-management/suspend_30_cycles_with_reboots

Expected results: test case can be done automatically. No need to wake system up from suspend manually.

Actual results: Need to wake system up manually often.

Additional information:
Plainbox version
ii plainbox 0.24~c1~ppa~ubuntu14.04.1 all toolkit for software and hardware integration testing
ii plainbox-glmark2-es2-meta 0.20.1-3 amd64 Meta-package to selectively install glmark2-es2
ii plainbox-insecure-policy 0.24~c1~ppa~ubuntu14.04.1 all policykit policy required to use plainbox (insecure version)
ii plainbox-provider-certification-client 0.20.1-3 all Client Certification provider for Plainbox
ii plainbox-provider-checkbox 0.23~c1~ppa~ubuntu14.04.1 amd64 CheckBox provider for PlainBox
ii plainbox-provider-oem 0.25 all plainbox oem provider
ii plainbox-provider-oem-stella 0.25 all plainbox oem provider for stella
ii plainbox-provider-resource-generic 0.21~c1~ppa~ubuntu14.04.1 amd64 CheckBox generic resource jobs provider
ii python3-plainbox 0.24~c1~ppa~ubuntu14.04.1 all toolkit for software and hardware testing (python3 module)

checkbox version
ii checkbox 0.17.9.1~ubuntu14.04.1 amd64 System testing application
ii checkbox-gui 0.34~ppa~ubuntu14.04.1 amd64 QML based interface for system testing based on PlainBox.
ii checkbox-hw-collection 0.17.9.1~ubuntu14.04.1 amd64 CLI tool for collecting HW information from a system
ii checkbox-ng 0.22~c1~ppa~ubuntu14.04.1 all PlainBox based test runner
ii checkbox-ng-service 0.22~c1~ppa~ubuntu14.04.1 all CheckBox D-Bus service (transitional package)
ii checkbox-oem-bug 1.8-1-ubuntu1 all Checkbox OEM bug
ii plainbox-provider-checkbox 0.23~c1~ppa~ubuntu14.04.1 amd64 CheckBox provider for PlainBox
ii python3-checkbox 0.17.9.1~ubuntu14.04.1 all CheckBox python3 library
ii python3-checkbox-ng 0.22~c1~ppa~ubuntu14.04.1 all PlainBox based test runner (Python 3 library)
ii python3-checkbox-support 0.22~c1~ppa~ubuntu14.04.1 all collection of Python modules used by PlainBox providers

Image: stella-datong140729-trusty-amd64-20141230-1

CPU:
AMD A6 PRO-7050B R4, 5 Compute Cores 2C+3G (1x)
AMD A6 PRO-7050B R4, 5 Compute Cores 2C+3G (1x)

GPU: 00:01.0 VGA compatible controller: Advanced Micro Devices, Inc. [AMD/ATI] Kaveri

Manufacturer: Hewlett-Packard

ProductName: HP ProBook 455G2

BiosVersion: M75 Ver. 01.30

[Jerry Kao (jerry.kao)]

Automatically attached

[Pierre Equoy (pieq)]

I tested on Skittles 2 using the following process:

- install latest version of plainbox/checkbox with boxer (./boxer install -p stella)
- run the “3 × (30 suspend + reboot)” cycle job using this command:
    plainbox run -i ^.*suspend_30_cycles_with_reboots.*

A single suspend test is run (OK since it's a dependency of suspend_30_cycles_with_reboots job) followed by the job.

The device:
- suspends 30 times
- reboots
- suspends 30 more times
- reboots
- suspends 30 more times
- reboots one last time
- displays a popup window saying the reboot test is finished.

After that, I can go to the Checkbox data directory (~/.cache/plainbox/sessions/pbox-*.session/CHECKBOX_DATA/) and check the file `pm_test.reboot.3.log`.

Amongst other things, it contains three blocks of information like this:

2015-11-18 15:12:41,475 INFO ==================== Test Results ====================
1: ('Pass', 0.8830309999999884, 2.6965350000000115)
2: ('Pass', 0.9341039999999907, 2.6965569999999843)
3: ('Pass', 0.8784220000000005, 2.6965250000000083)
4: ('Pass', 0.8767419999999788, 2.644531000000029)
5: ('Pass', 0.9277670000000171, 2.688652999999988)
6: ('Pass', 0.8591779999999858, 2.63654600000001)
7: ('Pass', 0.9071660000000179, 2.6484350000000063)
8: ('Pass', 0.9000689999999736, 2.640412000000026)
9: ('Pass', 0.8103550000000155, 2.7045760000000314)
10: ('Pass', 0.8752700000000004, 2.692457000000047)
11: ('Pass', 0.8766650000000027, 2.7003710000000183)
12: ('Pass', 0.8944709999999532, 2.7006300000000465)
13: ('Pass', 0.7866449999999645, 2.6446200000000317)
14: ('Pass', 0.8707489999999893, 2.648669000000041)
15: ('Pass', 0.8761180000000195, 2.644679999999994)
16: ('Pass', 0.888198999999986, 2.692610000000002)
17: ('Pass', 0.876152999999988, 2.7046589999999924)
18: ('Pass', 0.8735120000000052, 2.640692999999999)
19: ('Pass', 0.8576380000000086, 2.6444529999999986)
20: ('Pass', 0.8974329999999782, 2.6884230000000002)
21: ('Pass', 0.8477219999999761, 2.6405399999999872)
22: ('Pass', 0.8911480000000438, 2.6846739999999727)
23: ('Pass', 0.8660689999999818, 2.6484649999999874)
24: ('Pass', 0.8434219999999755, 2.696510999999987)
25: ('Pass', 0.8399809999999661, 2.644602999999961)
26: ('Pass', 0.8815709999999513, 2.644391999999982)
27: ('Pass', 0.8474590000000148, 2.644365999999991)
28: ('Pass', 0.8545450000000301, 2.70873899999998)
29: ('Pass', 0.8566369999999779, 2.640642000000014)
30: ('Pass', 0.8616650000000163, 2.6846630000000005)
Average time to sleep: 0.8713
Average time to resume: 2.6698
Successfully completed 30 sleep iterations

Each line is the result of a suspend test, so we can see in the block above that the 30 suspend tests have passed.

Then another line in the log shows:

2015-11-18 15:12:48,460 INFO Executing new 'reboot' operation...

Which proves that the device reboots. It is followed by 30 more suspend tests, and one more reboot, etc.

I'll check directly on the device used by Jerry.

[Jerry Kao (jerry.kao)]

Thanks, Pierre.
I can find the test log in /.cache/plainbox/sessions/pbox-*.session/CHECKBOX_DATA/

The data of one block is as follow
2015-11-16 15:59:30,778 INFO ==================== Test Results ====================
1: ('Pass', 1.062630999999996, 2.556276000000004)
2: ('Pass', 1.2526889999999966, 2.5595630000000043)
3: ('Pass', 1.1097979999999978, 2.5524739999999895)
4: ('Pass', 5.9812319999999914, 2.6652909999999963)
5: ('Pass', 1.1572329999999909, 2.6801849999999945)
6: ('Pass', 1.0136809999999912, 2.6560280000000063)
7: ('Pass', 1.0746429999999947, 2.6567409999999967)
8: ('Pass', 1.0531700000000086, 2.647416000000007)
9: ('Pass', 1.6550189999999816, 2.658508000000012)
10: ('Pass', 1.1328419999999824, 2.6004900000000077)
11: ('Pass', 1.1038310000000138, 2.6045540000000074)
12: ('Pass', 1.1340370000000064, 2.6124650000000145)
13: ('Pass', 1.0221739999999784, 2.603566999999998)
14: ('Pass', 1.1005830000000003, 2.6324550000000215)
15: ('Pass', 2.7811989999999867, 2.592646000000002)
16: ('Pass', 1.0873420000000067, 2.6065670000000125)
17: ('Pass', 1.1172590000000184, 2.5906999999999982)
18: ('Pass', 1.1166059999999902, 2.56845899999999)
19: ('Pass', 1.0927939999999978, 2.572991000000002)
20: ('Pass', 1.053465999999986, 2.5845700000000136)
21: ('Pass', 1.1154839999999808, 2.5684200000000033)
22: ('Pass', 1.2842530000000068, 2.555650000000014)
23: ('Pass', 1.088187000000005, 2.642614999999978)
24: ('Pass', 1.0245330000000195, 2.560701999999992)
25: ('Pass', 0.9475909999999885, 2.572638999999981)
26: ('Pass', 1.1383519999999976, 2.5646980000000212)
27: ('Pass', 0.9663079999999695, 2.5807159999999953)
28: ('Pass', 4.453579999999988, 2.55249699999996)
29: ('Pass', 0.9670639999999935, 2.576279999999997)
30: ('Pass', 1.1933139999999867, 2.5685169999999857)
Average time to sleep: 1.4427
Average time to resume: 2.5982
Successfully completed 30 sleep iterations

The sleep times are not as consistence as yours, and I did wake system up manually several times.

But since HWE suggest to use fwts as test method for suspend. I think we will switch this test case to fwts.

[Pierre Equoy (pieq)]

@Jerry: Yes you're right. Today we discussed with Sylvain and Ara about it, and the best approach is to switch to fwts which is actively maintained and more flexible. I'll have a look at it when I'm back from holidays (Monday).

[Jerry Kao (jerry.kao)]

HWE suggests parameters are time consuming.

Since original parameters (--s3-device-check-delay=45 --s3-sleep-delay=30) work well and did not cause any issue. Suggest to keep it.

[Pierre Equoy (pieq)]

Following a discussion with Jerry on IRC, I proposed to use the default value suggested by fwts for the --s3-device-check-delay parameter (15 seconds).