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

Issue 755816 link

Starred by 1 user
Status: Archived
Owner:
█ porce@chromium.org
Last visit > 30 days ago
Closed: Aug 2017
Cc:
█ frankhu@chromium.org
█ mzhuo@chromium.org
dsunk...@chromium.org
█ egemih@chromium.org
harpreet@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

Huddly Updater autotest failing with "AutoservRunError: command execution error"

Project Member Reported by harpreet@chromium.org, Aug 16 2017 
Good thing is that enterprise_CFM_HuddlyUpdater is finally running nightly now. Bad thing is that it failing because of AutoservRunError: command execution error

Test results in wmatrix: https://wmatrix.googleplex.com/matrix/unfiltered?hide_missing=True&tests=enterprise_CFM_HuddlyUpdater&days_back=30
Test logs for 1 of the test runs: https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/135166825-chromeos-test/chromeos1-row3-rack5-host3/


Sample trace below...


08/15 01:22:02.723 WARNI|              test:0612| The test failed with the following exception
Traceback (most recent call last):
  File "/usr/local/autotest/client/common_lib/test.py", line 606, in _exec
    _call_test_function(self.execute, *p_args, **p_dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 812, in _call_test_function
    raise error.UnhandledTestFail(e)
UnhandledTestFail: Unhandled AutoservRunError: command execution error
* Command: 
    /usr/bin/ssh -a -x     -o StrictHostKeyChecking=no -o
    UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o
    ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4
    -o Protocol=2 -l root -p 22 chromeos1-row3-rack5-host3 "export
    LIBC_FATAL_STDERR_=1; if type \"logger\" > /dev/null 2>&1; then logger
    -tag \"autotest\" \"server[stack::_shcmd|run|wrapper] -> ssh_run(rm -rf
    /lib/firmware/huddly)\";fi; rm -rf /lib/firmware/huddly"
Exit status: 1
Duration: 0.669053077698

stderr:
rm: cannot remove '/lib/firmware/huddly/bin/huddly_boot.bin': Read-only file system
rm: cannot remove '/lib/firmware/huddly/bin/huddly.bin': Read-only file system
rm: cannot remove '/lib/firmware/huddly/huddly.pkg': Read-only file system
rm: cannot remove '/lib/firmware/huddly/manifest.json': Read-only file system
rm: cannot remove '/lib/firmware/huddly/manifest.txt': Read-only file system
Traceback (most recent call last):
  File "/usr/local/autotest/client/common_lib/test.py", line 806, in _call_test_function
    return func(*args, **dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 470, in execute
    dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 347, in _call_run_once_with_retry
    postprocess_profiled_run, args, dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 380, in _call_run_once
    self.run_once(*args, **dargs)
  File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 140, in run_once
    self.cleanup()
  File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 54, in cleanup
    self._shcmd(cmd)
  File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 64, in _shcmd
    return self._client.run(cmd)
  File "/usr/local/autotest/server/hosts/ssh_host.py", line 316, in run
    return self.run_very_slowly(*args, **kwargs)
  File "/usr/local/autotest/site-packages/chromite/lib/metrics.py", line 458, in wrapper
    return fn(*args, **kwargs)
  File "/usr/local/autotest/server/hosts/ssh_host.py", line 307, in run_very_slowly
    ssh_failure_retry_ok)
  File "/usr/local/autotest/server/hosts/ssh_host.py", line 258, in _run
    raise error.AutoservRunError("command execution error", result)
AutoservRunError: command execution error
* Command: 
    /usr/bin/ssh -a -x     -o StrictHostKeyChecking=no -o
    UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o
    ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4
    -o Protocol=2 -l root -p 22 chromeos1-row3-rack5-host3 "export
    LIBC_FATAL_STDERR_=1; if type \"logger\" > /dev/null 2>&1; then logger
    -tag \"autotest\" \"server[stack::_shcmd|run|wrapper] -> ssh_run(rm -rf
    /lib/firmware/huddly)\";fi; rm -rf /lib/firmware/huddly"
Exit status: 1
Duration: 0.669053077698

stderr:
rm: cannot remove '/lib/firmware/huddly/bin/huddly_boot.bin': Read-only file system
rm: cannot remove '/lib/firmware/huddly/bin/huddly.bin': Read-only file system
rm: cannot remove '/lib/firmware/huddly/huddly.pkg': Read-only file system
rm: cannot remove '/lib/firmware/huddly/manifest.json': Read-only file system
rm: cannot remove '/lib/firmware/huddly/manifest.txt': Read-only file system

