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

Issue 642986 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Last visit > 30 days ago
Closed: Nov 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux
Pri: 2
Type: Bug



Sign in to add a comment

gs errors in BuildPackages stage.

Project Member Reported by nxia@chromium.org, Sep 1 2016

Issue description

BuildPackages failed at downloading files from gs.



https://uberchromegw.corp.google.com/i/chromeos/builders/veyron_speedy-paladin/builds/2997/steps/BuildPackages/logs/stdio

https://uberchromegw.corp.google.com/i/chromeos/builders/daisy_spring-paladin/builds/12984/steps/CommitQueueSync/logs/stdio

https://uberchromegw.corp.google.com/i/chromeos/builders/glados-paladin/builds/2983/steps/CommitQueueSync/logs/stdio

https://uberchromegw.corp.google.com/i/chromeos/builders/glados-paladin/builds/2991/steps/CommitQueueSync/logs/stdio


GSCommandError: return code: 1; command: /mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gsutil -o 'Boto:num_retries=10' cp -v -- gs://chromeos-prebuilt/board/veyron_speedy/paladin-R54-8731.0.0-rc1/packages/dev-libs/libgcrypt-1.6.3-r3.debug.tbz2 /build/veyron_speedy/packages/dev-libs/libgcrypt-1.6.3-r3.debug.tbz2
Copying gs://chromeos-prebuilt/board/veyron_speedy/paladin-R54-8731.0.0-rc1/packages/dev-libs/libgcrypt-1.6.3-r3.debug.tbz2...
Downloading .../packages/dev-libs/libgcrypt-1.6.3-r3.debug.tbz2: 0 B/691.72 KiB    
Traceback (most recent call last):
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gsutil", line 22, in <module>
    gsutil.RunMain()
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gsutil.py", line 106, in RunMain
    sys.exit(gslib.__main__.main())
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/__main__.py", line 377, in main
    perf_trace_token=perf_trace_token)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/__main__.py", line 565, in _RunNamedCommandAndHandleExceptions
    parallel_operations, perf_trace_token=perf_trace_token)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/command_runner.py", line 280, in RunNamedCommand
    return_code = command_inst.RunCommand()
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/commands/cp.py", line 968, in RunCommand
    fail_on_error=(not self.continue_on_error))
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/command.py", line 1172, in Apply
    arg_checker, should_return_results, fail_on_error)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/command.py", line 1243, in _SequentialApply
    worker_thread.PerformTask(task, self)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/command.py", line 1705, in PerformTask
    results = task.func(cls, task.args, thread_state=self.thread_gsutil_api)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/commands/cp.py", line 707, in _CopyFuncWrapper
    cls.CopyFunc(args, thread_state=thread_state)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/commands/cp.py", line 859, in CopyFunc
    gzip_exts=self.gzip_exts))
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/copy_helper.py", line 2904, in PerformCopy
    decryption_key=decryption_key)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/copy_helper.py", line 2386, in _DownloadObjectToFile
    gsutil_api, logger, digesters, decryption_key=decryption_key))
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/copy_helper.py", line 2244, in _DownloadObjectToFileResumable
    decryption_tuple=CryptoTupleFromKey(decryption_key))
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/cloud_api_delegator.py", line 252, in GetObjectMedia
    decryption_tuple=decryption_tuple)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/boto_translation.py", line 481, in GetObjectMedia
    num_callbacks=num_progress_callbacks, hash_algs=hash_algs)
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/gslib/boto_translation.py", line 636, in _PerformResumableDownload
    key.close()
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/third_party/boto/boto/s3/key.py", line 370, in close
    self.resp.read()
  File "/mnt/host/source/.cache/common/gsutil_4.19.tar.gz/gsutil/third_party/boto/boto/connection.py", line 410, in read
    self._cached_response = http_client.HTTPResponse.read(self)
  File "/usr/lib64/python2.7/httplib.py", line 596, in read
    s = self._safe_read(self.length)
  File "/usr/lib64/python2.7/httplib.py", line 703, in _safe_read
    chunk = self.fp.read(min(amt, MAXAMOUNT))
  File "/usr/lib64/python2.7/socket.py", line 384, in read
    data = self._sock.recv(left)
  File "/usr/lib64/python2.7/ssl.py", line 734, in recv
    return self.read(buflen)
  File "/usr/lib64/python2.7/ssl.py", line 621, in read
    v = self._sslobj.read(len or 1024)
