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

Issue 642611 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Last visit > 30 days ago
Closed: Sep 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

Paygen suite job timed out despite all PASSED

Project Member Reported by kitching@chromium.org, Aug 31 2016

Issue description

auron_paine-release Paygen "Suite job" times out despite all PASSED:


https://uberchromegw.corp.google.com/i/chromeos/builders/auron_paine-release/builds/347

https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/75155876-chromeos-test/hostless/debug

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







08/30 17:32:20.809 INFO |        server_job:0129| START	75156319-chromeos-test/chromeos4-row8-rack3-host1/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472591650	localtime=Aug 30 14:14:10	
08/30 17:32:20.810 INFO |        server_job:0129| 	GOOD	75156319-chromeos-test/chromeos4-row8-rack3-host1/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592297	localtime=Aug 30 14:24:57	completed successfully
08/30 17:32:20.810 INFO |        server_job:0129| END GOOD	75156319-chromeos-test/chromeos4-row8-rack3-host1/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592297	localtime=Aug 30 14:24:57	
08/30 17:32:20.811 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_delta=75156319-chromeos-test
08/30 17:32:22.114 INFO |        server_job:0129| START	75156320-chromeos-test/chromeos4-row8-rack3-host3/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592024	localtime=Aug 30 14:20:24	
08/30 17:32:22.115 INFO |        server_job:0129| 	GOOD	75156320-chromeos-test/chromeos4-row8-rack3-host3/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592607	localtime=Aug 30 14:30:07	completed successfully
08/30 17:32:22.116 INFO |        server_job:0129| END GOOD	75156320-chromeos-test/chromeos4-row8-rack3-host3/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592607	localtime=Aug 30 14:30:07	
08/30 17:32:22.116 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_full=75156320-chromeos-test
08/30 17:32:23.969 INFO |        server_job:0129| START	75156321-chromeos-test/chromeos4-row8-rack4-host4/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592087	localtime=Aug 30 14:21:27	
08/30 17:32:23.970 INFO |        server_job:0129| 	GOOD	75156321-chromeos-test/chromeos4-row8-rack4-host4/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592784	localtime=Aug 30 14:33:04	completed successfully
08/30 17:32:23.971 INFO |        server_job:0129| END GOOD	75156321-chromeos-test/chromeos4-row8-rack4-host4/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592784	localtime=Aug 30 14:33:04	
08/30 17:32:23.971 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_full=75156321-chromeos-test
08/30 17:32:25.578 INFO |        server_job:0129| START	75156322-chromeos-test/chromeos4-row8-rack4-host3/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592087	localtime=Aug 30 14:21:27	
08/30 17:32:25.579 INFO |        server_job:0129| 	GOOD	75156322-chromeos-test/chromeos4-row8-rack4-host3/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592695	localtime=Aug 30 14:31:35	completed successfully
08/30 17:32:25.580 INFO |        server_job:0129| END GOOD	75156322-chromeos-test/chromeos4-row8-rack4-host3/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592695	localtime=Aug 30 14:31:35	
08/30 17:32:25.580 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_delta=75156322-chromeos-test
08/30 17:32:26.948 INFO |        server_job:0129| START	75156325-chromeos-test/chromeos4-row8-rack5-host11/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592273	localtime=Aug 30 14:24:33	
08/30 17:32:26.949 INFO |        server_job:0129| 	GOOD	75156325-chromeos-test/chromeos4-row8-rack5-host11/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592865	localtime=Aug 30 14:34:25	completed successfully
08/30 17:32:26.949 INFO |        server_job:0129| END GOOD	75156325-chromeos-test/chromeos4-row8-rack5-host11/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592865	localtime=Aug 30 14:34:25	
08/30 17:32:26.950 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_full=75156325-chromeos-test
08/30 17:32:31.973 DEBUG|     dynamic_suite:0556| Finished waiting on suite. Returning from _perform_reimage_and_run.
08/30 17:32:31.974 DEBUG|     dynamic_suite:0495| Returning from dynamic_suite.reimage_and_run.
08/30 17:32:31.974 INFO |        server_job:0693| Finished processing control file
08/30 17:32:31.976 WARNI|        subcommand:0081| parallel_simple was called with an empty arglist, did you forget to pass in a list of machines?
08/30 17:32:32.174 DEBUG|   logging_manager:0627| Logging subprocess finished
08/30 17:32:32.174 DEBUG|   logging_manager:0627| Logging subprocess finished