08/15 01:22:02.724 DEBUG|              test:0617| Running cleanup for test.
08/15 01:22:02.724 INFO |enterprise_CFM_Hud:0063| CMD: [rm -rf /lib/firmware/huddly]
08/15 01:22:02.748 DEBUG|          ssh_host:0296| Running (ssh) 'rm -rf /lib/firmware/huddly' from '_cherry_pick_call|cleanup|_shcmd|run|wrapper|run_very_slowly'
08/15 01:22:03.510 ERROR|             utils:0280| [stderr] rm: cannot remove '/lib/firmware/huddly/bin/huddly_boot.bin': Read-only file system
08/15 01:22:03.511 ERROR|             utils:0280| [stderr] rm: cannot remove '/lib/firmware/huddly/bin/huddly.bin': Read-only file system
08/15 01:22:03.512 ERROR|             utils:0280| [stderr] rm: cannot remove '/lib/firmware/huddly/huddly.pkg': Read-only file system
08/15 01:22:03.513 ERROR|             utils:0280| [stderr] rm: cannot remove '/lib/firmware/huddly/manifest.json': Read-only file system
08/15 01:22:03.513 ERROR|             utils:0280| [stderr] rm: cannot remove '/lib/firmware/huddly/manifest.txt': Read-only file system
08/15 01:22:03.516 ERROR|              test:0620| Ignoring exception during cleanup() phase:
08/15 01:22:03.517 ERROR|         traceback:0013| Traceback (most recent call last):
08/15 01:22:03.517 ERROR|         traceback:0013|   File "/usr/local/autotest/client/common_lib/test.py", line 618, in _exec
08/15 01:22:03.518 ERROR|         traceback:0013|     _cherry_pick_call(self.cleanup, *args, **dargs)
08/15 01:22:03.519 ERROR|         traceback:0013|   File "/usr/local/autotest/client/common_lib/test.py", line 721, in _cherry_pick_call
08/15 01:22:03.520 ERROR|         traceback:0013|     return func(*p_args, **p_dargs)
08/15 01:22:03.520 ERROR|         traceback:0013|   File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 54, in cleanup
08/15 01:22:03.521 ERROR|         traceback:0013|     self._shcmd(cmd)
08/15 01:22:03.522 ERROR|         traceback:0013|   File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 64, in _shcmd
08/15 01:22:03.522 ERROR|         traceback:0013|     return self._client.run(cmd)
08/15 01:22:03.523 ERROR|         traceback:0013|   File "/usr/local/autotest/server/hosts/ssh_host.py", line 316, in run
08/15 01:22:03.524 ERROR|         traceback:0013|     return self.run_very_slowly(*args, **kwargs)
08/15 01:22:03.524 ERROR|         traceback:0013|   File "/usr/local/autotest/site-packages/chromite/lib/metrics.py", line 458, in wrapper
08/15 01:22:03.525 ERROR|         traceback:0013|     return fn(*args, **kwargs)
08/15 01:22:03.525 ERROR|         traceback:0013|   File "/usr/local/autotest/server/hosts/ssh_host.py", line 307, in run_very_slowly
08/15 01:22:03.526 ERROR|         traceback:0013|     ssh_failure_retry_ok)
08/15 01:22:03.527 ERROR|         traceback:0013|   File "/usr/local/autotest/server/hosts/ssh_host.py", line 258, in _run
08/15 01:22:03.527 ERROR|         traceback:0013|     raise error.AutoservRunError("command execution error", result)
08/15 01:22:03.529 ERROR|         traceback:0013| AutoservRunError: command execution error
08/15 01:22:03.529 ERROR|         traceback:0013| * Command: 
08/15 01:22:03.530 ERROR|         traceback:0013|     /usr/bin/ssh -a -x     -o StrictHostKeyChecking=no -o
08/15 01:22:03.530 ERROR|         traceback:0013|     UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o
08/15 01:22:03.531 ERROR|         traceback:0013|     ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4
08/15 01:22:03.531 ERROR|         traceback:0013|     -o Protocol=2 -l root -p 22 chromeos1-row3-rack5-host3 "export
08/15 01:22:03.532 ERROR|         traceback:0013|     LIBC_FATAL_STDERR_=1; if type \"logger\" > /dev/null 2>&1; then logger
08/15 01:22:03.532 ERROR|         traceback:0013|     -tag \"autotest\" \"server[stack::_shcmd|run|wrapper] -> ssh_run(rm -rf
08/15 01:22:03.533 ERROR|         traceback:0013|     /lib/firmware/huddly)\";fi; rm -rf /lib/firmware/huddly"
08/15 01:22:03.534 ERROR|         traceback:0013| Exit status: 1
08/15 01:22:03.534 ERROR|         traceback:0013| Duration: 0.706113815308
08/15 01:22:03.535 ERROR|         traceback:0013| 
08/15 01:22:03.535 ERROR|         traceback:0013| stderr:
08/15 01:22:03.536 ERROR|         traceback:0013| rm: cannot remove '/lib/firmware/huddly/bin/huddly_boot.bin': Read-only file system
08/15 01:22:03.536 ERROR|         traceback:0013| rm: cannot remove '/lib/firmware/huddly/bin/huddly.bin': Read-only file system
08/15 01:22:03.537 ERROR|         traceback:0013| rm: cannot remove '/lib/firmware/huddly/huddly.pkg': Read-only file system
08/15 01:22:03.537 ERROR|         traceback:0013| rm: cannot remove '/lib/firmware/huddly/manifest.json': Read-only file system
08/15 01:22:03.538 ERROR|         traceback:0013| rm: cannot remove '/lib/firmware/huddly/manifest.txt': Read-only file system
08/15 01:22:03.538 ERROR|              test:0624| Now raising the earlier <class 'autotest_lib.client.common_lib.error.UnhandledTestFail'> error