ssl.SSLError: ('The read operation timed out',)

cwd=None, extra env={'BOTO_CONFIG': u'/mnt/host/source/src/private-overlays/chromeos-overlay/googlestorage_account.boto'}

ERROR   : Wed Aug 31 13:38:11 PDT 2016
ERROR   :  PGID  PPID   PID     ELAPSED     TIME %CPU COMMAND
ERROR   : Arguments of 10: ./build_packages '--board=veyron_speedy' '--accept_licenses=@CHROMEOS' '--withdebugsymbols' '--skip_chroot_upgrade' '--noworkon' 'virtual/target-os' 'virtual/target-os-dev' 'virtual/target-os-test' 'virtual/target-os-factory' 'virtual/target-os-factory-shim' 'chromeos-base/autotest-all'
ERROR   : Backtrace:  (most recent call is last)
ERROR   :  build_packages:276:main(), called: die_err_trap  
ERROR   : 
ERROR   : Command failed:
ERROR   :   Command 'sudo -E "${GCLIENT_ROOT}/chromite/bin/cros_install_debug_syms" "--board=${FLAGS_board}" "--all"' exited with nonzero code: 1
13:38:11: ERROR: 
return code: 1; command: /b/cbuild/internal_master/chromite/bin/cros_sdk 'PARALLEL_EMERGE_STATUS_FILE=/tmp/tmpeaumfE' 'USE=chrome_internal' 'FEATURES=separatedebug' -- ./build_packages '--board=veyron_speedy' '--accept_licenses=@CHROMEOS' --withdebugsymbols --skip_chroot_upgrade --noworkon virtual/target-os virtual/target-os-dev virtual/target-os-test virtual/target-os-factory virtual/target-os-factory-shim chromeos-base/autotest-all
cwd=/b/cbuild/internal_master, extra env={'PARALLEL_EMERGE_STATUS_FILE': '/tmp/tmpeaumfE', 'USE': 'chrome_internal', 'FEATURES': 'separatedebug'}



 

Comment 1 by nxia@chromium.org, Sep 1 2016

Components: Infra>Client>ChromeOS
Labels: -OS-Android OS-Linux
a network related bug has been tracked at https://buganizer.corp.google.com/issues/31011610

Project Member

Comment 2 by bugdroid1@chromium.org, Sep 1 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/chromite/+/2241deca14274e9a7c53c86f4fb33b31e5b205c3

commit 2241deca14274e9a7c53c86f4fb33b31e5b205c3
Author: Ningning Xia <nxia@chromium.org>
Date: Wed Aug 31 23:26:46 2016

Log gs errors in gs _RetryFilter

Temporary log for debuging chromium:642986. Will be reverted after the issue is
identified.

BUG= chromium:642986 
TEST=run_tests

Change-Id: Ia5716057cf30415203f6153a9d1d78966de1a5e0
Reviewed-on: https://chromium-review.googlesource.com/379616
Reviewed-by: Mike Frysinger <vapier@chromium.org>
Commit-Queue: Ningning Xia <nxia@chromium.org>
Tested-by: Ningning Xia <nxia@chromium.org>
Trybot-Ready: Ningning Xia <nxia@chromium.org>

[modify] https://crrev.com/2241deca14274e9a7c53c86f4fb33b31e5b205c3/lib/gs.py

Comment 3 by aut...@google.com, Sep 7 2016

Owner: nxia@chromium.org
Labels: -Pri-2 Pri-1
Again in https://uberchromegw.corp.google.com/i/chromeos/builders/leon-paladin/builds/11747/steps/BuildPackages/logs/stdio

Do we need to ping upstream bug for progress?
happened again in https://uberchromegw.corp.google.com/i/chromeos/builders/guado_moblab-paladin/builds/3908/steps/BuildPackages/logs/stdio

(that builder is temporarily experimental, but about to not be)


Happening also in buddy-release, but in the Paygen step.

https://uberchromegw.corp.google.com/i/chromeos/builders/buddy-release/builds/448/steps/Paygen/logs/stdio

22:35:36: WARNING: GS_ERROR: CommandException: No URLs matched: gs://chromeos-releases/tobesigned/45,canary-channel,buddy,8858.0.0,payloads,signing,29191-140587527677760,update_signer.payload.signer.instructions
 (Temp log for  crbug.com/642986 )

