New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 920414 link

Starred by 1 user
Status: Duplicate
Merged: issue 916811
Owner:
█ ravisadineni@chromium.org
Last visit > 30 days ago
Closed: Jan 18
Cc:
pgangishetty@chromium.org
█ ravisadineni@chromium.org
matthewjoseph@chromium.org
ka...@chromium.org
derat@chromium.org
█ patricia@chromium.org
dchan@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug-Regression



Sign in to add a comment

[Chameleon_audio] Jerry audio suspend tests are failing on M73.

Project Member Reported by sontis@chromium.org, Jan 9 
DUT: veyron_jerry

Host names: chromeos15-audiobox2-host1 & 	
chromeos15-row14b-rack8-host1

https://screenshot.googleplex.com/k200UpZ92w1


From debug logs:
=========================================================================01/09 08:19:19.853 INFO |        server_job:0217| 	END FAIL	----	suspend	timestamp=1547050759	localtime=Jan 09 08:19:19	DUT is not responding after 77 seconds
  Traceback (most recent call last):
    File "/usr/local/autotest/server/server_job.py", line 964, in run_op
      op_func()
    File "/usr/local/autotest/server/hosts/remote.py", line 217, in suspend
      "DUT is not responding after %d seconds" % (time_counter))
  AutoservSuspendError: DUT is not responding after 77 seconds
01/09 08:19:19.853 INFO | audio_widget_link:0084| Disconnecting ( Cros | HDMI | source ) from ( Chameleon | HDMI | sink )
01/09 08:19:19.853 INFO |         chameleon:0462| Unplug Chameleon port 3
01/09 08:19:19.958 DEBUG|              edid:0076| Wrong checksum in the block 0 of EDID
01/09 08:19:19.959 INFO |         chameleon:0595| Restore the original EDID.
01/09 08:19:20.408 DEBUG|              test:0381| Test failed due to DUT is not responding after 77 seconds. Exception log follows the after_iteration_hooks.
01/09 08:19:20.408 DEBUG|              test:0386| Starting after_iteration_hooks for audio_AudioBasicHDMI
01/09 08:19:20.421 DEBUG|          ssh_host:0310| Running (ssh) 'test -e "/tmp/sysinfo/autoserv-J75VaC"' from 'decorated_func|wrapper|_install|path_exists|run|run_very_slowly'
01/09 08:20:23.633 DEBUG|             utils:0287| [stderr] ssh: connect to host chromeos15-row14b-rack8-host1 port 22: Connection timed out
01/09 08:20:23.636 ERROR|               log:0027| post-test iteration server sysinfo error:
01/09 08:20:23.637 ERROR|         traceback:0013| Traceback (most recent call last):
01/09 08:20:23.637 ERROR|         traceback:0013|   File "/usr/local/autotest/client/common_lib/log.py", line 25, in decorated_func
01/09 08:20:23.638 ERROR|         traceback:0013|     fn(*args, **dargs)
01/09 08:20:23.639 ERROR|         traceback:0013|   File "/usr/local/autotest/server/test.py", line 66, in wrapper
01/09 08:20:23.640 ERROR|         traceback:0013|     host, at, outputdir = self._install()
01/09 08:20:23.640 ERROR|         traceback:0013|   File "/usr/local/autotest/server/test.py", line 142, in _install
01/09 08:20:23.641 ERROR|         traceback:0013|     if not autodir or not self.host.path_exists(autodir):
01/09 08:20:23.641 ERROR|         traceback:0013|   File "/usr/local/autotest/client/common_lib/hosts/base_classes.py", line 520, in path_exists
01/09 08:20:23.642 ERROR|         traceback:0013|     ignore_status=True)
01/09 08:20:23.643 ERROR|         traceback:0013|   File "/usr/local/autotest/server/hosts/ssh_host.py", line 335, in run
01/09 08:20:23.643 ERROR|         traceback:0013|     return self.run_very_slowly(*args, **kwargs)
01/09 08:20:23.644 ERROR|         traceback:0013|   File "/usr/local/autotest/server/hosts/ssh_host.py", line 324, in run_very_slowly
01/09 08:20:23.644 ERROR|         traceback:0013|     ssh_failure_retry_ok)
01/09 08:20:23.645 ERROR|         traceback:0013|   File "/usr/local/autotest/server/hosts/ssh_host.py", line 260, in _run
01/09 08:20:23.646 ERROR|         traceback:0013|     raise error.AutoservSSHTimeout("ssh timed out", result)
01/09 08:20:23.648 ERROR|         traceback:0013| AutoservSSHTimeout: ('ssh timed out', * Command: 
01/09 08:20:23.649 ERROR|         traceback:0013|     /usr/bin/ssh -a -x   -o Protocol=2 -o StrictHostKeyChecking=no -o
01/09 08:20:23.650 ERROR|         traceback:0013|     UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o
01/09 08:20:23.650 ERROR|         traceback:0013|     ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4
01/09 08:20:23.651 ERROR|         traceback:0013|     -l root -p 22 chromeos15-row14b-rack8-host1 "export LIBC_FATAL_STDERR_=1;
01/09 08:20:23.651 ERROR|         traceback:0013|     if type \"logger\" > /dev/null 2>&1; then logger -tag \"autotest\"
01/09 08:20:23.652 ERROR|         traceback:0013|     \"server[stack::_install|path_exists|run] -> ssh_run(test -e
01/09 08:20:23.652 ERROR|         traceback:0013|     \\\"/tmp/sysinfo/autoserv-J75VaC\\\")\";fi; test -e \"/tmp/sysinfo
01/09 08:20:23.653 ERROR|         traceback:0013|     /autoserv-J75VaC\""
01/09 08:20:23.653 ERROR|         traceback:0013| Exit status: 255
01/09 08:20:23.654 ERROR|         traceback:0013| Duration: 63.1985538006
01/09 08:20:23.654 ERROR|         traceback:0013| 
01/09 08:20:23.655 ERROR|         traceback:0013| stderr:
01/09 08:20:23.655 ERROR|         traceback:0013| ssh: connect to host chromeos15-row14b-rack8-host1 port 22: Connection timed out)
01/09 08:20:23.656 DEBUG|              test:0391| after_iteration_hooks completed
01/09 08:20:23.657 WARNI|              test:0606| The test failed with the following exception
Traceback (most recent call last):
  File "/usr/local/autotest/client/common_lib/test.py", line 600, in _exec
    _call_test_function(self.execute, *p_args, **p_dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 806, in _call_test_function
    raise error.UnhandledTestFail(e)
UnhandledTestFail: Unhandled AutoservSuspendError: DUT is not responding after 77 seconds
Traceback (most recent call last):
  File "/usr/local/autotest/client/common_lib/test.py", line 800, in _call_test_function
    return func(*args, **dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 464, in execute
    postprocess_profiled_run, args, dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 371, in _call_run_once
    self.run_once(*args, **dargs)
  File "/usr/local/autotest/server/site_tests/audio_AudioBasicHDMI/audio_AudioBasicHDMI.py", line 131, in run_once
    self.playback_and_suspend(audio_facade, while_playback)
  File "/usr/local/autotest/server/site_tests/audio_AudioBasicHDMI/audio_AudioBasicHDMI.py", line 64, in playback_and_suspend
    self.host.suspend(suspend_time=self.SUSPEND_SEC)
  File "/usr/local/autotest/server/hosts/cros_host.py", line 1114, in suspend
    allow_early_resume);
  File "/usr/local/autotest/server/hosts/remote.py", line 220, in suspend
    self.log_op(self.OP_SUSPEND, suspend)
  File "/usr/local/autotest/client/common_lib/hosts/base_classes.py", line 556, in log_op
    self.job.run_op(op, op_func, self.get_kernel_ver)
  File "/usr/local/autotest/server/server_job.py", line 964, in run_op
    op_func()
  File "/usr/local/autotest/server/hosts/remote.py", line 217, in suspend
    "DUT is not responding after %d seconds" % (time_counter))
