[01:29:04.097] New invocation is queued and will start shortly
[01:29:05.465] Starting the invocation (attempt 1)
[01:29:05.500] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[01:29:05.557] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[01:29:05.557] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111750970574761248",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"c21c571e8788a23a5b0748783ee6b99ead774b2c\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
},
"tags": [
"builder:infra-continuous-win10-64",
"scheduler_invocation_id:9111750970574761248",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c21c571e8788a23a5b0748783ee6b99ead774b2c",
"gitiles_ref:refs/heads/master"
]
}
[01:29:06.933] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526520545690390",
"id": "8946320908240629008",
"lease_expiration_ts": "1526529546704140",
"lease_key": "836744367",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"c21c571e8788a23a5b0748783ee6b99ead774b2c\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526520546842610",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2399",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c21c571e8788a23a5b0748783ee6b99ead774b2c",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111750970574761248",
"scheduler_job_id:infra/infra-continuous-win10-64",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Windows-10",
"swarming_dimension:pool:Chrome",
"swarming_hostname:chromium-swarm-dev.appspot.com",
"swarming_tag:allow_milo:1",
"swarming_tag:build_address:luci.infra.ci/infra-continuous-win10-64/2399",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946320908240629008",
"swarming_tag:buildbucket_hostname:cr-buildbucket-dev.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:31208890f23bdb2fc5a18d6f2e1d18355d60a3a4",
"swarming_tag:builder:infra-continuous-win10-64",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c21c571e8788a23a5b0748783ee6b99ead774b2c",
"swarming_tag:cpu:x86-64",
"swarming_tag:gitiles_ref:refs/heads/master",
"swarming_tag:log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946320908240629008/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:os:Windows-10",
"swarming_tag:pool:Chrome",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:infra_continuous_luci",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_tag:scheduler_invocation_id:9111750970574761248",
"swarming_tag:scheduler_job_id:infra/infra-continuous-win10-64",
"swarming_tag:service_account:adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler-dev",
"swarming_task_id:3d84888ccedebb10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526520546842620",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2399",
"utcnow_ts": "1526520546919690"
}
}
[01:29:06.933] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2399
[01:29:06.933] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:2:0) after 1m0s
[01:30:07.073] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:2:0)
[01:30:07.073] Timer tick, asking Buildbucket for the build status
[01:30:07.183] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:30:07.183] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:3:0) after 1m0s
[01:31:07.310] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:3:0)
[01:31:07.310] Timer tick, asking Buildbucket for the build status
[01:31:07.378] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:31:07.378] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:4:0) after 1m0s
[01:32:07.451] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:4:0)
[01:32:07.451] Timer tick, asking Buildbucket for the build status
[01:32:07.631] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:32:07.631] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:5:0) after 1m0s
[01:33:07.753] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:5:0)
[01:33:07.753] Timer tick, asking Buildbucket for the build status
[01:33:07.904] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:33:07.904] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:6:0) after 1m0s
[01:34:07.961] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:6:0)
[01:34:07.961] Timer tick, asking Buildbucket for the build status
[01:34:08.342] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:34:08.342] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:7:0) after 1m0s
[01:35:08.440] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:7:0)
[01:35:08.440] Timer tick, asking Buildbucket for the build status
[01:35:08.783] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:35:08.783] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:8:0) after 1m0s
[01:36:08.857] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:8:0)
[01:36:08.857] Timer tick, asking Buildbucket for the build status
[01:36:09.220] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:36:09.220] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:9:0) after 1m0s
[01:37:09.278] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:9:0)
[01:37:09.278] Timer tick, asking Buildbucket for the build status
[01:37:09.726] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:37:09.726] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:10:0) after 1m0s
[01:38:09.889] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:10:0)
[01:38:09.889] Timer tick, asking Buildbucket for the build status
[01:38:10.211] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:38:10.211] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:11:0) after 1m0s
[01:39:10.233] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:11:0)
[01:39:10.233] Timer tick, asking Buildbucket for the build status
[01:39:10.629] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:39:10.629] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:12:0) after 1m0s
[01:40:10.751] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:12:0)
[01:40:10.751] Timer tick, asking Buildbucket for the build status
[01:40:11.059] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:40:11.059] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:13:0) after 1m0s
[01:41:11.230] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:13:0)
[01:41:11.230] Timer tick, asking Buildbucket for the build status
[01:41:11.649] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:41:11.649] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:14:0) after 1m0s
[01:42:11.689] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:14:0)
[01:42:11.689] Timer tick, asking Buildbucket for the build status
[01:42:12.008] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:42:12.008] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:15:0) after 1m0s
[01:43:12.174] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:15:0)
[01:43:12.174] Timer tick, asking Buildbucket for the build status
[01:43:12.549] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:43:12.549] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:16:0) after 1m0s
[01:44:12.727] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:16:0)
[01:44:12.727] Timer tick, asking Buildbucket for the build status
[01:44:13.095] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:44:13.095] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:17:0) after 1m0s
[01:45:13.214] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:17:0)
[01:45:13.214] Timer tick, asking Buildbucket for the build status
[01:45:13.532] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:45:13.532] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:18:0) after 1m0s
[01:46:13.755] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:18:0)
[01:46:13.755] Timer tick, asking Buildbucket for the build status
[01:46:14.206] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:46:14.206] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:19:0) after 1m0s
[01:47:14.350] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:19:0)
[01:47:14.350] Timer tick, asking Buildbucket for the build status
[01:47:14.724] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:47:14.724] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:20:0) after 1m0s
[01:48:14.873] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:20:0)
[01:48:14.873] Timer tick, asking Buildbucket for the build status
[01:48:15.209] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:48:15.209] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:21:0) after 1m0s
[01:49:15.391] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:21:0)
[01:49:15.391] Timer tick, asking Buildbucket for the build status
[01:49:15.773] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:49:15.773] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:22:0) after 1m0s
[01:50:15.913] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:22:0)
[01:50:15.913] Timer tick, asking Buildbucket for the build status
[01:50:16.200] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:50:16.200] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:23:0) after 1m0s
[01:51:16.398] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:23:0)
[01:51:16.398] Timer tick, asking Buildbucket for the build status
[01:51:16.699] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:51:16.699] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:24:0) after 1m0s
[01:52:16.805] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:24:0)
[01:52:16.805] Timer tick, asking Buildbucket for the build status
[01:52:17.151] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:52:17.151] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:25:0) after 1m0s
[01:53:17.340] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:25:0)
[01:53:17.340] Timer tick, asking Buildbucket for the build status
[01:53:17.886] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:53:17.886] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:26:0) after 1m0s
[01:54:18.002] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:26:0)
[01:54:18.002] Timer tick, asking Buildbucket for the build status
[01:54:18.332] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:54:18.332] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:27:0) after 1m0s
[01:55:18.521] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:27:0)
[01:55:18.521] Timer tick, asking Buildbucket for the build status
[01:55:18.955] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:55:18.955] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:28:0) after 1m0s
[01:56:19.080] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:28:0)
[01:56:19.080] Timer tick, asking Buildbucket for the build status
[01:56:19.523] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:56:19.523] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:29:0) after 1m0s
[01:57:19.836] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:29:0)
[01:57:19.836] Timer tick, asking Buildbucket for the build status
[01:57:20.370] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:57:20.370] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:30:0) after 1m0s
[01:58:20.458] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:30:0)
[01:58:20.458] Timer tick, asking Buildbucket for the build status
[01:58:20.961] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:58:20.961] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:31:0) after 1m0s
[01:59:21.137] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:31:0)
[01:59:21.137] Timer tick, asking Buildbucket for the build status
[01:59:21.567] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:59:21.567] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:32:0) after 1m0s
[02:00:21.622] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:32:0)
[02:00:21.622] Timer tick, asking Buildbucket for the build status
[02:00:22.004] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:00:22.004] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:33:0) after 1m0s
[02:01:22.145] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:33:0)
[02:01:22.145] Timer tick, asking Buildbucket for the build status
[02:01:22.533] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:01:22.533] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:34:0) after 1m0s
[02:02:22.551] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:34:0)
[02:02:22.551] Timer tick, asking Buildbucket for the build status
[02:02:22.927] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:02:22.927] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:35:0) after 1m0s
[02:03:23.006] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:35:0)
[02:03:23.006] Timer tick, asking Buildbucket for the build status
[02:03:23.376] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:03:23.376] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:36:0) after 1m0s
[02:04:23.509] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:36:0)
[02:04:23.509] Timer tick, asking Buildbucket for the build status
[02:04:24.027] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:04:24.027] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:37:0) after 1m0s
[02:05:24.143] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:37:0)
[02:05:24.143] Timer tick, asking Buildbucket for the build status
[02:05:24.682] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:05:24.682] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:38:0) after 1m0s
[02:06:24.762] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:38:0)
[02:06:24.762] Timer tick, asking Buildbucket for the build status
[02:06:25.184] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:06:25.184] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:39:0) after 1m0s
[02:07:25.314] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:39:0)
[02:07:25.314] Timer tick, asking Buildbucket for the build status
[02:07:25.597] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:07:25.597] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:40:0) after 1m0s
[02:08:25.729] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:40:0)
[02:08:25.729] Timer tick, asking Buildbucket for the build status
[02:08:26.074] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:08:26.074] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:41:0) after 1m0s
[02:09:26.221] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:41:0)
[02:09:26.221] Timer tick, asking Buildbucket for the build status
[02:09:26.645] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:09:26.645] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:42:0) after 1m0s
[02:10:26.764] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:42:0)
[02:10:26.764] Timer tick, asking Buildbucket for the build status
[02:10:27.125] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:10:27.125] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:43:0) after 1m0s
[02:11:27.259] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:43:0)
[02:11:27.259] Timer tick, asking Buildbucket for the build status
[02:11:27.667] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:11:27.667] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:44:0) after 1m0s
[02:12:27.774] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:44:0)
[02:12:27.774] Timer tick, asking Buildbucket for the build status
[02:12:28.216] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:12:28.216] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:45:0) after 1m0s
[02:13:28.285] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:45:0)
[02:13:28.285] Timer tick, asking Buildbucket for the build status
[02:13:28.689] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:13:28.689] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:46:0) after 1m0s
[02:14:28.785] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:46:0)
[02:14:28.785] Timer tick, asking Buildbucket for the build status
[02:14:29.541] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:14:29.541] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:47:0) after 1m0s
[02:15:29.605] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:47:0)
[02:15:29.605] Timer tick, asking Buildbucket for the build status
[02:15:29.938] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:15:29.938] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:48:0) after 1m0s
[02:16:29.999] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:48:0)
[02:16:29.999] Timer tick, asking Buildbucket for the build status
[02:16:30.388] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:16:30.388] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:49:0) after 1m0s
[02:17:30.490] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:49:0)
[02:17:30.490] Timer tick, asking Buildbucket for the build status
[02:17:30.819] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:17:30.819] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:50:0) after 1m0s
[02:18:30.936] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:50:0)
[02:18:30.936] Timer tick, asking Buildbucket for the build status
[02:18:31.348] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:18:31.348] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:51:0) after 1m0s
[02:19:31.482] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:51:0)
[02:19:31.482] Timer tick, asking Buildbucket for the build status
[02:19:31.831] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:19:31.831] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:52:0) after 1m0s
[02:20:31.916] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:52:0)
[02:20:31.916] Timer tick, asking Buildbucket for the build status
[02:20:33.031] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:20:33.031] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:53:0) after 1m0s
[02:21:33.170] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:53:0)
[02:21:33.170] Timer tick, asking Buildbucket for the build status
[02:21:33.586] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:21:33.586] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:54:0) after 1m0s
[02:22:33.809] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:54:0)
[02:22:33.809] Timer tick, asking Buildbucket for the build status
[02:22:34.206] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:22:34.206] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:55:0) after 1m0s
[02:23:34.239] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:55:0)
[02:23:34.239] Timer tick, asking Buildbucket for the build status
[02:23:34.686] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:23:34.686] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:56:0) after 1m0s
[02:24:34.706] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:56:0)
[02:24:34.706] Timer tick, asking Buildbucket for the build status
[02:24:35.096] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:24:35.096] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:57:0) after 1m0s
[02:25:35.126] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:57:0)
[02:25:35.126] Timer tick, asking Buildbucket for the build status
[02:25:35.582] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:25:35.582] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:58:0) after 1m0s
[02:26:35.609] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:58:0)
[02:26:35.609] Timer tick, asking Buildbucket for the build status
[02:26:35.929] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:26:35.929] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:59:0) after 1m0s
[02:27:35.960] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:59:0)
[02:27:35.960] Timer tick, asking Buildbucket for the build status
[02:27:36.328] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:27:36.328] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:60:0) after 1m0s
[02:28:36.347] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:60:0)
[02:28:36.347] Timer tick, asking Buildbucket for the build status
[02:28:36.737] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:28:36.737] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:61:0) after 1m0s
[02:29:36.771] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:61:0)
[02:29:36.771] Timer tick, asking Buildbucket for the build status
[02:29:37.252] Build 8946320908240629008: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:29:37.252] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111750970574761248:62:0) after 1m0s
[02:30:02.318] Received PubSub notification, asking Buildbucket for the build status
[02:30:02.386] Build 8946320908240629008: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[02:30:02.386] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526524200876640",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526520545690390",
"id": "8946320908240629008",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"c21c571e8788a23a5b0748783ee6b99ead774b2c\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-17T01:29:06.015010\", \"name\": \"bb-8946320908240629008-infra-infra-continuous-win10-64\", \"task_id\": \"3d84888ccedebb10\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2399\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8946320908240629008\", \"buildbucket_hostname:cr-buildbucket-dev.appspot.com\", \"buildbucket_template_canary:0\", \"buildbucket_template_revision:31208890f23bdb2fc5a18d6f2e1d18355d60a3a4\", \"builder:infra-continuous-win10-64\", \"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c21c571e8788a23a5b0748783ee6b99ead774b2c\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946320908240629008/+/annotations\", \"luci_project:infra\", \"os:Windows-10\", \"pool:Chrome\", \"priority:30\", \"recipe_name:infra_continuous_luci\", \"recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra\", \"scheduler_invocation_id:9111750970574761248\", \"scheduler_job_id:infra/infra-continuous-win10-64\", \"service_account:adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com\", \"user:None\", \"user_agent:luci-scheduler-dev\"], \"internal_failure\": false, \"server_versions\": [\"3549-9b79bc3-tainted-maruel\"], \"abandoned_ts\": \"2018-05-17T02:30:00.876640\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-17T02:30:00.876640\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526524201553880",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2399",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c21c571e8788a23a5b0748783ee6b99ead774b2c",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111750970574761248",
"scheduler_job_id:infra/infra-continuous-win10-64",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Windows-10",
"swarming_dimension:pool:Chrome",
"swarming_hostname:chromium-swarm-dev.appspot.com",
"swarming_tag:allow_milo:1",
"swarming_tag:build_address:luci.infra.ci/infra-continuous-win10-64/2399",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946320908240629008",
"swarming_tag:buildbucket_hostname:cr-buildbucket-dev.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:31208890f23bdb2fc5a18d6f2e1d18355d60a3a4",
"swarming_tag:builder:infra-continuous-win10-64",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c21c571e8788a23a5b0748783ee6b99ead774b2c",
"swarming_tag:cpu:x86-64",
"swarming_tag:gitiles_ref:refs/heads/master",
"swarming_tag:log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946320908240629008/+/annotations",
"swarming_tag:luci_project:infra",
"swarming_tag:os:Windows-10",
"swarming_tag:pool:Chrome",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:infra_continuous_luci",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_tag:scheduler_invocation_id:9111750970574761248",
"swarming_tag:scheduler_job_id:infra/infra-continuous-win10-64",
"swarming_tag:service_account:adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler-dev",
"swarming_task_id:3d84888ccedebb10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526524201554860",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2399",
"utcnow_ts": "1526524202360750"
}
}
[02:30:02.387] Invocation finished in 1h0m58.30559395s with status FAILED