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

Issue 903938 link

Starred by 1 user

Issue metadata

Status: Assigned
Owner:
OOO
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

devserver: dev_server call hangs for ~2 hours

Project Member Reported by pprabhu@chromium.org, Nov 9

Issue description

Any single gscache call (or retries for the same call) shouldn't hang around for 2 hours.

I believe this issue was exacerbating issue 897885

For example
https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/buildDetails?buildbucketId=8930424150363543360

had a suite timeout. Focussing on one of the provision tasks that timed out:

http://cros-full-0005.mtv.corp.google.com/afe/#tab_id=view_job&object_id=256094448

And looking at dut-history, I find that the provision logs are at:
https://stainless.corp.google.com/browse/chromeos-autotest-results/hosts/chromeos6-row1-rack23-host1/2365082-provision/

and following repair logs are at:
https://stainless.corp.google.com/browse/chromeos-autotest-results/hosts/chromeos6-row1-rack23-host1/2365656-repair/
(finds nothing wrong with the DUT, as expected)
 
Labels: -Pri-2 Pri-1
Owner: gu...@chromium.org
Status: Assigned (was: Untriaged)
In the provision autoserv.DEBUG, we see:

11/08 06:38:00.079 INFO |        dev_server:1255| Staging artifacts on devserver http://100.115.219.135:8082: build=caroline-arcnext-paladin/R72-11241.0.0-rc2, artifacts=['autotest_packages'], files=, archive_url=gs://chromeos-image-archive/caroline-arcnext-paladin/R72-11241.0.0-rc2
11/08 06:38:00.081 DEBUG|             utils:0219| Running 'ssh 100.115.219.135 'curl "http://100.115.219.135:8082/stage?artifacts=autotest_packages&files=&async=True&archive_url=gs://chromeos-image-archive/caroline-arcnext-paladin/R72-11241.0.0-rc2"''
11/08 06:39:00.405 WARNI|             utils:0938| run process timeout (60) fired on: ssh 100.115.219.135 'curl "http://100.115.219.135:8082/stage?artifacts=autotest_packages&files=&async=True&archive_url=gs://chromeos-image-archive/caroline-arcnext-paladin/R72-11241.0.0-rc2"'
11/08 06:39:01.410 DEBUG|        dev_server:1038| Error occurred with exit_code 0 when executing the ssh call: Warning: Permanently added '100.115.219.135' (ECDSA) to the list of known hosts.
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:02 --:--:--     0


...

[retry for 2 hours]

11/08 08:10:56.554 WARNI|             retry:0228| <class 'autotest_lib.client.common_lib.error.CmdTimeoutError'>(Command <ssh 100.115.219.135 'curl "http://100.115.219.135:8082/stage?artifacts=autotest_packages&files=&async=True&archive_url=gs://chromeos-image-archive/caroline-arcnext-paladin/R72-11241.0.0-rc2"'> failed, rc=0, Command(s) did not complete within 60 seconds
* Command: 
    ssh 100.115.219.135 'curl "http://100.115.219.135:8082/stage?artifacts=au
    totest_packages&files=&async=True&archive_url=gs://chromeos-image-archive
    /caroline-arcnext-paladin/R72-11241.0.0-rc2"'
Exit status: 0
Duration: 61.2461781502

stderr:
Warning: Permanently added '100.115.219.135' (ECDSA) to the list of known hosts.
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:02 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:03 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:04 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:05 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:06 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:07 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:08 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:09 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:10 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:11 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:12 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:13 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:14 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:15 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:16 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:17 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:18 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:19 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:20 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:21 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:22 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:23 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:24 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:25 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:26 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:27 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:28 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:29 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:30 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:31 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:32 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:33 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:34 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:35 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:36 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:37 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:38 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:39 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:40 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:41 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:42 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:43 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:44 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:45 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:46 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:47 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:48 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:49 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:50 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:51 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:52 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:53 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:54 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:55 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:56 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:57 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:58 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:59 --:--:--     0)
11/08 08:10:56.556 WARNI|             retry:0183| Retrying in 3.681991 seconds...
11/08 08:11:00.253 DEBUG|             utils:0219| Running 'ssh 100.115.219.135 'curl "http://100.115.219.135:8082/stage?artifacts=autotest_packages&files=&async=True&archive_url=gs://chromeos-image-archive/caroline-arcnext-paladin/R72-11241.0.0-rc2"''


---------------
This is wrong.
Summary: devserver: dev_server call hangs for ~2 hours (was: gscache: dev_server call hangs for ~2 hours)
Clearly, it's not related to gscache. Instead, it's the old devserver code. I can continue to look why it always retried.

Sign in to add a comment