08-30-2016 [14:05:08] Created suite job: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155876
@@@STEP_LINK@Link to suite@http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155876@@@
The suite job has another 2:29:45.057794 till timeout.
The suite job has another 1:59:43.514055 till timeout.

08-30-2016 [15:35:09] printing summary of incomplete jobs (5):

autoupdate_EndToEndTest_paygen_au_dev_delta_8756.0.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75156319
autoupdate_EndToEndTest_paygen_au_dev_full_8737.1.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75156320
autoupdate_EndToEndTest_paygen_au_dev_full_8756.0.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75156321
autoupdate_EndToEndTest_paygen_au_dev_delta_8737.1.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75156322
autoupdate_EndToEndTest_paygen_au_dev_full_6457.83.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75156325
The suite job has another 1:29:35.813406 till timeout.
The suite job has another 0:59:26.580951 till timeout.
The suite job has another 0:29:20.613278 till timeout.
The suite job has another -1 day, 23:59:13.333519 till timeout.
The suite job has another -1 day, 23:29:04.685618 till timeout.
Suite timed out. Started on 08-30-2016 [14:05:08], timed out on 08-30-2016 [17:41:00]
Suite job                                     [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_delta   [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_delta   [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]

Suite timings:
Downloads started at 2016-08-30 14:05:03
Payload downloads ended at 2016-08-30 14:05:06
Suite started at 2016-08-30 14:08:54
Artifact downloads ended (at latest) at 2016-08-30 14:09:07
Testing started at 2016-08-30 14:14:10
Testing ended at 2016-08-30 14:34:25



Looks *kind of like* this issue:
https://bugs.chromium.org/p/chromium/issues/detail?id=600500
 
Same issue on auron_yuna-release:

https://uberchromegw.corp.google.com/i/chromeos/builders/auron_yuna-release/builds/348

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

http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75154968

https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/75154968-chromeos-test/hostless/debug





08/30 14:03:39.251 DEBUG|             suite:1156| Parsing control files ...
08/30 14:03:42.054 DEBUG|             suite:1221| Parsed 1668 control files.
08/30 14:03:42.061 DEBUG|             suite:0907| Discovered 5 stable tests.
08/30 14:03:42.061 DEBUG|             suite:0909| Discovered 0 unstable tests.
08/30 14:03:42.062 INFO |        server_job:0129| INFO	----	Start paygen_au_dev	timestamp=1472591022	localtime=Aug 30 14:03:42	
08/30 14:03:42.062 DEBUG|             suite:0825| Scheduling autoupdate_EndToEndTest_paygen_au_dev_delta_8756.0.0
08/30 14:03:42.879 DEBUG|             suite:1079| Adding job keyval for autoupdate_EndToEndTest_paygen_au_dev_delta_8756.0.0=75155329-chromeos-test
08/30 14:03:42.880 DEBUG|             suite:0825| Scheduling autoupdate_EndToEndTest_paygen_au_dev_full_8737.1.0
08/30 14:03:43.546 DEBUG|             suite:1079| Adding job keyval for autoupdate_EndToEndTest_paygen_au_dev_full_8737.1.0=75155333-chromeos-test
08/30 14:03:43.547 DEBUG|             suite:0825| Scheduling autoupdate_EndToEndTest_paygen_au_dev_full_8756.0.0
08/30 14:03:44.194 DEBUG|             suite:1079| Adding job keyval for autoupdate_EndToEndTest_paygen_au_dev_full_8756.0.0=75155337-chromeos-test
08/30 14:03:44.195 DEBUG|             suite:0825| Scheduling autoupdate_EndToEndTest_paygen_au_dev_delta_8737.1.0
08/30 14:03:44.944 DEBUG|             suite:1079| Adding job keyval for autoupdate_EndToEndTest_paygen_au_dev_delta_8737.1.0=75155341-chromeos-test
08/30 14:03:44.944 DEBUG|             suite:0825| Scheduling autoupdate_EndToEndTest_paygen_au_dev_full_6457.83.0
08/30 14:03:45.793 DEBUG|             suite:1079| Adding job keyval for autoupdate_EndToEndTest_paygen_au_dev_full_6457.83.0=75155345-chromeos-test
08/30 14:03:45.794 DEBUG|     dynamic_suite:0554| Waiting on suite.
08/30 17:32:25.095 INFO |        server_job:0129| START	75155329-chromeos-test/chromeos4-row10-rack5-host7/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472591851	localtime=Aug 30 14:17:31	
08/30 17:32:25.096 INFO |        server_job:0129| 	GOOD	75155329-chromeos-test/chromeos4-row10-rack5-host7/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592434	localtime=Aug 30 14:27:14	completed successfully
08/30 17:32:25.096 INFO |        server_job:0129| END GOOD	75155329-chromeos-test/chromeos4-row10-rack5-host7/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592434	localtime=Aug 30 14:27:14	
08/30 17:32:25.097 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_delta=75155329-chromeos-test
08/30 17:32:26.540 INFO |        server_job:0129| START	75155333-chromeos-test/chromeos4-row10-rack5-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472591932	localtime=Aug 30 14:18:52	
08/30 17:32:26.541 INFO |        server_job:0129| 	GOOD	75155333-chromeos-test/chromeos4-row10-rack5-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592644	localtime=Aug 30 14:30:44	completed successfully
08/30 17:32:26.541 INFO |        server_job:0129| END GOOD	75155333-chromeos-test/chromeos4-row10-rack5-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592644	localtime=Aug 30 14:30:44	
08/30 17:32:26.542 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_full=75155333-chromeos-test
08/30 17:32:27.702 INFO |        server_job:0129| START	75155337-chromeos-test/chromeos4-row10-rack8-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592002	localtime=Aug 30 14:20:02	
08/30 17:32:27.703 INFO |        server_job:0129| 	GOOD	75155337-chromeos-test/chromeos4-row10-rack8-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592638	localtime=Aug 30 14:30:38	completed successfully
08/30 17:32:27.703 INFO |        server_job:0129| END GOOD	75155337-chromeos-test/chromeos4-row10-rack8-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592638	localtime=Aug 30 14:30:38	
08/30 17:32:27.704 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_full=75155337-chromeos-test
08/30 17:32:28.776 INFO |        server_job:0129| START	75155341-chromeos-test/chromeos4-row10-rack5-host11/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592038	localtime=Aug 30 14:20:38	
08/30 17:32:28.776 INFO |        server_job:0129| 	GOOD	75155341-chromeos-test/chromeos4-row10-rack5-host11/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592678	localtime=Aug 30 14:31:18	completed successfully
08/30 17:32:28.777 INFO |        server_job:0129| END GOOD	75155341-chromeos-test/chromeos4-row10-rack5-host11/autoupdate_EndToEndTest.paygen_au_dev_delta	autoupdate_EndToEndTest.paygen_au_dev_delta	timestamp=1472592678	localtime=Aug 30 14:31:18	
08/30 17:32:28.777 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_delta=75155341-chromeos-test
08/30 17:32:29.756 INFO |        server_job:0129| START	75155345-chromeos-test/chromeos4-row10-rack7-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592194	localtime=Aug 30 14:23:14	
08/30 17:32:29.756 INFO |        server_job:0129| 	GOOD	75155345-chromeos-test/chromeos4-row10-rack7-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592963	localtime=Aug 30 14:36:03	completed successfully
08/30 17:32:29.756 INFO |        server_job:0129| END GOOD	75155345-chromeos-test/chromeos4-row10-rack7-host5/autoupdate_EndToEndTest.paygen_au_dev_full	autoupdate_EndToEndTest.paygen_au_dev_full	timestamp=1472592963	localtime=Aug 30 14:36:03	
08/30 17:32:29.757 DEBUG|             suite:1095| Adding status keyval for autoupdate_EndToEndTest.paygen_au_dev_full=75155345-chromeos-test
08/30 17:32:34.781 DEBUG|     dynamic_suite:0556| Finished waiting on suite. Returning from _perform_reimage_and_run.
08/30 17:32:34.782 DEBUG|     dynamic_suite:0495| Returning from dynamic_suite.reimage_and_run.
08/30 17:32:34.782 INFO |        server_job:0693| Finished processing control file
08/30 17:32:34.785 WARNI|        subcommand:0081| parallel_simple was called with an empty arglist, did you forget to pass in a list of machines?
08/30 17:32:34.989 DEBUG|   logging_manager:0627| Logging subprocess finished
08/30 17:32:34.989 DEBUG|   logging_manager:0627| Logging subprocess finished








08-30-2016 [14:02:50] Created suite job: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75154968
@@@STEP_LINK@Link to suite@http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75154968@@@
The suite job has another 2:29:48.023903 till timeout.
The suite job has another 1:59:46.032109 till timeout.

08-30-2016 [15:32:53] printing summary of incomplete jobs (5):

autoupdate_EndToEndTest_paygen_au_dev_delta_8756.0.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155329
autoupdate_EndToEndTest_paygen_au_dev_full_8737.1.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155333
autoupdate_EndToEndTest_paygen_au_dev_full_8756.0.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155337
autoupdate_EndToEndTest_paygen_au_dev_delta_8737.1.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155341
autoupdate_EndToEndTest_paygen_au_dev_full_6457.83.0: http://cautotest.corp.google.com/afe/#tab_id=view_job&object_id=75155345
The suite job has another 1:29:32.538134 till timeout.
The suite job has another 0:59:30.017401 till timeout.
The suite job has another 0:29:25.355396 till timeout.
The suite job has another -1 day, 23:59:21.060561 till timeout.
The suite job has another -1 day, 23:29:19.049561 till timeout.
Suite timed out. Started on 08-30-2016 [14:02:50], timed out on 08-30-2016 [17:40:52]
Suite job                                     [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_delta   [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_delta   [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]

Suite timings:
Downloads started at 2016-08-30 14:02:44
Payload downloads ended at 2016-08-30 14:02:47
Suite started at 2016-08-30 14:03:23
Artifact downloads ended (at latest) at 2016-08-30 14:03:36
Testing started at 2016-08-30 14:17:31
Testing ended at 2016-08-30 14:36:03

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

this is due to the lab db outage and has been fixed at crbug.com/641290

Comment 3 by nxia@chromium.org, Sep 2 2016

Status: Fixed (was: Untriaged)

Comment 4 by dchan@chromium.org, Oct 7 2016

Labels: VerifyIn-55

Comment 5 by dchan@chromium.org, Oct 10 2016

Labels: -VerifyIn-55

Comment 6 by dchan@google.com, Nov 19 2016

Labels: VerifyIn-56

Comment 7 by dchan@google.com, Jan 21 2017

Labels: VerifyIn-57

Comment 8 by dchan@google.com, Mar 4 2017

Labels: VerifyIn-58

Comment 9 by dchan@google.com, Apr 17 2017

Labels: VerifyIn-59

Comment 10 by dchan@google.com, May 30 2017

Labels: VerifyIn-60
Labels: VerifyIn-61
Status: Verified (was: Fixed)

Sign in to add a comment