Comment 1 by harpreet@chromium.org, Aug 16 2017

Labels: meeting-rooms-sheriff

Comment 2 by porce@chromium.org, Aug 21 2017

Cc: egemih@chromium.org harpreet@chromium.org dsunk...@chromium.org
Evidently, this is caused from a wrong assumption that the Autotest testbed DUT's root file system is read-writable.

At the same time, the fact that the DUT filesystem may be read-only, imposes a restriction on the scope of the autotesting of the firmware update. This is because of the fact that the udev rule, and the huddly-updater has hard-coded path to the firmware package files, and testing the USB unplug/plug will have to invoke udev rule-driven huddly-updater.

Comment 3 by porce@chromium.org, Aug 21 2017 


Due to the way that ChromeOS the minijail, the udev rule, and the huddly-updater work together, if the DUT filesystem is NOT writable, we cannot perform the Huddly updater test. This is essentially it requires a new firmware to try out, which is not loaded on the DUT's OS before the test.


Here is the plan for fix:
1. The new autotest will test if the filesystem is writable or not. If not, the test will be skipped with warning message.

2. I recommend Autotest DUT have the writable root file system.

harpreet@, please comment on the 2nd point.
Project Member

Comment 5 by bugdroid1@chromium.org, Aug 24 2017 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/autotest/+/6b45b8c0d5b1a247baac4c727d020d2c0c28575b

commit 6b45b8c0d5b1a247baac4c727d020d2c0c28575b
Author: Jiwoong Lee <porce@google.com>
Date: Thu Aug 24 10:24:13 2017

Make DUT root filesystem read-writable if not

BUG= chromium:755816 
TEST=None
# pre-cq-configs: bluestreak-pre-cq

Change-Id: Ic977ababa078be3fd530f88a34f8f9c3f4f34756
Reviewed-on: https://chromium-review.googlesource.com/630764
Commit-Ready: Jiwoong Lee <porce@chromium.org>
Tested-by: Jiwoong Lee <porce@chromium.org>
Reviewed-by: Harpreet Grewal <harpreet@chromium.org>

[modify] https://crrev.com/6b45b8c0d5b1a247baac4c727d020d2c0c28575b/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py
Project Member

Comment 6 by bugdroid1@chromium.org, Aug 25 2017 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/huddly-updater/+/85b099e68c84891a01f99aa6be42e6e4a5e687a5

commit 85b099e68c84891a01f99aa6be42e6e4a5e687a5
Author: Jiwoong Lee <porce@google.com>
Date: Fri Aug 25 03:41:12 2017

Show info to stdout directly bypassing logging facility

This works around an issue of libchrome logging in which logging goes to
stderr while log_file is stdout.

BUG= chromium:755816 
TEST=Build guado package, run on DUT.