There are many of them.
Cc: denniskempin@chromium.org
Labels: Sheriff-40

Comment 9 by nxia@chromium.org, Oct 3 2016

The GS logs are warnings and are expected sometimes. For example, 'cat/list' the file first, if not exist, 'upload' the file to GS. The errors in comment #6 looks like lab/test errors. 

Comment 10 by nxia@chromium.org, Oct 3 2016

b/31011610 tracks the origin network issue which causes the gs failures in the BuildPackage stage. Please update the b/31011610 when this failure happens again, so they can respond and investigate network issues while it's happening. 


This bug was opened to turn on some logs and check why gs retry wasn't working as expected. 
Labels: -Sheriff-40 Hotlist-CrOS-Sheriffing

Comment 13 by nxia@chromium.org, Oct 3 2016

Followed the logs in comment#4, didn't find the warning logs(pasted below), this should be the reason why retry wasn't enabled.

https://cs.corp.google.com/chromeos_public/chromite/lib/gs.py?q=gs.py&sq=package:%5Echromeos_(internal%7Cpublic)$&dr&l=597

otherwise, retry should be enabled on ssl.SSLError as:
https://cs.corp.google.com/chromeos_public/chromite/lib/gs.py?q=gs.py&sq=package:%5Echromeos_(internal%7Cpublic)$&dr&l=626


Comment 15 by nxia@chromium.org, Oct 3 2016

I don't think the errors in signing stages are related to the this bug. The files hadn't been uploaded to the gs bucket when the signing stages tried to access them. 
Project Member

Comment 16 by bugdroid1@chromium.org, Oct 12 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/chromite/+/03998c2458a6abae87366d7c631c379b97c6f976

commit 03998c2458a6abae87366d7c631c379b97c6f976
Author: Ningning Xia <nxia@chromium.org>
Date: Tue Oct 11 20:12:05 2016

Add logs in gs.Copy()

We saw gs related errors in BuildStages and most of them were related to
gs.Copy(). Revert the log change in the _RetryFilter and add warning
in gs.Copy(), to reduce spam logs in _RetryFilter and turn on logs in
gs.Copy() for investigation.

BUG= chromium:642986 
TEST=run_tests

Change-Id: I66b09629075abfa6d4a338b840aee79a6932c9be
Reviewed-on: https://chromium-review.googlesource.com/396883
Commit-Ready: Ningning Xia <nxia@chromium.org>
Tested-by: Ningning Xia <nxia@chromium.org>
Reviewed-by: Don Garrett <dgarrett@chromium.org>

[modify] https://crrev.com/03998c2458a6abae87366d7c631c379b97c6f976/lib/gs.py

Comment 17 by nxia@chromium.org, Oct 12 2016

Labels: -Pri-1 Pri-2

Comment 18 by nxia@chromium.org, Oct 17 2016

Happened again here, suspected it didn't retry because of the different format of the error message. 

https://uberchromegw.corp.google.com/i/chromeos/builders/storm-paladin/builds/9076/steps/BuildPackages/logs/stdio

Project Member

Comment 19 by bugdroid1@chromium.org, Oct 20 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/chromite/+/14b255f36c4ca13f551ccca09ba3942df02e37cc

commit 14b255f36c4ca13f551ccca09ba3942df02e37cc
Author: Ningning Xia <nxia@chromium.org>
Date: Mon Oct 17 23:25:27 2016

gs should retry on SSL read-operation-timed-out error.

Set "ssl.SSLError: ('The read operation timed out',)" as one
resumable error message.

BUG= chromium:642986 
TEST=unit_test

Change-Id: I1b683d72ebe534ca60ae694aede15d91ad85c327
Reviewed-on: https://chromium-review.googlesource.com/399960
Commit-Ready: Dan Shi <dshi@google.com>
Tested-by: Ningning Xia <nxia@chromium.org>
Tested-by: Dan Shi <dshi@google.com>
Reviewed-by: Mike Frysinger <vapier@chromium.org>

[modify] https://crrev.com/14b255f36c4ca13f551ccca09ba3942df02e37cc/lib/gs_unittest.py
[modify] https://crrev.com/14b255f36c4ca13f551ccca09ba3942df02e37cc/lib/gs.py

Comment 20 by nxia@chromium.org, Nov 17 2016

Status: Fixed (was: Untriaged)

Sign in to add a comment