[21:25:04.080] New invocation is queued and will start shortly
[21:25:05.516] Starting the invocation (attempt 1)
[21:25:05.553] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[21:25:05.554] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[21:25:05.554] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9096455434423952736",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"bbd1466adbd8cdfc5efb42296adaa76add6fcd62\"}}",
"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:9096455434423952736",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/git/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"gitiles_ref:refs/heads/master"
]
}
[21:25:06.790] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1541107505645641",
"id": "8931025372118883072",
"lease_expiration_ts": "1541199306492132",
"lease_key": "435747519",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"bbd1466adbd8cdfc5efb42296adaa76add6fcd62\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1541107506665023",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/5240",
"builder:infra-continuous-win10-64",
"buildset:commit/git/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9096455434423952736",
"scheduler_job_id:infra/infra-continuous-win10-64",
"swarming_dimension:caches:builder_82ed111fed7ea8169e482f00b5f3e5338a65daa41208585de67cb0a736b1d538_v2",
"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/5240",
"swarming_tag:buildbucket_bucket:infra/ci",
"swarming_tag:buildbucket_build_id:8931025372118883072",
"swarming_tag:buildbucket_hostname:cr-buildbucket-dev.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:08e7af934650e940d8457d1ecdec69bcaa595f34",
"swarming_tag:builder:infra-continuous-win10-64",
"swarming_tag:buildset:commit/git/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"swarming_tag:caches:builder_82ed111fed7ea8169e482f00b5f3e5338a65daa41208585de67cb0a736b1d538_v2",
"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/8931025372118883072/+/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",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_tag:scheduler_invocation_id:9096455434423952736",
"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:swarming.pool.template:prod",
"swarming_tag:swarming.pool.version:daeae5401f149f52d36ed73afd144ba12bc7c77b",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler-dev",
"swarming_task_id:40e9fbe4223a0610",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1541107506665151",
"url": "https://luci-milo-dev.appspot.com/b/8931025372118883072",
"utcnow_ts": "1541107506776798"
}
}
[21:25:06.790] Task URL: https://luci-milo-dev.appspot.com/b/8931025372118883072
[21:25:06.790] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:2:0) after 1m0s
[21:26:06.868] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:2:0)
[21:26:06.868] Timer tick, asking Buildbucket for the build status
[21:26:06.959] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:26:06.959] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:3:0) after 1m0s
[21:27:07.081] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:3:0)
[21:27:07.081] Timer tick, asking Buildbucket for the build status
[21:27:07.155] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:27:07.155] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:4:0) after 1m0s
[21:28:07.172] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:4:0)
[21:28:07.172] Timer tick, asking Buildbucket for the build status
[21:28:07.248] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:28:07.248] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:5:0) after 1m0s
[21:29:07.276] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:5:0)
[21:29:07.277] Timer tick, asking Buildbucket for the build status
[21:29:07.371] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:29:07.371] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:6:0) after 1m0s
[21:30:07.408] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:6:0)
[21:30:07.408] Timer tick, asking Buildbucket for the build status
[21:30:07.498] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:30:07.498] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:7:0) after 1m0s
[21:31:07.520] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:7:0)
[21:31:07.520] Timer tick, asking Buildbucket for the build status
[21:31:07.630] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:31:07.630] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:8:0) after 1m0s
[21:32:07.719] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:8:0)
[21:32:07.719] Timer tick, asking Buildbucket for the build status
[21:32:07.846] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:32:07.846] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:9:0) after 1m0s
[21:33:07.918] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:9:0)
[21:33:07.918] Timer tick, asking Buildbucket for the build status
[21:33:08.058] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:33:08.058] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:10:0) after 1m0s
[21:34:08.240] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:10:0)
[21:34:08.240] Timer tick, asking Buildbucket for the build status
[21:34:08.372] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:34:08.372] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:11:0) after 1m0s
[21:35:08.421] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:11:0)
[21:35:08.421] Timer tick, asking Buildbucket for the build status
[21:35:08.521] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:35:08.521] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:12:0) after 1m0s
[21:36:08.648] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:12:0)
[21:36:08.648] Timer tick, asking Buildbucket for the build status
[21:36:08.767] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:36:08.767] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:13:0) after 1m0s
[21:37:08.868] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:13:0)
[21:37:08.868] Timer tick, asking Buildbucket for the build status
[21:37:08.986] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:37:08.986] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:14:0) after 1m0s
[21:38:09.066] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:14:0)
[21:38:09.066] Timer tick, asking Buildbucket for the build status
[21:38:09.209] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:38:09.209] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:15:0) after 1m0s
[21:39:09.294] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:15:0)
[21:39:09.294] Timer tick, asking Buildbucket for the build status
[21:39:09.402] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:39:09.402] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:16:0) after 1m0s
[21:40:09.537] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:16:0)
[21:40:09.537] Timer tick, asking Buildbucket for the build status
[21:40:09.612] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:40:09.612] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:17:0) after 1m0s
[21:41:09.704] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:17:0)
[21:41:09.704] Timer tick, asking Buildbucket for the build status
[21:41:09.807] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:41:09.807] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:18:0) after 1m0s
[21:42:09.911] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:18:0)
[21:42:09.911] Timer tick, asking Buildbucket for the build status
[21:42:10.010] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:42:10.010] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:19:0) after 1m0s
[21:43:10.139] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:19:0)
[21:43:10.139] Timer tick, asking Buildbucket for the build status
[21:43:10.258] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:43:10.258] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:20:0) after 1m0s
[21:44:10.395] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:20:0)
[21:44:10.395] Timer tick, asking Buildbucket for the build status
[21:44:10.496] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:44:10.496] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:21:0) after 1m0s
[21:45:10.533] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:21:0)
[21:45:10.533] Timer tick, asking Buildbucket for the build status
[21:45:10.668] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:45:10.668] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:22:0) after 1m0s
[21:46:10.704] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:22:0)
[21:46:10.704] Timer tick, asking Buildbucket for the build status
[21:46:10.871] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:46:10.871] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:23:0) after 1m0s
[21:47:10.926] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:23:0)
[21:47:10.926] Timer tick, asking Buildbucket for the build status
[21:47:11.002] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:47:11.002] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:24:0) after 1m0s
[21:48:11.025] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:24:0)
[21:48:11.025] Timer tick, asking Buildbucket for the build status
[21:48:11.122] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:48:11.122] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:25:0) after 1m0s
[21:49:11.161] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:25:0)
[21:49:11.162] Timer tick, asking Buildbucket for the build status
[21:49:11.275] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:49:11.275] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:26:0) after 1m0s
[21:50:11.312] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:26:0)
[21:50:11.312] Timer tick, asking Buildbucket for the build status
[21:50:11.420] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:50:11.420] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:27:0) after 1m0s
[21:51:11.465] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:27:0)
[21:51:11.465] Timer tick, asking Buildbucket for the build status
[21:51:11.627] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:51:11.627] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:28:0) after 1m0s
[21:52:11.688] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:28:0)
[21:52:11.688] Timer tick, asking Buildbucket for the build status
[21:52:11.801] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:52:11.801] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:29:0) after 1m0s
[21:53:11.828] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:29:0)
[21:53:11.828] Timer tick, asking Buildbucket for the build status
[21:53:11.966] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:53:11.966] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:30:0) after 1m0s
[21:54:11.988] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:30:0)
[21:54:11.988] Timer tick, asking Buildbucket for the build status
[21:54:12.077] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:54:12.078] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:31:0) after 1m0s
[21:55:12.105] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:31:0)
[21:55:12.105] Timer tick, asking Buildbucket for the build status
[21:55:12.292] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:55:12.292] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:32:0) after 1m0s
[21:56:12.323] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:32:0)
[21:56:12.323] Timer tick, asking Buildbucket for the build status
[21:56:12.461] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:56:12.461] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:33:0) after 1m0s
[21:57:12.482] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:33:0)
[21:57:12.482] Timer tick, asking Buildbucket for the build status
[21:57:12.620] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:57:12.620] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:34:0) after 1m0s
[21:58:12.683] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:34:0)
[21:58:12.683] Timer tick, asking Buildbucket for the build status
[21:58:12.846] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:58:12.846] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:35:0) after 1m0s
[21:59:12.940] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:35:0)
[21:59:12.940] Timer tick, asking Buildbucket for the build status
[21:59:13.035] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:59:13.035] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:36:0) after 1m0s
[22:00:13.203] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:36:0)
[22:00:13.203] Timer tick, asking Buildbucket for the build status
[22:00:13.418] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:00:13.418] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:37:0) after 1m0s
[22:01:13.491] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:37:0)
[22:01:13.491] Timer tick, asking Buildbucket for the build status
[22:01:13.611] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:01:13.611] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:38:0) after 1m0s
[22:02:13.629] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:38:0)
[22:02:13.629] Timer tick, asking Buildbucket for the build status
[22:02:13.753] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:02:13.753] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:39:0) after 1m0s
[22:03:13.772] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:39:0)
[22:03:13.772] Timer tick, asking Buildbucket for the build status
[22:03:13.856] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:03:13.856] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:40:0) after 1m0s
[22:04:13.888] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:40:0)
[22:04:13.888] Timer tick, asking Buildbucket for the build status
[22:04:14.027] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:04:14.027] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:41:0) after 1m0s
[22:05:14.060] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:41:0)
[22:05:14.060] Timer tick, asking Buildbucket for the build status
[22:05:14.229] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:05:14.229] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:42:0) after 1m0s
[22:06:14.292] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:42:0)
[22:06:14.292] Timer tick, asking Buildbucket for the build status
[22:06:14.482] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:06:14.482] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:43:0) after 1m0s
[22:07:14.560] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:43:0)
[22:07:14.560] Timer tick, asking Buildbucket for the build status
[22:07:14.659] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:07:14.659] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:44:0) after 1m0s
[22:08:14.926] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:44:0)
[22:08:14.926] Timer tick, asking Buildbucket for the build status
[22:08:15.072] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:08:15.072] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:45:0) after 1m0s
[22:09:15.212] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:45:0)
[22:09:15.212] Timer tick, asking Buildbucket for the build status
[22:09:15.338] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:09:15.338] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:46:0) after 1m0s
[22:10:15.469] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:46:0)
[22:10:15.469] Timer tick, asking Buildbucket for the build status
[22:10:15.566] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:10:15.566] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:47:0) after 1m0s
[22:11:15.690] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:47:0)
[22:11:15.690] Timer tick, asking Buildbucket for the build status
[22:11:15.799] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:11:15.799] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:48:0) after 1m0s
[22:12:15.857] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:48:0)
[22:12:15.857] Timer tick, asking Buildbucket for the build status
[22:12:15.960] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:12:15.960] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:49:0) after 1m0s
[22:13:16.040] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:49:0)
[22:13:16.040] Timer tick, asking Buildbucket for the build status
[22:13:16.141] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:13:16.141] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:50:0) after 1m0s
[22:14:16.270] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:50:0)
[22:14:16.270] Timer tick, asking Buildbucket for the build status
[22:14:16.375] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:14:16.375] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:51:0) after 1m0s
[22:15:16.395] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:51:0)
[22:15:16.395] Timer tick, asking Buildbucket for the build status
[22:15:16.493] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:15:16.493] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:52:0) after 1m0s
[22:16:16.513] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:52:0)
[22:16:16.513] Timer tick, asking Buildbucket for the build status
[22:16:16.648] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:16:16.648] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:53:0) after 1m0s
[22:17:16.675] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:53:0)
[22:17:16.675] Timer tick, asking Buildbucket for the build status
[22:17:16.766] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:17:16.766] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:54:0) after 1m0s
[22:18:16.788] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:54:0)
[22:18:16.788] Timer tick, asking Buildbucket for the build status
[22:18:16.958] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:18:16.959] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:55:0) after 1m0s
[22:19:16.979] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:55:0)
[22:19:16.979] Timer tick, asking Buildbucket for the build status
[22:19:17.075] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:19:17.075] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:56:0) after 1m0s
[22:20:17.103] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:56:0)
[22:20:17.103] Timer tick, asking Buildbucket for the build status
[22:20:17.222] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:20:17.222] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:57:0) after 1m0s
[22:21:17.273] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:57:0)
[22:21:17.273] Timer tick, asking Buildbucket for the build status
[22:21:17.406] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:21:17.406] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:58:0) after 1m0s
[22:22:17.447] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:58:0)
[22:22:17.447] Timer tick, asking Buildbucket for the build status
[22:22:17.528] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:22:17.528] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:59:0) after 1m0s
[22:23:17.567] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:59:0)
[22:23:17.567] Timer tick, asking Buildbucket for the build status
[22:23:17.676] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:23:17.676] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:60:0) after 1m0s
[22:24:17.707] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:60:0)
[22:24:17.707] Timer tick, asking Buildbucket for the build status
[22:24:17.805] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:24:17.805] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:61:0) after 1m0s
[22:25:17.926] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:61:0)
[22:25:17.926] Timer tick, asking Buildbucket for the build status
[22:25:18.064] Build 8931025372118883072: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[22:25:18.065] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9096455434423952736:62:0) after 1m0s
[22:26:03.907] Received PubSub notification, asking Buildbucket for the build status
[22:26:03.961] Build 8931025372118883072: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[22:26:03.961] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1541111162788158",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1541107505645641",
"id": "8931025372118883072",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"bbd1466adbd8cdfc5efb42296adaa76add6fcd62\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"bot_dimensions\": {}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1541111163190752",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/5240",
"builder:infra-continuous-win10-64",
"buildset:commit/git/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9096455434423952736",
"scheduler_job_id:infra/infra-continuous-win10-64",
"swarming_dimension:caches:builder_82ed111fed7ea8169e482f00b5f3e5338a65daa41208585de67cb0a736b1d538_v2",
"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/5240",
"swarming_tag:buildbucket_bucket:infra/ci",
"swarming_tag:buildbucket_build_id:8931025372118883072",
"swarming_tag:buildbucket_hostname:cr-buildbucket-dev.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:08e7af934650e940d8457d1ecdec69bcaa595f34",
"swarming_tag:builder:infra-continuous-win10-64",
"swarming_tag:buildset:commit/git/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/bbd1466adbd8cdfc5efb42296adaa76add6fcd62",
"swarming_tag:caches:builder_82ed111fed7ea8169e482f00b5f3e5338a65daa41208585de67cb0a736b1d538_v2",
"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/8931025372118883072/+/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",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/infra/infra",
"swarming_tag:scheduler_invocation_id:9096455434423952736",
"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:swarming.pool.template:prod",
"swarming_tag:swarming.pool.version:daeae5401f149f52d36ed73afd144ba12bc7c77b",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler-dev",
"swarming_task_id:40e9fbe4223a0610",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1541111163191508",
"url": "https://luci-milo-dev.appspot.com/b/8931025372118883072",
"utcnow_ts": "1541111163949360"
}
}
[22:26:03.961] Invocation finished in 1h0m59.897844473s with status FAILED