Change-Id: I807424a0e137018898b080af30be4b3121204f80
Reviewed-on: https://chromium-review.googlesource.com/633704
Commit-Ready: Jiwoong Lee <porce@chromium.org>
Tested-by: Jiwoong Lee <porce@chromium.org>
Reviewed-by: Zhongze Hu <frankhu@google.com>

[modify] https://crrev.com/85b099e68c84891a01f99aa6be42e6e4a5e687a5/src/firmware.cc
[modify] https://crrev.com/85b099e68c84891a01f99aa6be42e6e4a5e687a5/src/minicam_device.cc

Comment 7 by porce@chromium.org, Aug 25 2017

Status: Fixed (was: Untriaged)
This particular issue is now addressed. 
I expect future Autotest will encounter a separate issue, which appears to be related to the way host.run() is executed. Please open a separate bug if that is the case.

Comment 8 by harpreet@chromium.org, Aug 27 2017

Status: Assigned (was: Fixed)
Its still failing with command execution error but not because of read-only file system... I am re-opening this bug for now due to same error message but let me know if you prefer a separate bug.


Complete logs: https://storage.cloud.google.com/chromeos-autotest-results/137663997-chromeos-test/chromeos1-row3-rack5-host3/enterprise_CFM_HuddlyUpdater/debug/enterprise_CFM_HuddlyUpdater.DEBUG?_ga=2.180448036.-2021762073.1503789544


Snippet:

08/27 02:54:31.724 INFO |enterprise_CFM_Hud:0071| CMD: [[ -f /lib/firmware/huddly ] && rm -rf /lib/firmware/huddly]
08/27 02:54:31.744 DEBUG|          ssh_host:0296| Running (ssh) '[ -f /lib/firmware/huddly ] && rm -rf /lib/firmware/huddly' from 'run_once|cleanup|_shcmd|run|wrapper|run_very_slowly'
08/27 02:54:32.509 DEBUG|              test:0389| Test failed due to command execution error
* Command: 
    /usr/bin/ssh -a -x     -o StrictHostKeyChecking=no -o
    UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o
    ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4
    -o Protocol=2 -l root -p 22 chromeos1-row3-rack5-host3 "export
    LIBC_FATAL_STDERR_=1; if type \"logger\" > /dev/null 2>&1; then logger
    -tag \"autotest\" \"server[stack::_shcmd|run|wrapper] -> ssh_run([ -f
    /lib/firmware/huddly ] && rm -rf /lib/firmware/huddly)\";fi; [ -f
    /lib/firmware/huddly ] && rm -rf /lib/firmware/huddly"
Exit status: 1

Duration: 0.710116863251

Traceback (most recent call last):
  File "/usr/local/autotest/client/common_lib/test.py", line 806, in _call_test_function
    return func(*args, **dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 470, in execute
    dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 347, in _call_run_once_with_retry
    postprocess_profiled_run, args, dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 380, in _call_run_once
    self.run_once(*args, **dargs)
  File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 179, in run_once
    self.cleanup()
  File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 62, in cleanup
    self._shcmd(cmd)
  File "/usr/local/autotest/server/site_tests/enterprise_CFM_HuddlyUpdater/enterprise_CFM_HuddlyUpdater.py", line 72, in _shcmd
    result = self._client.run(cmd)
  File "/usr/local/autotest/server/hosts/ssh_host.py", line 316, in run
    return self.run_very_slowly(*args, **kwargs)
  File "/usr/local/autotest/site-packages/chromite/lib/metrics.py", line 482, in wrapper
    return fn(*args, **kwargs)
  File "/usr/local/autotest/server/hosts/ssh_host.py", line 307, in run_very_slowly
    ssh_failure_retry_ok)
  File "/usr/local/autotest/server/hosts/ssh_host.py", line 258, in _run
    raise error.AutoservRunError("command execution error", result)
AutoservRunError: command execution error

Comment 9 by porce@chromium.org, Aug 28 2017

Status: Fixed (was: Assigned)
harpreet@,
Yes, kindly open a new bug. The original root cause of this bug is now fixed; the new foundings should go to a new bug. The what you encounter is from a different cause and should be tracked down in a different bug; I expected it to occur in #7; unfortunately due to a recurring issue "Master ssh session down" in my setup, it was difficult for me to cover.

Comment 10 by dchan@chromium.org, Jan 22 2018

Status: Archived (was: Fixed)
►

Sign in to add a comment