[11:21:12.387] New invocation is queued and will start shortly
[11:21:13.751] Starting the invocation (attempt 1)
[11:21:13.792] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[11:21:13.793] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[11:21:13.793] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111260731699728720",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"f841bd2f597734d3d35a853585b1abaf64eb407c\"}}",
"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:9111260731699728720",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/f841bd2f597734d3d35a853585b1abaf64eb407c",
"gitiles_ref:refs/heads/master"
]
}
[11:21:14.681] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526988073923850",
"id": "8945830669356087264",
"lease_expiration_ts": "1526997074489010",
"lease_key": "1044336738",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"f841bd2f597734d3d35a853585b1abaf64eb407c\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526988074603400",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2447",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/f841bd2f597734d3d35a853585b1abaf64eb407c",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111260731699728720",
"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/2447",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945830669356087264",
"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/+/f841bd2f597734d3d35a853585b1abaf64eb407c",
"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/8945830669356087264/+/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:9111260731699728720",
"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:3da0667536ec4810",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526988074603420",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2447",
"utcnow_ts": "1526988074670030"
}
}
[11:21:14.681] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2447
[11:21:14.681] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:2:0) after 1m0s
[11:22:14.707] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:2:0)
[11:22:14.707] Timer tick, asking Buildbucket for the build status
[11:22:14.775] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:22:14.775] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:3:0) after 1m0s
[11:23:14.795] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:3:0)
[11:23:14.795] Timer tick, asking Buildbucket for the build status
[11:23:14.873] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:23:14.873] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:4:0) after 1m0s
[11:24:14.893] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:4:0)
[11:24:14.893] Timer tick, asking Buildbucket for the build status
[11:24:14.977] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:24:14.977] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:5:0) after 1m0s
[11:25:14.996] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:5:0)
[11:25:14.996] Timer tick, asking Buildbucket for the build status
[11:25:15.051] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:25:15.051] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:6:0) after 1m0s
[11:26:15.078] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:6:0)
[11:26:15.078] Timer tick, asking Buildbucket for the build status
[11:26:15.178] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:26:15.178] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:7:0) after 1m0s
[11:27:15.194] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:7:0)
[11:27:15.194] Timer tick, asking Buildbucket for the build status
[11:27:15.279] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:27:15.279] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:8:0) after 1m0s
[11:28:15.309] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:8:0)
[11:28:15.309] Timer tick, asking Buildbucket for the build status
[11:28:15.401] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:28:15.401] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:9:0) after 1m0s
[11:29:15.418] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:9:0)
[11:29:15.418] Timer tick, asking Buildbucket for the build status
[11:29:15.479] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:29:15.479] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:10:0) after 1m0s
[11:30:15.500] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:10:0)
[11:30:15.500] Timer tick, asking Buildbucket for the build status
[11:30:15.595] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:30:15.596] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:11:0) after 1m0s
[11:31:15.665] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:11:0)
[11:31:15.665] Timer tick, asking Buildbucket for the build status
[11:31:15.775] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:31:15.775] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:12:0) after 1m0s
[11:32:15.799] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:12:0)
[11:32:15.799] Timer tick, asking Buildbucket for the build status
[11:32:15.885] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:32:15.885] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:13:0) after 1m0s
[11:33:15.910] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:13:0)
[11:33:15.910] Timer tick, asking Buildbucket for the build status
[11:33:15.980] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:33:15.980] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:14:0) after 1m0s
[11:34:15.997] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:14:0)
[11:34:15.997] Timer tick, asking Buildbucket for the build status
[11:34:16.074] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:34:16.074] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:15:0) after 1m0s
[11:35:16.092] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:15:0)
[11:35:16.092] Timer tick, asking Buildbucket for the build status
[11:35:16.188] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:35:16.188] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:16:0) after 1m0s
[11:36:16.234] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:16:0)
[11:36:16.234] Timer tick, asking Buildbucket for the build status
[11:36:16.305] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:36:16.305] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:17:0) after 1m0s
[11:37:16.328] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:17:0)
[11:37:16.328] Timer tick, asking Buildbucket for the build status
[11:37:16.795] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:37:16.795] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:18:0) after 1m0s
[11:38:16.814] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:18:0)
[11:38:16.814] Timer tick, asking Buildbucket for the build status
[11:38:16.891] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:38:16.891] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:19:0) after 1m0s
[11:39:16.916] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:19:0)
[11:39:16.916] Timer tick, asking Buildbucket for the build status
[11:39:16.969] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:39:16.969] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:20:0) after 1m0s
[11:40:16.991] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:20:0)
[11:40:16.991] Timer tick, asking Buildbucket for the build status
[11:40:17.085] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:40:17.085] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:21:0) after 1m0s
[11:41:17.104] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:21:0)
[11:41:17.104] Timer tick, asking Buildbucket for the build status
[11:41:17.175] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:41:17.175] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:22:0) after 1m0s
[11:42:17.272] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:22:0)
[11:42:17.272] Timer tick, asking Buildbucket for the build status
[11:42:17.428] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:42:17.428] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:23:0) after 1m0s
[11:43:17.514] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:23:0)
[11:43:17.514] Timer tick, asking Buildbucket for the build status
[11:43:17.705] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:43:17.705] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:24:0) after 1m0s
[11:44:17.828] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:24:0)
[11:44:17.828] Timer tick, asking Buildbucket for the build status
[11:44:17.929] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:44:17.929] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:25:0) after 1m0s
[11:45:18.097] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:25:0)
[11:45:18.097] Timer tick, asking Buildbucket for the build status
[11:45:18.266] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:45:18.266] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:26:0) after 1m0s
[11:46:18.350] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:26:0)
[11:46:18.350] Timer tick, asking Buildbucket for the build status
[11:46:18.592] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:46:18.592] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:27:0) after 1m0s
[11:47:18.786] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:27:0)
[11:47:18.786] Timer tick, asking Buildbucket for the build status
[11:47:18.934] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:47:18.934] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:28:0) after 1m0s
[11:48:19.106] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:28:0)
[11:48:19.106] Timer tick, asking Buildbucket for the build status
[11:48:19.287] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:48:19.287] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:29:0) after 1m0s
[11:49:19.407] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:29:0)
[11:49:19.407] Timer tick, asking Buildbucket for the build status
[11:49:19.543] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:49:19.543] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:30:0) after 1m0s
[11:50:19.824] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:30:0)
[11:50:19.824] Timer tick, asking Buildbucket for the build status
[11:50:19.970] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:50:19.970] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:31:0) after 1m0s
[11:51:20.111] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:31:0)
[11:51:20.111] Timer tick, asking Buildbucket for the build status
[11:51:20.285] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:51:20.285] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:32:0) after 1m0s
[11:52:20.521] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:32:0)
[11:52:20.521] Timer tick, asking Buildbucket for the build status
[11:52:20.692] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:52:20.692] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:33:0) after 1m0s
[11:53:20.732] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:33:0)
[11:53:20.733] Timer tick, asking Buildbucket for the build status
[11:53:20.878] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:53:20.878] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:34:0) after 1m0s
[11:54:21.024] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:34:0)
[11:54:21.024] Timer tick, asking Buildbucket for the build status
[11:54:21.258] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:54:21.258] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:35:0) after 1m0s
[11:55:21.336] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:35:0)
[11:55:21.336] Timer tick, asking Buildbucket for the build status
[11:55:21.586] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:55:21.586] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:36:0) after 1m0s
[11:56:21.828] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:36:0)
[11:56:21.828] Timer tick, asking Buildbucket for the build status
[11:56:22.016] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:56:22.016] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:37:0) after 1m0s
[11:57:22.122] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:37:0)
[11:57:22.122] Timer tick, asking Buildbucket for the build status
[11:57:22.241] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:57:22.241] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:38:0) after 1m0s
[11:58:22.467] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:38:0)
[11:58:22.467] Timer tick, asking Buildbucket for the build status
[11:58:22.713] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:58:22.713] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:39:0) after 1m0s
[11:59:22.922] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:39:0)
[11:59:22.922] Timer tick, asking Buildbucket for the build status
[11:59:23.118] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:59:23.118] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:40:0) after 1m0s
[12:00:23.250] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:40:0)
[12:00:23.250] Timer tick, asking Buildbucket for the build status
[12:00:23.502] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:00:23.502] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:41:0) after 1m0s
[12:01:23.592] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:41:0)
[12:01:23.592] Timer tick, asking Buildbucket for the build status
[12:01:23.719] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:01:23.719] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:42:0) after 1m0s
[12:02:23.849] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:42:0)
[12:02:23.849] Timer tick, asking Buildbucket for the build status
[12:02:24.053] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:02:24.053] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:43:0) after 1m0s
[12:03:24.123] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:43:0)
[12:03:24.123] Timer tick, asking Buildbucket for the build status
[12:03:24.282] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:03:24.282] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:44:0) after 1m0s
[12:04:24.361] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:44:0)
[12:04:24.361] Timer tick, asking Buildbucket for the build status
[12:04:24.526] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:04:24.526] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:45:0) after 1m0s
[12:05:24.676] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:45:0)
[12:05:24.676] Timer tick, asking Buildbucket for the build status
[12:05:24.826] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:05:24.826] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:46:0) after 1m0s
[12:06:24.899] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:46:0)
[12:06:24.899] Timer tick, asking Buildbucket for the build status
[12:06:25.043] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:06:25.043] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:47:0) after 1m0s
[12:07:25.174] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:47:0)
[12:07:25.174] Timer tick, asking Buildbucket for the build status
[12:07:25.321] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:07:25.321] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:48:0) after 1m0s
[12:08:25.392] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:48:0)
[12:08:25.393] Timer tick, asking Buildbucket for the build status
[12:08:25.522] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:08:25.522] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:49:0) after 1m0s
[12:09:25.672] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:49:0)
[12:09:25.672] Timer tick, asking Buildbucket for the build status
[12:09:25.741] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:09:25.741] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:50:0) after 1m0s
[12:10:25.800] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:50:0)
[12:10:25.800] Timer tick, asking Buildbucket for the build status
[12:10:25.934] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:10:25.934] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:51:0) after 1m0s
[12:11:26.101] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:51:0)
[12:11:26.101] Timer tick, asking Buildbucket for the build status
[12:11:26.235] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:11:26.235] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:52:0) after 1m0s
[12:12:26.375] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:52:0)
[12:12:26.375] Timer tick, asking Buildbucket for the build status
[12:12:26.486] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:12:26.486] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:53:0) after 1m0s
[12:14:34.541] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:53:0)
[12:14:34.541] Timer tick, asking Buildbucket for the build status
[12:14:34.868] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:14:34.868] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:54:0) after 1m0s
[12:15:34.893] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:54:0)
[12:15:34.893] Timer tick, asking Buildbucket for the build status
[12:15:35.670] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:15:35.670] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:55:0) after 1m0s
[12:16:35.734] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:55:0)
[12:16:35.734] Timer tick, asking Buildbucket for the build status
[12:16:35.972] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:16:35.972] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:56:0) after 1m0s
[12:17:36.025] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:56:0)
[12:17:36.025] Timer tick, asking Buildbucket for the build status
[12:17:36.193] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:17:36.193] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:57:0) after 1m0s
[12:18:36.402] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:57:0)
[12:18:36.402] Timer tick, asking Buildbucket for the build status
[12:18:36.522] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:18:36.522] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:58:0) after 1m0s
[12:19:36.549] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:58:0)
[12:19:36.549] Timer tick, asking Buildbucket for the build status
[12:19:36.693] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:19:36.693] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:59:0) after 1m0s
[12:20:36.851] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:59:0)
[12:20:36.851] Timer tick, asking Buildbucket for the build status
[12:20:37.174] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:20:37.174] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:60:0) after 1m0s
[12:21:37.269] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:60:0)
[12:21:37.269] Timer tick, asking Buildbucket for the build status
[12:21:37.686] Build 8945830669356087264: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:21:37.686] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111260731699728720:61:0) after 1m0s
[12:22:09.086] Received PubSub notification, asking Buildbucket for the build status
[12:22:09.235] Build 8945830669356087264: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[12:22:09.235] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526991726929480",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526988073923850",
"id": "8945830669356087264",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"f841bd2f597734d3d35a853585b1abaf64eb407c\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-22T11:21:14.159020\", \"name\": \"bb-8945830669356087264-infra-infra-continuous-win10-64\", \"task_id\": \"3da0667536ec4810\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2447\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8945830669356087264\", \"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/+/f841bd2f597734d3d35a853585b1abaf64eb407c\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8945830669356087264/+/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:9111260731699728720\", \"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\": [\"3561-435d49c-tainted-smut\"], \"abandoned_ts\": \"2018-05-22T12:22:06.929480\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-22T12:22:06.929480\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526991727706940",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2447",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/f841bd2f597734d3d35a853585b1abaf64eb407c",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111260731699728720",
"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/2447",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945830669356087264",
"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/+/f841bd2f597734d3d35a853585b1abaf64eb407c",
"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/8945830669356087264/+/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:9111260731699728720",
"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:3da0667536ec4810",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526991727708470",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2447",
"utcnow_ts": "1526991729200300"
}
}
[12:22:09.235] Invocation finished in 1h0m56.930729625s with status FAILED