[21:26:04.280] New invocation is queued and will start shortly
[21:26:05.515] Starting the invocation (attempt 1)
[21:26:05.550] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[21:26:05.550] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[21:26:05.550] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111766258619719920",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"d9b69b4e64cef0c62bf0e4c41c06e511b9546c82\"}}",
"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:9111766258619719920",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d9b69b4e64cef0c62bf0e4c41c06e511b9546c82",
"gitiles_ref:refs/heads/master"
]
}
[21:26:06.871] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary": true,
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526505965725510",
"id": "8946336196441864464",
"lease_expiration_ts": "1526514966597880",
"lease_key": "656219091",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"d9b69b4e64cef0c62bf0e4c41c06e511b9546c82\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526505966709080",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2395",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d9b69b4e64cef0c62bf0e4c41c06e511b9546c82",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111766258619719920",
"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/2395",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946336196441864464",
"swarming_tag:buildbucket_hostname:cr-buildbucket-dev.appspot.com",
"swarming_tag:buildbucket_template_canary:1",
"swarming_tag:buildbucket_template_revision:31208890f23bdb2fc5a18d6f2e1d18355d60a3a4",
"swarming_tag:builder:infra-continuous-win10-64",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d9b69b4e64cef0c62bf0e4c41c06e511b9546c82",
"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/8946336196441864464/+/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:9111766258619719920",
"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:3d83aa1358b1af10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526505966709090",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2395",
"utcnow_ts": "1526505966858560"
}
}
[21:26:06.871] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2395
[21:26:06.871] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:2:0) after 1m0s
[21:27:06.903] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:2:0)
[21:27:06.903] Timer tick, asking Buildbucket for the build status
[21:27:07.059] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:27:07.059] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:3:0) after 1m0s
[21:28:07.110] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:3:0)
[21:28:07.110] Timer tick, asking Buildbucket for the build status
[21:28:07.198] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:28:07.198] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:4:0) after 1m0s
[21:29:07.373] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:4:0)
[21:29:07.373] Timer tick, asking Buildbucket for the build status
[21:29:07.506] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:29:07.506] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:5:0) after 1m0s
[21:30:07.552] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:5:0)
[21:30:07.552] Timer tick, asking Buildbucket for the build status
[21:30:07.707] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:30:07.707] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:6:0) after 1m0s
[21:31:07.785] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:6:0)
[21:31:07.786] Timer tick, asking Buildbucket for the build status
[21:31:07.862] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:31:07.862] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:7:0) after 1m0s
[21:32:07.957] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:7:0)
[21:32:07.957] Timer tick, asking Buildbucket for the build status
[21:32:08.178] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:32:08.178] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:8:0) after 1m0s
[21:33:08.421] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:8:0)
[21:33:08.421] Timer tick, asking Buildbucket for the build status
[21:33:08.514] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:33:08.514] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:9:0) after 1m0s
[21:34:08.530] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:9:0)
[21:34:08.530] Timer tick, asking Buildbucket for the build status
[21:34:08.600] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:34:08.600] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:10:0) after 1m0s
[21:35:08.688] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:10:0)
[21:35:08.688] Timer tick, asking Buildbucket for the build status
[21:35:08.809] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:35:08.809] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:11:0) after 1m0s
[21:36:08.934] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:11:0)
[21:36:08.934] Timer tick, asking Buildbucket for the build status
[21:36:09.007] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:36:09.007] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:12:0) after 1m0s
[21:37:09.128] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:12:0)
[21:37:09.128] Timer tick, asking Buildbucket for the build status
[21:37:09.213] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:37:09.213] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:13:0) after 1m0s
[21:38:09.316] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:13:0)
[21:38:09.316] Timer tick, asking Buildbucket for the build status
[21:38:09.423] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:38:09.423] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:14:0) after 1m0s
[21:39:09.508] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:14:0)
[21:39:09.508] Timer tick, asking Buildbucket for the build status
[21:39:09.626] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:39:09.626] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:15:0) after 1m0s
[21:40:09.689] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:15:0)
[21:40:09.689] Timer tick, asking Buildbucket for the build status
[21:40:09.782] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:40:09.782] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:16:0) after 1m0s
[21:41:09.824] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:16:0)
[21:41:09.824] Timer tick, asking Buildbucket for the build status
[21:41:09.987] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:41:09.987] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:17:0) after 1m0s
[21:42:10.120] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:17:0)
[21:42:10.120] Timer tick, asking Buildbucket for the build status
[21:42:10.203] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:42:10.203] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:18:0) after 1m0s
[21:43:10.237] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:18:0)
[21:43:10.237] Timer tick, asking Buildbucket for the build status
[21:43:10.366] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:43:10.367] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:19:0) after 1m0s
[21:44:10.400] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:19:0)
[21:44:10.400] Timer tick, asking Buildbucket for the build status
[21:44:10.485] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:44:10.485] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:20:0) after 1m0s
[21:45:10.545] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:20:0)
[21:45:10.545] Timer tick, asking Buildbucket for the build status
[21:45:10.682] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:45:10.682] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:21:0) after 1m0s
[21:46:10.809] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:21:0)
[21:46:10.809] Timer tick, asking Buildbucket for the build status
[21:46:10.888] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:46:10.889] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:22:0) after 1m0s
[21:47:11.011] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:22:0)
[21:47:11.011] Timer tick, asking Buildbucket for the build status
[21:47:11.098] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:47:11.098] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:23:0) after 1m0s
[21:48:11.224] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:23:0)
[21:48:11.224] Timer tick, asking Buildbucket for the build status
[21:48:11.319] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:48:11.319] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:24:0) after 1m0s
[21:49:11.433] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:24:0)
[21:49:11.433] Timer tick, asking Buildbucket for the build status
[21:49:11.522] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:49:11.522] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:25:0) after 1m0s
[21:50:11.632] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:25:0)
[21:50:11.632] Timer tick, asking Buildbucket for the build status
[21:50:11.821] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:50:11.821] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:26:0) after 1m0s
[21:51:11.856] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:26:0)
[21:51:11.856] Timer tick, asking Buildbucket for the build status
[21:51:12.829] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:51:12.829] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:27:0) after 1m0s
[21:52:12.852] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:27:0)
[21:52:12.852] Timer tick, asking Buildbucket for the build status
[21:52:12.974] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:52:12.974] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:28:0) after 1m0s
[21:53:13.002] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:28:0)
[21:53:13.002] Timer tick, asking Buildbucket for the build status
[21:53:13.089] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:53:13.089] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:29:0) after 1m0s
[21:54:13.107] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:29:0)
[21:54:13.107] Timer tick, asking Buildbucket for the build status
[21:54:13.188] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:54:13.188] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:30:0) after 1m0s
[21:55:13.219] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:30:0)
[21:55:13.219] Timer tick, asking Buildbucket for the build status
[21:55:13.284] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:55:13.284] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:31:0) after 1m0s
[21:56:13.400] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:31:0)
[21:56:13.400] Timer tick, asking Buildbucket for the build status
[21:56:13.507] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:56:13.507] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:32:0) after 1m0s
[21:57:13.643] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:32:0)
[21:57:13.643] Timer tick, asking Buildbucket for the build status
[21:57:13.798] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:57:13.798] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:33:0) after 1m0s
[21:58:13.910] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:33:0)
[21:58:13.910] Timer tick, asking Buildbucket for the build status
[21:58:13.984] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:58:13.984] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:34:0) after 1m0s
[21:59:14.212] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:34:0)
[21:59:14.212] Timer tick, asking Buildbucket for the build status
[21:59:14.291] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:59:14.291] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:35:0) after 1m0s
[22:00:14.412] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:35:0)
[22:00:14.412] Timer tick, asking Buildbucket for the build status
[22:00:14.511] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:00:14.511] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:36:0) after 1m0s
[22:01:14.575] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:36:0)
[22:01:14.575] Timer tick, asking Buildbucket for the build status
[22:01:14.695] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:01:14.695] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:37:0) after 1m0s
[22:02:14.927] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:37:0)
[22:02:14.927] Timer tick, asking Buildbucket for the build status
[22:02:15.010] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:02:15.010] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:38:0) after 1m0s
[22:03:15.187] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:38:0)
[22:03:15.187] Timer tick, asking Buildbucket for the build status
[22:03:15.295] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:03:15.295] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:39:0) after 1m0s
[22:04:15.521] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:39:0)
[22:04:15.521] Timer tick, asking Buildbucket for the build status
[22:04:15.841] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:04:15.841] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:40:0) after 1m0s
[22:05:15.976] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:40:0)
[22:05:15.976] Timer tick, asking Buildbucket for the build status
[22:05:16.322] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:05:16.322] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:41:0) after 1m0s
[22:06:16.513] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:41:0)
[22:06:16.513] Timer tick, asking Buildbucket for the build status
[22:06:16.913] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:06:16.913] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:42:0) after 1m0s
[22:07:17.051] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:42:0)
[22:07:17.051] Timer tick, asking Buildbucket for the build status
[22:07:17.416] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:07:17.416] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:43:0) after 1m0s
[22:08:17.450] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:43:0)
[22:08:17.450] Timer tick, asking Buildbucket for the build status
[22:08:17.815] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:08:17.815] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:44:0) after 1m0s
[22:09:17.891] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:44:0)
[22:09:17.891] Timer tick, asking Buildbucket for the build status
[22:09:18.211] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:09:18.211] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:45:0) after 1m0s
[22:10:18.308] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:45:0)
[22:10:18.308] Timer tick, asking Buildbucket for the build status
[22:10:18.633] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:10:18.633] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:46:0) after 1m0s
[22:11:18.786] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:46:0)
[22:11:18.786] Timer tick, asking Buildbucket for the build status
[22:11:19.148] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:11:19.148] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:47:0) after 1m0s
[22:12:19.167] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:47:0)
[22:12:19.167] Timer tick, asking Buildbucket for the build status
[22:12:19.388] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:12:19.388] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:48:0) after 1m0s
[22:13:19.520] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:48:0)
[22:13:19.520] Timer tick, asking Buildbucket for the build status
[22:13:19.595] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:13:19.595] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:49:0) after 1m0s
[22:14:19.745] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:49:0)
[22:14:19.745] Timer tick, asking Buildbucket for the build status
[22:14:19.874] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:14:19.874] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:50:0) after 1m0s
[22:15:19.961] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:50:0)
[22:15:19.961] Timer tick, asking Buildbucket for the build status
[22:15:20.085] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:15:20.085] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:51:0) after 1m0s
[22:16:20.134] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:51:0)
[22:16:20.134] Timer tick, asking Buildbucket for the build status
[22:16:20.274] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:16:20.274] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:52:0) after 1m0s
[22:17:20.320] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:52:0)
[22:17:20.320] Timer tick, asking Buildbucket for the build status
[22:17:20.491] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:17:20.491] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:53:0) after 1m0s
[22:18:20.609] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:53:0)
[22:18:20.609] Timer tick, asking Buildbucket for the build status
[22:18:20.695] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:18:20.695] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:54:0) after 1m0s
[22:19:20.782] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:54:0)
[22:19:20.782] Timer tick, asking Buildbucket for the build status
[22:19:20.913] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:19:20.914] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:55:0) after 1m0s
[22:20:21.050] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:55:0)
[22:20:21.050] Timer tick, asking Buildbucket for the build status
[22:20:21.266] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:20:21.266] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:56:0) after 1m0s
[22:21:21.350] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:56:0)
[22:21:21.350] Timer tick, asking Buildbucket for the build status
[22:21:21.538] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:21:21.538] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:57:0) after 1m0s
[22:22:21.682] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:57:0)
[22:22:21.682] Timer tick, asking Buildbucket for the build status
[22:22:21.800] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:22:21.800] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:58:0) after 1m0s
[22:23:21.896] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:58:0)
[22:23:21.896] Timer tick, asking Buildbucket for the build status
[22:23:22.052] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:23:22.052] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:59:0) after 1m0s
[22:24:22.415] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:59:0)
[22:24:22.415] Timer tick, asking Buildbucket for the build status
[22:24:22.527] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:24:22.527] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:60:0) after 1m0s
[22:25:22.763] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:60:0)
[22:25:22.763] Timer tick, asking Buildbucket for the build status
[22:25:22.894] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:25:22.894] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:61:0) after 1m0s
[22:26:23.024] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:61:0)
[22:26:23.024] Timer tick, asking Buildbucket for the build status
[22:26:23.103] Build 8946336196441864464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:26:23.103] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111766258619719920:62:0) after 1m0s
[22:27:02.272] Received PubSub notification, asking Buildbucket for the build status
[22:27:02.371] Build 8946336196441864464: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[22:27:02.371] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary": true,
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526509620685810",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526505965725510",
"id": "8946336196441864464",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"d9b69b4e64cef0c62bf0e4c41c06e511b9546c82\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-16T21:26:05.941480\", \"name\": \"bb-8946336196441864464-infra-infra-continuous-win10-64\", \"task_id\": \"3d83aa1358b1af10\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2395\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8946336196441864464\", \"buildbucket_hostname:cr-buildbucket-dev.appspot.com\", \"buildbucket_template_canary:1\", \"buildbucket_template_revision:31208890f23bdb2fc5a18d6f2e1d18355d60a3a4\", \"builder:infra-continuous-win10-64\", \"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d9b69b4e64cef0c62bf0e4c41c06e511b9546c82\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946336196441864464/+/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:9111766258619719920\", \"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-16T22:27:00.685810\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-16T22:27:00.685810\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526509621382340",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2395",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d9b69b4e64cef0c62bf0e4c41c06e511b9546c82",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111766258619719920",
"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/2395",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946336196441864464",
"swarming_tag:buildbucket_hostname:cr-buildbucket-dev.appspot.com",
"swarming_tag:buildbucket_template_canary:1",
"swarming_tag:buildbucket_template_revision:31208890f23bdb2fc5a18d6f2e1d18355d60a3a4",
"swarming_tag:builder:infra-continuous-win10-64",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d9b69b4e64cef0c62bf0e4c41c06e511b9546c82",
"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/8946336196441864464/+/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:9111766258619719920",
"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:3d83aa1358b1af10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526509621383090",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2395",
"utcnow_ts": "1526509622351340"
}
}
[22:27:02.371] Invocation finished in 1h0m58.106210045s with status FAILED