New issue
Advanced search Search tips

Issue 778326 link

Starred by 1 user

Issue metadata

Status: WontFix
Owner:
Closed: Oct 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

cros flash fails to apply delta payload

Project Member Reported by ahass...@chromium.org, Oct 25 2017

Issue description

simple cros flash works fine for full payloads but when I try to apply delta payload using '--src-image-to-delta' flag, it fails with the following errors. I used to be able to do this with no problem, but there might have been recent changes to the base code that may be causing this? Any idea what could cause this?

Kind of need this to do a lot of UE memory tests for delta payloads.

$ cros flash --debug --src-image-to-delta=../src/build/images/veyron_minnie/latest/chromiumos_test_image.bin  100.127.1.198  veyron-minnie-R63-9928.0.0.bin 
10:42:30: DEBUG: Cache dir lookup.
10:42:30: DEBUG: Configured cache_dir to '/mnt/host/source/.cache'
10:42:30: NOTICE: Preparing to update the remote device 100.127.1.198
10:42:30: INFO: RunCommand: ping -c 1 -w 20 100.127.1.198
10:42:30: INFO: Using image veyron-minnie-R63-9928.0.0.bin
10:42:30: INFO: Copying image to temporary directory /tmp/dev_server_wrapper_local_imageBOGAYj
10:42:48: INFO: Creating a symlink /mnt/host/source/devserver/static/local_imagedCXx9y/link -> /tmp/dev_server_wrapper_local_imageBOGAYj
10:42:48: DEBUG: Assuming local_imagedCXx9y/link/test is an xbuddy path.
10:42:48: INFO: Starting local devserver to generate/serve payloads...
10:42:48: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- start_devserver --pidfile /tmp/devserver_wrapperfBZkoZ/devserver_wrapperg_tia7 --logfile /tmp/devserver_wrapperfBZkoZ/dev_server.log '--port=0' --critical_update '--portfile=/tmp/devserver_wrapperfBZkoZ/dev_server.port' '--static_dir=/mnt/host/source/devserver/static' '--src_image=/mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1213-a1/chromiumos_test_image.bin' in /mnt/host/source
10:42:53: DEBUG: Retrieving http://127.0.0.1:34573/check_health
10:42:53: DEBUG: Retrieving http://172.22.112.223:34573/xbuddy/local_imagedCXx9y/link/test?for_update=true&return_dir=true
10:57:53: ERROR: Cannot connect to devserver (timed out)
10:57:53: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- test -f /tmp/devserver_wrapperfBZkoZ/dev_server.log
10:57:53: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- tail -n 50 /tmp/devserver_wrapperfBZkoZ/dev_server.log
10:57:54: WARNING: --- Start output from /tmp/devserver_wrapperfBZkoZ/dev_server.log ---[25/Oct/2017:10:42:49] DEVSERVER Using cache directory /mnt/host/source/devserver/static/cache
[25/Oct/2017:10:42:49] DEVSERVER Serving from /mnt/host/source/devserver/static
[25/Oct/2017:10:42:49] XBUDDY Using shadow config file stored at /mnt/host/source/src/platform/dev/shadow_xbuddy_config.ini
[25/Oct/2017:10:42:49] UTIL Error happened while reading lsb-release file: cat: /etc/lsb-release: No such file or directory
[25/Oct/2017:10:42:49] ENGINE Listening for SIGHUP.
[25/Oct/2017:10:42:49] ENGINE Listening for SIGTERM.
[25/Oct/2017:10:42:49] ENGINE Listening for SIGUSR1.
[25/Oct/2017:10:42:49] ENGINE Bus STARTING
[25/Oct/2017:10:42:49] ENGINE PID 47556 written to '/tmp/devserver_wrapperfBZkoZ/devserver_wrapperg_tia7'.
[25/Oct/2017:10:42:49] ENGINE Started monitor thread '_TimeoutMonitor'.
[25/Oct/2017:10:42:49] ENGINE (wait_for_free_port) No cached port to wait for.
[25/Oct/2017:10:42:49] ENGINE Port 34573 written to '/tmp/devserver_wrapperfBZkoZ/dev_server.port'.
[25/Oct/2017:10:42:49] ENGINE (wait_for_occupied_port) Waiting for actual port 34573.
[25/Oct/2017:10:42:49] ENGINE Serving on :::0
[25/Oct/2017:10:42:49] ENGINE Bus STARTED
::ffff:127.0.0.1 - - [25/Oct/2017:10:42:53] "GET /check_health HTTP/1.1" 200 370 "" "Python-urllib/2.7"
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/lumpy/R63-10005.0.2017_10_09_1035-a1 from /mnt/host/source/src/build/images/lumpy/R63-10005.0.2017_10_09_1035-a1
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/lumpy/R63-10005.0.2017_10_09_1122-a1 from /mnt/host/source/src/build/images/lumpy/R63-10005.0.2017_10_09_1122-a1
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/veyron_minnie/R64-10054.0.2017_10_23_1034-a1 from /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1034-a1
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/veyron_minnie/R64-10054.0.2017_10_23_1213-a1 from /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1213-a1
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/veyron_minnie/R64-10054.0.2017_10_20_1547-a1 from /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_20_1547-a1
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/amd64-generic/R63-9914.0.2017_09_07_1219-a1 from /mnt/host/source/src/build/images/amd64-generic/R63-9914.0.2017_09_07_1219-a1
[25/Oct/2017:10:42:53] XBUDDY Linking to /mnt/host/source/devserver/static/amd64-generic/R63-9977.0.2017_09_29_1244-a1 from /mnt/host/source/src/build/images/amd64-generic/R63-9977.0.2017_09_29_1244-a1
[25/Oct/2017:10:42:53] XBUDDY Path is local_imagedCXx9y/link/test, location suffix is -release
[25/Oct/2017:10:42:53] XBUDDY Get artifact 'test' with board local_imagedCXx9y and version link'. Locally? True
[25/Oct/2017:10:42:53] XBUDDY Returning path to payload: local_imagedCXx9y/link/chromiumos_test_image.bin
[25/Oct/2017:10:42:53] XBUDDY Downloading ['full_payload', 'stateful'] from gs://chromeos-image-archive/local_imagedCXx9y/link
[25/Oct/2017:10:42:53] UTIL Error happened while reading lsb-release file: cat: /etc/lsb-release: No such file or directory
[25/Oct/2017:10:42:53] GOOGLE_STORAGE_DOWNLOADER Downloading artifacts *_full_*->/mnt/host/source/devserver/static/local_imagedCXx9y/link stateful.tgz->/mnt/host/source/devserver/static/local_imagedCXx9y/link.
[25/Oct/2017:10:42:53] A_U_TEST_PAYLOAD No marker file, *_full_*->/mnt/host/source/devserver/static/local_imagedCXx9y/link is not staged.
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/lumpy/R63-10005.0.2017_10_09_1035-a1 from /mnt/host/source/src/build/images/lumpy/R63-10005.0.2017_10_09_1035-a1
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/lumpy/R63-10005.0.2017_10_09_1122-a1 from /mnt/host/source/src/build/images/lumpy/R63-10005.0.2017_10_09_1122-a1
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/veyron_minnie/R64-10054.0.2017_10_23_1034-a1 from /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1034-a1
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/veyron_minnie/R64-10054.0.2017_10_23_1213-a1 from /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1213-a1
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/veyron_minnie/R64-10054.0.2017_10_20_1547-a1 from /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_20_1547-a1
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/amd64-generic/R63-9914.0.2017_09_07_1219-a1 from /mnt/host/source/src/build/images/amd64-generic/R63-9914.0.2017_09_07_1219-a1
[25/Oct/2017:10:42:54] XBUDDY Linking to /mnt/host/source/devserver/static/amd64-generic/R63-9977.0.2017_09_29_1244-a1 from /mnt/host/source/src/build/images/amd64-generic/R63-9977.0.2017_09_29_1244-a1
[25/Oct/2017:10:42:54] XBUDDY Path is local_imagedCXx9y/link/test, location suffix is -release
[25/Oct/2017:10:42:54] XBUDDY Get artifact 'test' with board local_imagedCXx9y and version link'. Locally? True
[25/Oct/2017:10:42:54] XBUDDY Updating timestamp for local_imagedCXx9y/link
[25/Oct/2017:10:42:54] XBUDDY Returning path to payload: local_imagedCXx9y/link/chromiumos_test_image.bin
[25/Oct/2017:10:42:54] DEVSERVER Payload generation triggered by request
[25/Oct/2017:10:42:54] UPDATE Update label/file: local_imagedCXx9y/link/chromiumos_test_image.bin
[25/Oct/2017:10:42:54] UPDATE Generating update for src /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1213-a1/chromiumos_test_image.bin image /mnt/host/source/devserver/static/local_imagedCXx9y/link/chromiumos_test_image.bin
[25/Oct/2017:10:43:19] UPDATE Caching in sub_dir "cache/ac7ef20f513d0d89148eca912434d0dd_0f7808e218e7eaa4073ea3c5b8900364"
[25/Oct/2017:10:43:19] UPDATE Generating update for image /mnt/host/source/devserver/static/local_imagedCXx9y/link/chromiumos_test_image.bin
[25/Oct/2017:10:43:19] UPDATE Generating update image /mnt/host/source/devserver/static/cache/ac7ef20f513d0d89148eca912434d0dd_0f7808e218e7eaa4073ea3c5b8900364/update.gz
[25/Oct/2017:10:43:19] UPDATE Running cros_generate_update_payload --image /mnt/host/source/devserver/static/local_imagedCXx9y/link/chromiumos_test_image.bin --out_metadata_hash_file /mnt/host/source/devserver/static/cache/ac7ef20f513d0d89148eca912434d0dd_0f7808e218e7eaa4073ea3c5b8900364/metadata_hash --output /mnt/host/source/devserver/static/cache/ac7ef20f513d0d89148eca912434d0dd_0f7808e218e7eaa4073ea3c5b8900364/update.gz --src_image /mnt/host/source/src/build/images/veyron_minnie/R64-10054.0.2017_10_23_1213-a1/chromiumos_test_image.bin
--- End output from /tmp/devserver_wrapperfBZkoZ/dev_server.log ---
10:57:54: DEBUG: Stopping devserver instance with pid 47556
10:57:54: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- kill 47556
10:58:04: WARNING: Devserver is unstoppable. Killing with SIGKILL
10:58:04: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- kill -9 47556
10:58:04: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- rm -rf -- /mnt/host/source/devserver/static/local_imagedCXx9y
10:58:04: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- rm -rf -- /tmp/dev_server_wrapper_local_imageBOGAYj
10:58:04: ERROR: Unable to get payloads from local path: /tmp/cros-flashnxtjnN
10:58:04: ERROR: Device update failed.
10:58:04: DEBUG: RunCommand: ssh -p 22 '-oConnectionAttempts=4' '-oUserKnownHostsFile=/dev/null' '-oProtocol=2' '-oConnectTimeout=30' '-oServerAliveCountMax=3' '-oStrictHostKeyChecking=no' '-oServerAliveInterval=10' '-oNumberOfPasswordPrompts=0' '-oIdentitiesOnly=yes' -i /tmp/ssh-tmpTSKi5T/testing_rsa root@100.127.1.198 -- cat /etc/lsb-release
10:58:05: INFO: Following are the LSB version details of the device:
CHROMEOS_ARC_ANDROID_SDK_VERSION=25
CHROMEOS_ARC_VERSION=4407969
CHROMEOS_AUSERVER=http://ahassani.mtv.corp.google.com:8080/update
CHROMEOS_BOARD_APPID={432FF9F1-4D2E-7E74-6F98-32E56E904BFB}
CHROMEOS_CANARY_APPID={90F229CE-83E2-4FAF-8479-E368A34938B1}
CHROMEOS_DEVSERVER=http://ahassani.mtv.corp.google.com:8080
CHROMEOS_RELEASE_APPID={432FF9F1-4D2E-7E74-6F98-32E56E904BFB}
CHROMEOS_RELEASE_BOARD=veyron_minnie
CHROMEOS_RELEASE_BRANCH_NUMBER=0
CHROMEOS_RELEASE_BUILD_NUMBER=10054
CHROMEOS_RELEASE_BUILD_TYPE=Test Build - ahassani
CHROMEOS_RELEASE_CHROME_MILESTONE=64
CHROMEOS_RELEASE_DESCRIPTION=10054.0.2017_10_23_1213 (Test Build - ahassani) developer-build veyron_minnie
CHROMEOS_RELEASE_NAME=Chromium OS
CHROMEOS_RELEASE_PATCH_NUMBER=2017_10_23_1213
CHROMEOS_RELEASE_TRACK=testimage-channel
CHROMEOS_RELEASE_VERSION=10054.0.2017_10_23_1213
DEVICETYPE=CHROMEBOOK
GOOGLE_RELEASE=10054.0.2017_10_23_1213
10:58:05: INFO: You can find the log files and/or payloads in /tmp/cros-flashnxtjnN
10:58:05: ERROR: cros flash failed before completing.
cros: Unhandled exception:
Traceback (most recent call last):
  File "/mnt/host/source/chromite/bin/cros", line 169, in <module>
    DoMain()
  File "/mnt/host/source/chromite/bin/cros", line 165, in DoMain
    commandline.ScriptWrapperMain(FindTarget)
  File "/mnt/host/source/chromite/lib/commandline.py", line 911, in ScriptWrapperMain
    ret = target(argv[1:])
  File "/mnt/host/source/chromite/scripts/cros.py", line 66, in main
    code = _RunSubCommand(subcommand)
  File "/mnt/host/source/chromite/scripts/cros.py", line 51, in _RunSubCommand
    return subcommand.Run()
  File "/mnt/host/source/chromite/cli/cros/cros_flash.py", line 151, in Run
    debug=self.options.debug)
  File "/mnt/host/source/chromite/cli/flash.py", line 564, in Flash
    updater.Run()
  File "/mnt/host/source/chromite/cli/flash.py", line 454, in Run
    payload_dir = self.GetPayloadDir(device)
  File "/mnt/host/source/chromite/cli/flash.py", line 402, in GetPayloadDir
    static_dir=DEVSERVER_STATIC_DIR)
  File "/mnt/host/source/chromite/lib/dev_server_wrapper.py", line 239, in GetUpdatePayloadsFromLocalPath
    static_dir=static_dir)
  File "/mnt/host/source/chromite/lib/dev_server_wrapper.py", line 239, in GetUpdatePayloadsFromLocalPath
    static_dir=static_dir)
  File "/mnt/host/source/chromite/lib/dev_server_wrapper.py", line 302, in GetUpdatePayloads
    url = ds.OpenURL(ds.GetURL(sub_dir=req), timeout=timeout)
  File "/mnt/host/source/chromite/lib/dev_server_wrapper.py", line 448, in OpenURL
    raise DevServerConnectionError(e)
chromite.lib.dev_server_wrapper.DevServerConnectionError: timed out
10:58:05: DEBUG: RunCommand: sudo 'CROS_CACHEDIR=/mnt/host/source/.cache' -- rm -rf -- /tmp/devserver_wrapperfBZkoZ
 
Cc: xixuan@chromium.org
Off the top of my head I can't think of anything that i changed that would crash it where it did.

Is --debug the same as --log-level debug?


  --debug               Alias for `--log-level=debug`. Useful for debugging
                        bugs/failures.
Status: WontFix (was: Untriaged)
wola..., I did a repo sync and it works now. It probably was a bug on tot at that time. I'm going to mark this as won't fix.
Woooo

Sign in to add a comment