[00:28:04.379] New invocation is queued and will start shortly
[00:28:05.728] Starting the invocation (attempt 1)
[00:28:05.758] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[00:28:05.760] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[00:28:05.760] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111754808065801472",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"626d8187f96d3c576d30e15730ce5647a059a7ea\"}}",
"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:9111754808065801472",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/626d8187f96d3c576d30e15730ce5647a059a7ea",
"gitiles_ref:refs/heads/master"
]
}
[00:28:06.538] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526516885831690",
"id": "8946324745880830320",
"lease_expiration_ts": "1526525886250290",
"lease_key": "1142207015",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"626d8187f96d3c576d30e15730ce5647a059a7ea\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526516886363030",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2398",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/626d8187f96d3c576d30e15730ce5647a059a7ea",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111754808065801472",
"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/2398",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946324745880830320",
"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/+/626d8187f96d3c576d30e15730ce5647a059a7ea",
"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/8946324745880830320/+/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:9111754808065801472",
"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:3d8450b244f71110",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526516886363050",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2398",
"utcnow_ts": "1526516886434340"
}
}
[00:28:06.538] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2398
[00:28:06.538] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:2:0) after 1m0s
[00:29:06.664] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:2:0)
[00:29:06.664] Timer tick, asking Buildbucket for the build status
[00:29:06.816] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:29:06.816] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:3:0) after 1m0s
[00:30:07.676] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:3:0)
[00:30:07.676] Timer tick, asking Buildbucket for the build status
[00:30:07.792] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:30:07.792] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:4:0) after 1m0s
[00:31:07.891] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:4:0)
[00:31:07.891] Timer tick, asking Buildbucket for the build status
[00:31:07.987] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:31:07.987] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:5:0) after 1m0s
[00:32:08.060] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:5:0)
[00:32:08.060] Timer tick, asking Buildbucket for the build status
[00:32:08.191] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:32:08.191] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:6:0) after 1m0s
[00:33:08.209] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:6:0)
[00:33:08.209] Timer tick, asking Buildbucket for the build status
[00:33:08.284] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:33:08.284] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:7:0) after 1m0s
[00:34:08.437] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:7:0)
[00:34:08.437] Timer tick, asking Buildbucket for the build status
[00:34:08.635] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:34:08.635] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:8:0) after 1m0s
[00:35:08.767] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:8:0)
[00:35:08.767] Timer tick, asking Buildbucket for the build status
[00:35:08.879] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:35:08.879] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:9:0) after 1m0s
[00:36:08.976] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:9:0)
[00:36:08.976] Timer tick, asking Buildbucket for the build status
[00:36:09.089] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:36:09.089] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:10:0) after 1m0s
[00:37:09.204] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:10:0)
[00:37:09.204] Timer tick, asking Buildbucket for the build status
[00:37:09.287] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:37:09.287] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:11:0) after 1m0s
[00:38:09.359] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:11:0)
[00:38:09.360] Timer tick, asking Buildbucket for the build status
[00:38:09.587] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:38:09.587] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:12:0) after 1m0s
[00:39:09.685] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:12:0)
[00:39:09.685] Timer tick, asking Buildbucket for the build status
[00:39:09.771] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:39:09.771] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:13:0) after 1m0s
[00:40:09.992] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:13:0)
[00:40:09.992] Timer tick, asking Buildbucket for the build status
[00:40:10.319] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:40:10.319] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:14:0) after 1m0s
[00:41:10.595] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:14:0)
[00:41:10.595] Timer tick, asking Buildbucket for the build status
[00:41:10.955] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:41:10.955] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:15:0) after 1m0s
[00:42:11.005] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:15:0)
[00:42:11.005] Timer tick, asking Buildbucket for the build status
[00:42:11.339] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:42:11.339] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:16:0) after 1m0s
[00:43:11.499] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:16:0)
[00:43:11.499] Timer tick, asking Buildbucket for the build status
[00:43:11.863] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:43:11.863] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:17:0) after 1m0s
[00:44:11.900] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:17:0)
[00:44:11.900] Timer tick, asking Buildbucket for the build status
[00:44:12.220] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:44:12.220] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:18:0) after 1m0s
[00:45:12.343] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:18:0)
[00:45:12.343] Timer tick, asking Buildbucket for the build status
[00:45:12.785] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:45:12.785] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:19:0) after 1m0s
[00:46:12.924] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:19:0)
[00:46:12.924] Timer tick, asking Buildbucket for the build status
[00:46:13.360] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:46:13.360] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:20:0) after 1m0s
[00:47:13.481] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:20:0)
[00:47:13.481] Timer tick, asking Buildbucket for the build status
[00:47:13.865] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:47:13.865] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:21:0) after 1m0s
[00:48:13.894] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:21:0)
[00:48:13.894] Timer tick, asking Buildbucket for the build status
[00:48:14.243] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:48:14.243] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:22:0) after 1m0s
[00:49:14.266] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:22:0)
[00:49:14.266] Timer tick, asking Buildbucket for the build status
[00:49:14.797] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:49:14.798] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:23:0) after 1m0s
[00:50:14.818] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:23:0)
[00:50:14.818] Timer tick, asking Buildbucket for the build status
[00:50:15.080] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:50:15.080] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:24:0) after 1m0s
[00:51:15.144] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:24:0)
[00:51:15.144] Timer tick, asking Buildbucket for the build status
[00:51:15.315] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:51:15.315] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:25:0) after 1m0s
[00:52:15.543] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:25:0)
[00:52:15.543] Timer tick, asking Buildbucket for the build status
[00:52:15.678] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:52:15.678] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:26:0) after 1m0s
[00:53:15.739] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:26:0)
[00:53:15.739] Timer tick, asking Buildbucket for the build status
[00:53:15.886] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:53:15.886] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:27:0) after 1m0s
[00:54:16.019] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:27:0)
[00:54:16.019] Timer tick, asking Buildbucket for the build status
[00:54:16.128] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:54:16.128] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:28:0) after 1m0s
[00:55:16.247] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:28:0)
[00:55:16.247] Timer tick, asking Buildbucket for the build status
[00:55:16.385] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:55:16.385] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:29:0) after 1m0s
[00:56:16.608] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:29:0)
[00:56:16.608] Timer tick, asking Buildbucket for the build status
[00:56:16.701] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:56:16.701] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:30:0) after 1m0s
[00:57:16.823] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:30:0)
[00:57:16.823] Timer tick, asking Buildbucket for the build status
[00:57:16.958] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:57:16.958] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:31:0) after 1m0s
[00:58:17.159] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:31:0)
[00:58:17.159] Timer tick, asking Buildbucket for the build status
[00:58:17.275] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:58:17.275] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:32:0) after 1m0s
[00:59:17.357] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:32:0)
[00:59:17.357] Timer tick, asking Buildbucket for the build status
[00:59:17.488] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:59:17.488] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:33:0) after 1m0s
[01:00:17.612] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:33:0)
[01:00:17.612] Timer tick, asking Buildbucket for the build status
[01:00:17.727] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:00:17.727] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:34:0) after 1m0s
[01:01:17.952] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:34:0)
[01:01:17.952] Timer tick, asking Buildbucket for the build status
[01:01:18.096] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:01:18.096] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:35:0) after 1m0s
[01:02:18.185] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:35:0)
[01:02:18.185] Timer tick, asking Buildbucket for the build status
[01:02:18.302] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:02:18.302] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:36:0) after 1m0s
[01:03:18.334] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:36:0)
[01:03:18.334] Timer tick, asking Buildbucket for the build status
[01:03:18.474] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:03:18.474] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:37:0) after 1m0s
[01:04:18.504] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:37:0)
[01:04:18.504] Timer tick, asking Buildbucket for the build status
[01:04:18.595] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:04:18.595] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:38:0) after 1m0s
[01:05:18.693] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:38:0)
[01:05:18.693] Timer tick, asking Buildbucket for the build status
[01:05:18.788] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:05:18.788] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:39:0) after 1m0s
[01:06:18.928] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:39:0)
[01:06:18.928] Timer tick, asking Buildbucket for the build status
[01:06:19.008] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:06:19.008] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:40:0) after 1m0s
[01:07:19.193] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:40:0)
[01:07:19.193] Timer tick, asking Buildbucket for the build status
[01:07:19.301] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:07:19.301] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:41:0) after 1m0s
[01:08:19.358] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:41:0)
[01:08:19.358] Timer tick, asking Buildbucket for the build status
[01:08:19.483] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:08:19.483] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:42:0) after 1m0s
[01:09:19.711] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:42:0)
[01:09:19.711] Timer tick, asking Buildbucket for the build status
[01:09:19.816] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:09:19.816] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:43:0) after 1m0s
[01:10:19.876] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:43:0)
[01:10:19.876] Timer tick, asking Buildbucket for the build status
[01:10:19.978] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:10:19.978] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:44:0) after 1m0s
[01:11:20.253] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:44:0)
[01:11:20.253] Timer tick, asking Buildbucket for the build status
[01:11:20.541] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:11:20.541] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:45:0) after 1m0s
[01:12:20.634] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:45:0)
[01:12:20.634] Timer tick, asking Buildbucket for the build status
[01:12:20.790] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:12:20.790] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:46:0) after 1m0s
[01:13:20.920] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:46:0)
[01:13:20.920] Timer tick, asking Buildbucket for the build status
[01:13:21.011] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:13:21.011] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:47:0) after 1m0s
[01:14:21.235] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:47:0)
[01:14:21.235] Timer tick, asking Buildbucket for the build status
[01:14:21.335] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:14:21.335] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:48:0) after 1m0s
[01:15:21.389] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:48:0)
[01:15:21.389] Timer tick, asking Buildbucket for the build status
[01:15:21.524] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:15:21.524] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:49:0) after 1m0s
[01:16:21.655] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:49:0)
[01:16:21.655] Timer tick, asking Buildbucket for the build status
[01:16:21.793] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:16:21.793] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:50:0) after 1m0s
[01:17:21.928] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:50:0)
[01:17:21.928] Timer tick, asking Buildbucket for the build status
[01:17:22.057] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:17:22.057] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:51:0) after 1m0s
[01:18:22.178] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:51:0)
[01:18:22.178] Timer tick, asking Buildbucket for the build status
[01:18:22.315] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:18:22.315] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:52:0) after 1m0s
[01:19:22.521] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:52:0)
[01:19:22.521] Timer tick, asking Buildbucket for the build status
[01:19:22.681] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:19:22.681] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:53:0) after 1m0s
[01:20:22.820] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:53:0)
[01:20:22.820] Timer tick, asking Buildbucket for the build status
[01:20:22.942] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:20:22.942] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:54:0) after 1m0s
[01:21:23.071] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:54:0)
[01:21:23.071] Timer tick, asking Buildbucket for the build status
[01:21:23.211] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:21:23.212] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:55:0) after 1m0s
[01:22:23.419] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:55:0)
[01:22:23.419] Timer tick, asking Buildbucket for the build status
[01:22:23.503] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:22:23.503] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:56:0) after 1m0s
[01:23:23.580] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:56:0)
[01:23:23.580] Timer tick, asking Buildbucket for the build status
[01:23:23.687] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:23:23.687] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:57:0) after 1m0s
[01:24:23.823] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:57:0)
[01:24:23.823] Timer tick, asking Buildbucket for the build status
[01:24:23.935] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:24:23.935] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:58:0) after 1m0s
[01:25:24.117] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:58:0)
[01:25:24.117] Timer tick, asking Buildbucket for the build status
[01:25:24.198] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:25:24.198] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:59:0) after 1m0s
[01:26:24.403] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:59:0)
[01:26:24.403] Timer tick, asking Buildbucket for the build status
[01:26:24.495] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:26:24.495] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:60:0) after 1m0s
[01:27:24.582] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:60:0)
[01:27:24.582] Timer tick, asking Buildbucket for the build status
[01:27:24.824] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:27:24.824] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:61:0) after 1m0s
[01:28:24.945] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:61:0)
[01:28:24.945] Timer tick, asking Buildbucket for the build status
[01:28:25.074] Build 8946324745880830320: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:28:25.074] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111754808065801472:62:0) after 1m0s
[01:29:01.805] Received PubSub notification, asking Buildbucket for the build status
[01:29:01.857] Build 8946324745880830320: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[01:29:01.857] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526520540581150",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526516885831690",
"id": "8946324745880830320",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"626d8187f96d3c576d30e15730ce5647a059a7ea\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-17T00:28:06.050600\", \"name\": \"bb-8946324745880830320-infra-infra-continuous-win10-64\", \"task_id\": \"3d8450b244f71110\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2398\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8946324745880830320\", \"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/+/626d8187f96d3c576d30e15730ce5647a059a7ea\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946324745880830320/+/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:9111754808065801472\", \"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-17T01:29:00.581150\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-17T01:29:00.581150\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526520541207680",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2398",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/626d8187f96d3c576d30e15730ce5647a059a7ea",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111754808065801472",
"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/2398",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946324745880830320",
"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/+/626d8187f96d3c576d30e15730ce5647a059a7ea",
"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/8946324745880830320/+/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:9111754808065801472",
"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:3d8450b244f71110",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526520541208390",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2398",
"utcnow_ts": "1526520541838480"
}
}
[01:29:01.857] Invocation finished in 1h0m57.493760713s with status FAILED