suspend-time-check not reporting any time

[omar-selo]

Bug Description

Suspend time check is failing on some machines with no reported times at all. Look at this example.

Cert-blocker Test Case

• cert-blocker

To Reproduce

Run the job http://10.102.156.15:8080/job/cert-oem-sru-jammy-desktop-hp-elite-tower-880-g9-desktop-pc-c30938

Environment

Look at the submission https://certification.canonical.com/hardware/202212-30938/submission/403415/

Relevant log output

Warning: Time to sleep was only reported 0 times out of 1 iterations!

Warning: Time to resume was only reported 0 times out of 1 iterations!

Average time to sleep: N/A

ERROR: One or more sleep times was not reported correctly:
could not convert string to float: 'N/A'
Average time to resume: N/A

ERROR: One or more resume times was not reported correctly:
could not convert string to float: 'N/A'

Additional context

No response

[syncronize-issues-to-jira]

Thank you for reporting us your feedback!

The internal ticket has been created: https://warthogs.atlassian.net/browse/CHECKBOX-1675.

This message was autogenerated

[fernando79513]

This seems to be an issue with the suspend/suspend_advanced_auto for some reason fwts is not reporting the sleep time.
The same error has been found in a set of devices:

• hp-z6-g5-a-workstation-desktop-pc-c34219
• hp-z6-g5-workstation-desktop-pc-c35313
• hp-z6-g5-workstation-desktop-pc-c35315
• hp-z8-fury-g5-workstation-desktop-pc-c35886
• hp-z8-g5-workstation-desktop-pc-c35572
• hp-z8-g5-workstation-desktop-pc-c35573
• hp-z8-g5-workstation-desktop-pc-c35574

Calling fwts
==================== Test Results ====================

1 iterations total.
Warning: Time to sleep was only reported 0 times out of 1 iterations!
Warning: Time to resume was only reported 0 times out of 1 iterations!

Average time to sleep: N/A
Average time to resume: N/A

Passed: 1
 - sleep

 Please review the following log for more information:

================================= Iteration 1 ==================================
Results generated by fwts: Version V25.01.00 (2025-01-21 03:29:52).

Some of this work - Copyright (c) 1999 - 2025, Intel Corp. All rights reserved.
Some of this work - Copyright (c) 2010 - 2025, Canonical.
Some of this work - Copyright (c) 2016 - 2025, IBM.
Some of this work - Copyright (c) 2017 - 2025, ARM Ltd.

This test run on 24/01/25 at 03:13:44 on host Linux localhost 6.8.0-1021-oem
#21-Ubuntu SMP PREEMPT_DYNAMIC Thu Jan 23 08:32:22 UTC 2025 x86_64.

Command: "fwts -q --stdout-summary -r /var/tmp/checkbox-ng/sessions
/session_title-2025-01-24T02.55.55.session/session-share/suspend_single.log
--s3-sleep-delay 30 --s3-device-check --s3-device-check-delay 45 s3".
Running tests: s3.

s3: Sleep suspend/resume test.
--------------------------------------------------------------------------------
Test 1 of 1: Sleep suspend/resume test.
Defaulted to 1 test, use --s3-multiple=N to run more S3 cycles 
S3 cycle 1 of 1 
Detecting the power method.
Response to CanSuspend is yes 
User allowed to execute the CanSuspend action 
Using logind as the default power method.
Cannot open /sys/class/bluetooth to scan bluetooth devices.
Cannot open /sys/class/typec to scan Type-C devices.
Requesting Suspend action 
Skipping the minimum delay (0) and using a 3 seconds delay instead 
S3 duration = 53.
wakeup source name: "00:00" wakeup event was signaled.
pm-action returned 0 after 53 seconds.
Cannot open /sys/class/bluetooth to scan bluetooth devices.
Cannot open /sys/class/typec to scan Type-C devices.
Suspend/Resume Timings:
  Could not determine time to suspend.
  Could not determine time to resume.
Completed S3 cycle(s) 
PASSED: Test 1, No kernel log errors detected.
PASSED: Test 1, No PM related suspend issues detected.
PASSED: Test 1, No device errors detected.
PASSED: Test 1, No kernel oopses detected.
PASSED: Test 1, No kernel WARN_ON warnings detected.
PASSED: Test 1, No s2idle errors detected.
PASSED: Test 1, Found no errors doing 1 suspend/resume cycle(s).
PASSED: Test 1, All suspends took less than 15.00 seconds.
PASSED: Test 1, All resumes took less than 15.00 seconds.

================================================================================
9 passed, 0 failed, 0 warning, 0 aborted, 0 skipped, 0 info only.
================================================================================


9 passed, 0 failed, 0 warning, 0 aborted, 0 skipped, 0 info only.

Test Failure Summary
================================================================================

Critical failures: NONE

High failures: NONE

Medium failures: NONE

Low failures: NONE

Other failures: NONE

Test           |Pass |Fail |Abort|Warn |Skip |Info |
---------------+-----+-----+-----+-----+-----+-----+
s3             |    9|     |     |     |     |     |
---------------+-----+-----+-----+-----+-----+-----+
Total:         |    9|    0|    0|    0|    0|    0|
---------------+-----+-----+-----+-----+-----+-----+

[pieqq]

An upstream issue has been filed, but FWTS maintainer cannot reproduce the issue, even with devices that exhibit the problem in the past. I will report these new findings to him.

[omar-selo]

Looks like this issue doesn't always occur. I happen to rerun a test execution that passed this test, and then it failed it in the second run.

[pieqq]

FWTS maintainer found an issue with FWTS when the kernel log buffer is emptied (using dmesg -C), which seems to be what we do in the lab before running tests.

Waiting for a test version to see if this improves the test outcome.

[pieqq]

It's now confirmed that the issue stems from FWTS, not from Checkbox. The issue is tracked above, so I'll close this and wait for a new version of FWTS to test this.