[17:15:10.215] New invocation is queued and will start shortly
[17:15:11.677] Starting the invocation (attempt 1)
[17:15:11.716] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[17:15:11.716] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[17:15:11.717] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111691446985264288",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"c8cc033118511b026deda64fa2b29735e1dc8a48\"}}",
"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:9111691446985264288",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c8cc033118511b026deda64fa2b29735e1dc8a48",
"gitiles_ref:refs/heads/master"
]
}
[17:15:12.843] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526577311823010",
"id": "8946261384635793248",
"lease_expiration_ts": "1526586312470010",
"lease_key": "640263620",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"c8cc033118511b026deda64fa2b29735e1dc8a48\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526577312737760",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2404",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c8cc033118511b026deda64fa2b29735e1dc8a48",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111691446985264288",
"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/2404",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946261384635793248",
"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/+/c8cc033118511b026deda64fa2b29735e1dc8a48",
"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/8946261384635793248/+/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:9111691446985264288",
"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:3d87eaba2b9f7710",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526577312737770",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2404",
"utcnow_ts": "1526577312828680"
}
}
[17:15:12.843] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2404
[17:15:12.843] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:2:0) after 1m0s
[17:16:12.965] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:2:0)
[17:16:12.965] Timer tick, asking Buildbucket for the build status
[17:16:13.062] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:16:13.062] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:3:0) after 1m0s
[17:17:13.187] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:3:0)
[17:17:13.187] Timer tick, asking Buildbucket for the build status
[17:17:13.283] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:17:13.283] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:4:0) after 1m0s
[17:18:13.407] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:4:0)
[17:18:13.407] Timer tick, asking Buildbucket for the build status
[17:18:13.483] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:18:13.483] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:5:0) after 1m0s
[17:19:13.572] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:5:0)
[17:19:13.572] Timer tick, asking Buildbucket for the build status
[17:19:13.656] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:19:13.656] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:6:0) after 1m0s
[17:20:13.780] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:6:0)
[17:20:13.780] Timer tick, asking Buildbucket for the build status
[17:20:13.868] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:20:13.868] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:7:0) after 1m0s
[17:21:14.001] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:7:0)
[17:21:14.001] Timer tick, asking Buildbucket for the build status
[17:21:14.089] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:21:14.089] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:8:0) after 1m0s
[17:22:14.224] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:8:0)
[17:22:14.224] Timer tick, asking Buildbucket for the build status
[17:22:14.409] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:22:14.409] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:9:0) after 1m0s
[17:23:14.529] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:9:0)
[17:23:14.529] Timer tick, asking Buildbucket for the build status
[17:23:14.922] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:23:14.922] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:10:0) after 1m0s
[17:24:15.015] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:10:0)
[17:24:15.015] Timer tick, asking Buildbucket for the build status
[17:24:15.322] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:24:15.322] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:11:0) after 1m0s
[17:25:15.489] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:11:0)
[17:25:15.489] Timer tick, asking Buildbucket for the build status
[17:25:16.031] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:25:16.031] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:12:0) after 1m0s
[17:26:16.117] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:12:0)
[17:26:16.117] Timer tick, asking Buildbucket for the build status
[17:26:16.503] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:26:16.503] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:13:0) after 1m0s
[17:27:16.661] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:13:0)
[17:27:16.661] Timer tick, asking Buildbucket for the build status
[17:27:17.026] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:27:17.026] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:14:0) after 1m0s
[17:28:17.148] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:14:0)
[17:28:17.148] Timer tick, asking Buildbucket for the build status
[17:28:17.551] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:28:17.551] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:15:0) after 1m0s
[17:29:17.673] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:15:0)
[17:29:17.673] Timer tick, asking Buildbucket for the build status
[17:29:18.072] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:29:18.072] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:16:0) after 1m0s
[17:30:18.127] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:16:0)
[17:30:18.127] Timer tick, asking Buildbucket for the build status
[17:30:18.600] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:30:18.600] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:17:0) after 1m0s
[17:31:18.839] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:17:0)
[17:31:18.839] Timer tick, asking Buildbucket for the build status
[17:31:19.277] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:31:19.277] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:18:0) after 1m0s
[17:32:19.406] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:18:0)
[17:32:19.406] Timer tick, asking Buildbucket for the build status
[17:32:19.750] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:32:19.751] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:19:0) after 1m0s
[17:33:19.898] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:19:0)
[17:33:19.898] Timer tick, asking Buildbucket for the build status
[17:33:19.988] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:33:19.988] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:20:0) after 1m0s
[17:34:20.114] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:20:0)
[17:34:20.114] Timer tick, asking Buildbucket for the build status
[17:34:20.403] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:34:20.403] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:21:0) after 1m0s
[17:35:20.508] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:21:0)
[17:35:20.508] Timer tick, asking Buildbucket for the build status
[17:35:20.809] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:35:20.809] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:22:0) after 1m0s
[17:36:20.945] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:22:0)
[17:36:20.945] Timer tick, asking Buildbucket for the build status
[17:36:21.369] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:36:21.369] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:23:0) after 1m0s
[17:37:21.400] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:23:0)
[17:37:21.400] Timer tick, asking Buildbucket for the build status
[17:37:21.713] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:37:21.713] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:24:0) after 1m0s
[17:38:21.836] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:24:0)
[17:38:21.836] Timer tick, asking Buildbucket for the build status
[17:38:22.304] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:38:22.304] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:25:0) after 1m0s
[17:39:22.561] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:25:0)
[17:39:22.561] Timer tick, asking Buildbucket for the build status
[17:39:23.035] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:39:23.035] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:26:0) after 1m0s
[17:40:23.158] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:26:0)
[17:40:23.158] Timer tick, asking Buildbucket for the build status
[17:40:23.559] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:40:23.559] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:27:0) after 1m0s
[17:41:23.684] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:27:0)
[17:41:23.684] Timer tick, asking Buildbucket for the build status
[17:41:24.127] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:41:24.127] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:28:0) after 1m0s
[17:42:24.174] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:28:0)
[17:42:24.174] Timer tick, asking Buildbucket for the build status
[17:42:24.577] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:42:24.577] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:29:0) after 1m0s
[17:43:24.707] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:29:0)
[17:43:24.707] Timer tick, asking Buildbucket for the build status
[17:43:25.090] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:43:25.090] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:30:0) after 1m0s
[17:44:25.186] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:30:0)
[17:44:25.186] Timer tick, asking Buildbucket for the build status
[17:44:25.467] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:44:25.467] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:31:0) after 1m0s
[17:45:25.666] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:31:0)
[17:45:25.666] Timer tick, asking Buildbucket for the build status
[17:45:26.204] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:45:26.204] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:32:0) after 1m0s
[17:46:26.353] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:32:0)
[17:46:26.353] Timer tick, asking Buildbucket for the build status
[17:46:26.726] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:46:26.726] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:33:0) after 1m0s
[17:47:26.768] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:33:0)
[17:47:26.768] Timer tick, asking Buildbucket for the build status
[17:47:27.174] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:47:27.174] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:34:0) after 1m0s
[17:48:27.299] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:34:0)
[17:48:27.299] Timer tick, asking Buildbucket for the build status
[17:48:27.679] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:48:27.679] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:35:0) after 1m0s
[17:49:27.762] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:35:0)
[17:49:27.762] Timer tick, asking Buildbucket for the build status
[17:49:28.126] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:49:28.126] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:36:0) after 1m0s
[17:50:28.151] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:36:0)
[17:50:28.151] Timer tick, asking Buildbucket for the build status
[17:50:28.597] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:50:28.597] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:37:0) after 1m0s
[17:51:28.618] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:37:0)
[17:51:28.618] Timer tick, asking Buildbucket for the build status
[17:51:29.077] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:51:29.077] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:38:0) after 1m0s
[17:52:29.211] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:38:0)
[17:52:29.211] Timer tick, asking Buildbucket for the build status
[17:52:29.610] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:52:29.611] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:39:0) after 1m0s
[17:53:29.737] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:39:0)
[17:53:29.737] Timer tick, asking Buildbucket for the build status
[17:53:30.249] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:53:30.249] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:40:0) after 1m0s
[17:54:30.439] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:40:0)
[17:54:30.439] Timer tick, asking Buildbucket for the build status
[17:54:30.814] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:54:30.814] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:41:0) after 1m0s
[17:55:30.923] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:41:0)
[17:55:30.923] Timer tick, asking Buildbucket for the build status
[17:55:31.304] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:55:31.304] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:42:0) after 1m0s
[17:56:31.425] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:42:0)
[17:56:31.425] Timer tick, asking Buildbucket for the build status
[17:56:31.649] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:56:31.649] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:43:0) after 1m0s
[17:57:31.775] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:43:0)
[17:57:31.775] Timer tick, asking Buildbucket for the build status
[17:57:32.132] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:57:32.132] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:44:0) after 1m0s
[17:58:32.239] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:44:0)
[17:58:32.239] Timer tick, asking Buildbucket for the build status
[17:58:32.628] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:58:32.629] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:45:0) after 1m0s
[17:59:32.655] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:45:0)
[17:59:32.655] Timer tick, asking Buildbucket for the build status
[17:59:33.027] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:59:33.027] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:46:0) after 1m0s
[18:00:33.075] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:46:0)
[18:00:33.075] Timer tick, asking Buildbucket for the build status
[18:00:33.556] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:00:33.556] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:47:0) after 1m0s
[18:01:33.621] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:47:0)
[18:01:33.621] Timer tick, asking Buildbucket for the build status
[18:01:34.066] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:01:34.066] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:48:0) after 1m0s
[18:02:34.097] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:48:0)
[18:02:34.097] Timer tick, asking Buildbucket for the build status
[18:02:34.482] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:02:34.482] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:49:0) after 1m0s
[18:03:34.715] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:49:0)
[18:03:34.715] Timer tick, asking Buildbucket for the build status
[18:03:35.807] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:03:35.807] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:50:0) after 1m0s
[18:04:35.917] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:50:0)
[18:04:35.917] Timer tick, asking Buildbucket for the build status
[18:04:36.344] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:04:36.344] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:51:0) after 1m0s
[18:05:36.548] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:51:0)
[18:05:36.548] Timer tick, asking Buildbucket for the build status
[18:05:36.953] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:05:36.953] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:52:0) after 1m0s
[18:06:37.093] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:52:0)
[18:06:37.093] Timer tick, asking Buildbucket for the build status
[18:06:37.446] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:06:37.446] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:53:0) after 1m0s
[18:07:37.689] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:53:0)
[18:07:37.689] Timer tick, asking Buildbucket for the build status
[18:07:38.113] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:07:38.113] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:54:0) after 1m0s
[18:08:38.254] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:54:0)
[18:08:38.254] Timer tick, asking Buildbucket for the build status
[18:08:38.681] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:08:38.681] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:55:0) after 1m0s
[18:09:38.752] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:55:0)
[18:09:38.752] Timer tick, asking Buildbucket for the build status
[18:09:39.116] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:09:39.116] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:56:0) after 1m0s
[18:10:39.340] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:56:0)
[18:10:39.340] Timer tick, asking Buildbucket for the build status
[18:10:40.019] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:10:40.019] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:57:0) after 1m0s
[18:11:40.164] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:57:0)
[18:11:40.164] Timer tick, asking Buildbucket for the build status
[18:11:40.596] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:11:40.596] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:58:0) after 1m0s
[18:12:40.715] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:58:0)
[18:12:40.715] Timer tick, asking Buildbucket for the build status
[18:12:41.010] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:12:41.010] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:59:0) after 1m0s
[18:13:41.171] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:59:0)
[18:13:41.171] Timer tick, asking Buildbucket for the build status
[18:13:41.602] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:13:41.602] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:60:0) after 1m0s
[18:14:41.687] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:60:0)
[18:14:41.687] Timer tick, asking Buildbucket for the build status
[18:14:42.097] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:14:42.097] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:61:0) after 1m0s
[18:15:42.184] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:61:0)
[18:15:42.184] Timer tick, asking Buildbucket for the build status
[18:15:42.585] Build 8946261384635793248: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:15:42.585] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111691446985264288:62:0) after 1m0s
[18:16:02.593] Received PubSub notification, asking Buildbucket for the build status
[18:16:02.645] Build 8946261384635793248: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[18:16:02.645] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526580961063820",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526577311823010",
"id": "8946261384635793248",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"c8cc033118511b026deda64fa2b29735e1dc8a48\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-17T17:15:12.163130\", \"name\": \"bb-8946261384635793248-infra-infra-continuous-win10-64\", \"task_id\": \"3d87eaba2b9f7710\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2404\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8946261384635793248\", \"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/+/c8cc033118511b026deda64fa2b29735e1dc8a48\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946261384635793248/+/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:9111691446985264288\", \"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\": [\"3550-7152c59\"], \"abandoned_ts\": \"2018-05-17T18:16:01.063820\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-17T18:16:01.063820\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526580961750850",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2404",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/c8cc033118511b026deda64fa2b29735e1dc8a48",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111691446985264288",
"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/2404",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946261384635793248",
"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/+/c8cc033118511b026deda64fa2b29735e1dc8a48",
"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/8946261384635793248/+/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:9111691446985264288",
"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:3d87eaba2b9f7710",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526580961751830",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2404",
"utcnow_ts": "1526580962634240"
}
}
[18:16:02.645] Invocation finished in 1h0m52.446423995s with status FAILED