AutoservSuspendError: DUT is not responding after 77 seconds

01/09 08:20:23.658 DEBUG|              test:0611| Running cleanup for test.
01/09 08:23:23.760 INFO |remote_facade_fact:0243| Setup the connection to RPC server, with retries...
=======================================================================


This issue is a recent regression. Looks like related to crbug.com/916811

AI's:
 Try to reproduce manually.
    -- Test both powerd suspend and "echo 0 > /sys/class/rtc/rtc0/wakealarm && echo +30 > /sys/class/rtc/rtc0/wakealarm && powerd_dbus_suspend --delay=0" command.

Comment 1 by kalin@google.com, Jan 9

Components: Test OS>Kernel>Power
Right, both hosts are failing suspend since R73-11546.0.0 - https://screenshot.googleplex.com/gPW1dXeMXKG

Yes, this starts after the fix for issue 916811 landed.
Not sure why jerry device be affected by dark resume change(landed at 11545.0.0).

Also, I see no other suspend tests failing to resume: https://stainless.corp.google.com/search?view=matrix&row=build&col=test&first_date=2019-01-03&last_date=2019-01-09&test=%5BSs%5Duspend&board=%5Eveyron_jerry%24&exclude_cts=false&exclude_not_run=true&exclude_non_release=true&exclude_au=true&exclude_acts=true&exclude_retried=true&exclude_non_production=true

Can you check the FW version of these devices if it is up to date?

Comment 2 by sontis@chromium.org, Jan 10 

Lab hosts FW version is up to date.

Able to reproduce this issue manually on M73 build 11552.0.0

Suspend resume is working fine with "powerd_dbus_suspend" command.

But "echo 0 > /sys/class/rtc/rtc0/wakealarm && echo +30 > /sys/class/rtc/rtc0/wakealarm && powerd_dbus_suspend --delay=0" command is failing.

Logs are present at https://pantheon.corp.google.com/storage/browser/chromiumos-test-logs/bugfiles/cros/920414/?debugUI=CLOUD

Comment 3 by kalin@google.com, Jan 10

Owner: ravisadineni@chromium.org
Thanks for reproducing.
ravisadineni@ can you take a look?

Comment 4 by kalin@google.com, Jan 10

Cc: derat@chromium.org

Comment 5 by tbroch@chromium.org, Jan 18 (5 days ago)

Mergedinto: 916811
Status: Duplicate (was: Untriaged)
Looks fixed as of today,

https://screenshot.googleplex.com/i0GNYRX5Zpq

As mentioned likely a dupe of 916811
►

Sign in to add a comment