[07:56:12.152] New invocation is queued and will start shortly
[07:56:13.444] Starting the invocation (attempt 1)
[07:56:13.477] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[07:56:13.488] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[07:56:13.488] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111183032395009552",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"9fe24bdd978b5139645355c452d54af34a9f28d6\"}}",
"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:9111183032395009552",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/9fe24bdd978b5139645355c452d54af34a9f28d6",
"gitiles_ref:refs/heads/master"
]
}
[07:56:14.210] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1527062173561310",
"id": "8945752970254008576",
"lease_expiration_ts": "1527071173983810",
"lease_key": "1507190662",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"9fe24bdd978b5139645355c452d54af34a9f28d6\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1527062174126650",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2461",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/9fe24bdd978b5139645355c452d54af34a9f28d6",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111183032395009552",
"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/2461",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945752970254008576",
"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/+/9fe24bdd978b5139645355c452d54af34a9f28d6",
"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/8945752970254008576/+/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:9111183032395009552",
"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:3da4d1208edffd10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1527062174126670",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2461",
"utcnow_ts": "1527062174195470"
}
}
[07:56:14.210] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2461
[07:56:14.210] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:2:0) after 1m0s
[07:57:14.322] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:2:0)
[07:57:14.322] Timer tick, asking Buildbucket for the build status
[07:57:14.409] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:57:14.409] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:3:0) after 1m0s
[07:58:14.470] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:3:0)
[07:58:14.470] Timer tick, asking Buildbucket for the build status
[07:58:14.580] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:58:14.580] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:4:0) after 1m0s
[07:59:14.653] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:4:0)
[07:59:14.653] Timer tick, asking Buildbucket for the build status
[07:59:15.033] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:59:15.033] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:5:0) after 1m0s
[08:00:15.144] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:5:0)
[08:00:15.144] Timer tick, asking Buildbucket for the build status
[08:00:15.538] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:00:15.538] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:6:0) after 1m0s
[08:01:15.657] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:6:0)
[08:01:15.657] Timer tick, asking Buildbucket for the build status
[08:01:16.054] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:01:16.054] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:7:0) after 1m0s
[08:02:16.392] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:7:0)
[08:02:16.392] Timer tick, asking Buildbucket for the build status
[08:02:16.704] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:02:16.704] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:8:0) after 1m0s
[08:03:16.871] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:8:0)
[08:03:16.871] Timer tick, asking Buildbucket for the build status
[08:03:17.182] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:03:17.182] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:9:0) after 1m0s
[08:04:17.261] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:9:0)
[08:04:17.261] Timer tick, asking Buildbucket for the build status
[08:04:17.655] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:04:17.655] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:10:0) after 1m0s
[08:05:17.882] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:10:0)
[08:05:17.882] Timer tick, asking Buildbucket for the build status
[08:05:18.196] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:05:18.196] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:11:0) after 1m0s
[08:06:18.239] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:11:0)
[08:06:18.239] Timer tick, asking Buildbucket for the build status
[08:06:18.649] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:06:18.649] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:12:0) after 1m0s
[08:07:18.912] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:12:0)
[08:07:18.912] Timer tick, asking Buildbucket for the build status
[08:07:19.210] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:07:19.210] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:13:0) after 1m0s
[08:08:19.360] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:13:0)
[08:08:19.360] Timer tick, asking Buildbucket for the build status
[08:08:19.758] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:08:19.758] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:14:0) after 1m0s
[08:09:20.018] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:14:0)
[08:09:20.019] Timer tick, asking Buildbucket for the build status
[08:09:20.319] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:09:20.319] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:15:0) after 1m0s
[08:10:20.442] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:15:0)
[08:10:20.442] Timer tick, asking Buildbucket for the build status
[08:10:20.866] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:10:20.866] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:16:0) after 1m0s
[08:11:21.095] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:16:0)
[08:11:21.095] Timer tick, asking Buildbucket for the build status
[08:11:21.497] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:11:21.497] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:17:0) after 1m0s
[08:12:21.621] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:17:0)
[08:12:21.621] Timer tick, asking Buildbucket for the build status
[08:12:21.947] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:12:21.947] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:18:0) after 1m0s
[08:13:22.072] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:18:0)
[08:13:22.072] Timer tick, asking Buildbucket for the build status
[08:13:22.446] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:13:22.446] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:19:0) after 1m0s
[08:14:22.522] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:19:0)
[08:14:22.522] Timer tick, asking Buildbucket for the build status
[08:14:22.834] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:14:22.834] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:20:0) after 1m0s
[08:15:22.940] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:20:0)
[08:15:22.940] Timer tick, asking Buildbucket for the build status
[08:15:23.339] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:15:23.339] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:21:0) after 1m0s
[08:16:23.522] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:21:0)
[08:16:23.522] Timer tick, asking Buildbucket for the build status
[08:16:25.299] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:16:25.299] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:22:0) after 1m0s
[08:17:25.321] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:22:0)
[08:17:25.321] Timer tick, asking Buildbucket for the build status
[08:17:25.693] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:17:25.693] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:23:0) after 1m0s
[08:18:25.746] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:23:0)
[08:18:25.746] Timer tick, asking Buildbucket for the build status
[08:18:26.110] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:18:26.110] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:24:0) after 1m0s
[08:19:26.212] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:24:0)
[08:19:26.212] Timer tick, asking Buildbucket for the build status
[08:19:26.556] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:19:26.556] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:25:0) after 1m0s
[08:20:26.690] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:25:0)
[08:20:26.690] Timer tick, asking Buildbucket for the build status
[08:20:27.059] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:20:27.059] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:26:0) after 1m0s
[08:21:27.089] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:26:0)
[08:21:27.089] Timer tick, asking Buildbucket for the build status
[08:21:27.384] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:21:27.384] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:27:0) after 1m0s
[08:22:27.566] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:27:0)
[08:22:27.566] Timer tick, asking Buildbucket for the build status
[08:22:27.649] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:22:27.649] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:28:0) after 1m0s
[08:23:27.776] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:28:0)
[08:23:27.776] Timer tick, asking Buildbucket for the build status
[08:23:28.090] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:23:28.090] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:29:0) after 1m0s
[08:24:28.224] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:29:0)
[08:24:28.224] Timer tick, asking Buildbucket for the build status
[08:24:28.508] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:24:28.508] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:30:0) after 1m0s
[08:25:28.640] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:30:0)
[08:25:28.640] Timer tick, asking Buildbucket for the build status
[08:25:29.037] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:25:29.037] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:31:0) after 1m0s
[08:26:29.163] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:31:0)
[08:26:29.163] Timer tick, asking Buildbucket for the build status
[08:26:29.558] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:26:29.558] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:32:0) after 1m0s
[08:27:29.617] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:32:0)
[08:27:29.617] Timer tick, asking Buildbucket for the build status
[08:27:29.995] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:27:29.995] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:33:0) after 1m0s
[08:28:30.118] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:33:0)
[08:28:30.118] Timer tick, asking Buildbucket for the build status
[08:28:30.472] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:28:30.472] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:34:0) after 1m0s
[08:29:30.534] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:34:0)
[08:29:30.534] Timer tick, asking Buildbucket for the build status
[08:29:30.923] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:29:30.923] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:35:0) after 1m0s
[08:30:30.973] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:35:0)
[08:30:30.973] Timer tick, asking Buildbucket for the build status
[08:30:31.332] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:30:31.332] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:36:0) after 1m0s
[08:31:31.376] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:36:0)
[08:31:31.376] Timer tick, asking Buildbucket for the build status
[08:31:31.781] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:31:31.781] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:37:0) after 1m0s
[08:32:31.908] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:37:0)
[08:32:31.908] Timer tick, asking Buildbucket for the build status
[08:32:32.223] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:32:32.223] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:38:0) after 1m0s
[08:33:32.329] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:38:0)
[08:33:32.329] Timer tick, asking Buildbucket for the build status
[08:33:32.809] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:33:32.809] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:39:0) after 1m0s
[08:34:32.940] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:39:0)
[08:34:32.940] Timer tick, asking Buildbucket for the build status
[08:34:33.366] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:34:33.366] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:40:0) after 1m0s
[08:35:33.421] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:40:0)
[08:35:33.421] Timer tick, asking Buildbucket for the build status
[08:35:33.818] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:35:33.818] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:41:0) after 1m0s
[08:36:33.915] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:41:0)
[08:36:33.915] Timer tick, asking Buildbucket for the build status
[08:36:34.319] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:36:34.319] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:42:0) after 1m0s
[08:37:34.437] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:42:0)
[08:37:34.437] Timer tick, asking Buildbucket for the build status
[08:37:34.917] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:37:34.917] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:43:0) after 1m0s
[08:38:34.942] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:43:0)
[08:38:34.942] Timer tick, asking Buildbucket for the build status
[08:38:35.342] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:38:35.342] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:44:0) after 1m0s
[08:39:35.467] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:44:0)
[08:39:35.467] Timer tick, asking Buildbucket for the build status
[08:39:35.828] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:39:35.828] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:45:0) after 1m0s
[08:40:36.046] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:45:0)
[08:40:36.046] Timer tick, asking Buildbucket for the build status
[08:40:36.424] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:40:36.424] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:46:0) after 1m0s
[08:41:36.547] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:46:0)
[08:41:36.547] Timer tick, asking Buildbucket for the build status
[08:41:36.930] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:41:36.930] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:47:0) after 1m0s
[08:42:37.161] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:47:0)
[08:42:37.161] Timer tick, asking Buildbucket for the build status
[08:42:37.538] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:42:37.539] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:48:0) after 1m0s
[08:43:37.667] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:48:0)
[08:43:37.667] Timer tick, asking Buildbucket for the build status
[08:43:38.066] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:43:38.066] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:49:0) after 1m0s
[08:44:38.292] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:49:0)
[08:44:38.292] Timer tick, asking Buildbucket for the build status
[08:44:39.406] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:44:39.406] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:50:0) after 1m0s
[08:45:39.518] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:50:0)
[08:45:39.518] Timer tick, asking Buildbucket for the build status
[08:45:39.701] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:45:39.701] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:51:0) after 1m0s
[08:46:39.829] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:51:0)
[08:46:39.829] Timer tick, asking Buildbucket for the build status
[08:46:40.299] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:46:40.299] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:52:0) after 1m0s
[08:47:40.422] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:52:0)
[08:47:40.422] Timer tick, asking Buildbucket for the build status
[08:47:40.882] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:47:40.882] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:53:0) after 1m0s
[08:48:40.929] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:53:0)
[08:48:40.929] Timer tick, asking Buildbucket for the build status
[08:48:41.354] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:48:41.354] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:54:0) after 1m0s
[08:49:41.514] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:54:0)
[08:49:41.514] Timer tick, asking Buildbucket for the build status
[08:49:41.934] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:49:41.934] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:55:0) after 1m0s
[08:50:42.135] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:55:0)
[08:50:42.135] Timer tick, asking Buildbucket for the build status
[08:50:42.851] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:50:42.851] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:56:0) after 1m0s
[08:51:43.761] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:56:0)
[08:51:43.761] Timer tick, asking Buildbucket for the build status
[08:51:44.097] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:51:44.097] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:57:0) after 1m0s
[08:52:44.292] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:57:0)
[08:52:44.292] Timer tick, asking Buildbucket for the build status
[08:52:44.652] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:52:44.652] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:58:0) after 1m0s
[08:53:44.789] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:58:0)
[08:53:44.789] Timer tick, asking Buildbucket for the build status
[08:53:45.132] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:53:45.132] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:59:0) after 1m0s
[08:54:45.250] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:59:0)
[08:54:45.250] Timer tick, asking Buildbucket for the build status
[08:54:45.681] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:54:45.681] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:60:0) after 1m0s
[08:55:45.710] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:60:0)
[08:55:45.710] Timer tick, asking Buildbucket for the build status
[08:55:46.026] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:55:46.026] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:61:0) after 1m0s
[08:56:46.047] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:61:0)
[08:56:46.047] Timer tick, asking Buildbucket for the build status
[08:56:46.489] Build 8945752970254008576: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:56:46.489] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111183032395009552:62:0) after 1m0s
[08:57:03.322] Received PubSub notification, asking Buildbucket for the build status
[08:57:03.457] Build 8945752970254008576: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[08:57:03.457] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1527065821909080",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1527062173561310",
"id": "8945752970254008576",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"9fe24bdd978b5139645355c452d54af34a9f28d6\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-23T07:56:13.759660\", \"name\": \"bb-8945752970254008576-infra-infra-continuous-win10-64\", \"task_id\": \"3da4d1208edffd10\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2461\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8945752970254008576\", \"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/+/9fe24bdd978b5139645355c452d54af34a9f28d6\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8945752970254008576/+/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:9111183032395009552\", \"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\": [\"3569-44f7240\"], \"abandoned_ts\": \"2018-05-23T08:57:01.909080\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-23T08:57:01.909080\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1527065822606150",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2461",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/9fe24bdd978b5139645355c452d54af34a9f28d6",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111183032395009552",
"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/2461",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945752970254008576",
"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/+/9fe24bdd978b5139645355c452d54af34a9f28d6",
"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/8945752970254008576/+/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:9111183032395009552",
"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:3da4d1208edffd10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1527065822607030",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2461",
"utcnow_ts": "1527065823375130"
}
}
[08:57:03.457] Invocation finished in 1h0m51.320819884s with status FAILED