[08:35:06.305] New invocation is queued and will start shortly
[08:35:07.577] Starting the invocation (attempt 1)
[08:35:07.613] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[08:35:07.616] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[08:35:07.616] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111633569689666000",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b\"}}",
"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:9111633569689666000",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b",
"gitiles_ref:refs/heads/master"
]
}
[08:35:08.776] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526632507715570",
"id": "8946203507548169888",
"lease_expiration_ts": "1526641508566930",
"lease_key": "986450084",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526632508694360",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2416",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111633569689666000",
"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/2416",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946203507548169888",
"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/+/025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b",
"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/8946203507548169888/+/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:9111633569689666000",
"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:3d8b34f3db33c010",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526632508694380",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2416",
"utcnow_ts": "1526632508764040"
}
}
[08:35:08.776] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2416
[08:35:08.776] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:2:0) after 1m0s
[08:36:08.896] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:2:0)
[08:36:08.896] Timer tick, asking Buildbucket for the build status
[08:36:08.978] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:36:08.978] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:3:0) after 1m0s
[08:37:09.028] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:3:0)
[08:37:09.028] Timer tick, asking Buildbucket for the build status
[08:37:09.163] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:37:09.163] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:4:0) after 1m0s
[08:38:09.208] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:4:0)
[08:38:09.208] Timer tick, asking Buildbucket for the build status
[08:38:09.272] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:38:09.272] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:5:0) after 1m0s
[08:39:09.397] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:5:0)
[08:39:09.397] Timer tick, asking Buildbucket for the build status
[08:39:09.473] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:39:09.473] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:6:0) after 1m0s
[08:40:09.628] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:6:0)
[08:40:09.628] Timer tick, asking Buildbucket for the build status
[08:40:09.753] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:40:09.753] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:7:0) after 1m0s
[08:41:09.816] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:7:0)
[08:41:09.816] Timer tick, asking Buildbucket for the build status
[08:41:09.968] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:41:09.968] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:8:0) after 1m0s
[08:42:10.100] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:8:0)
[08:42:10.100] Timer tick, asking Buildbucket for the build status
[08:42:10.179] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:42:10.179] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:9:0) after 1m0s
[08:43:10.253] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:9:0)
[08:43:10.253] Timer tick, asking Buildbucket for the build status
[08:43:10.369] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:43:10.369] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:10:0) after 1m0s
[08:44:10.517] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:10:0)
[08:44:10.517] Timer tick, asking Buildbucket for the build status
[08:44:10.611] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:44:10.611] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:11:0) after 1m0s
[08:45:10.697] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:11:0)
[08:45:10.697] Timer tick, asking Buildbucket for the build status
[08:45:10.769] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:45:10.769] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:12:0) after 1m0s
[08:46:10.859] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:12:0)
[08:46:10.859] Timer tick, asking Buildbucket for the build status
[08:46:10.973] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:46:10.974] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:13:0) after 1m0s
[08:47:11.043] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:13:0)
[08:47:11.043] Timer tick, asking Buildbucket for the build status
[08:47:11.172] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:47:11.172] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:14:0) after 1m0s
[08:48:11.239] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:14:0)
[08:48:11.239] Timer tick, asking Buildbucket for the build status
[08:48:11.364] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:48:11.364] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:15:0) after 1m0s
[08:49:11.461] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:15:0)
[08:49:11.461] Timer tick, asking Buildbucket for the build status
[08:49:11.582] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:49:11.582] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:16:0) after 1m0s
[08:50:11.612] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:16:0)
[08:50:11.612] Timer tick, asking Buildbucket for the build status
[08:50:11.687] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:50:11.687] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:17:0) after 1m0s
[08:51:11.801] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:17:0)
[08:51:11.801] Timer tick, asking Buildbucket for the build status
[08:51:11.875] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:51:11.875] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:18:0) after 1m0s
[08:52:11.931] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:18:0)
[08:52:11.931] Timer tick, asking Buildbucket for the build status
[08:52:12.076] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:52:12.076] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:19:0) after 1m0s
[08:53:12.252] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:19:0)
[08:53:12.252] Timer tick, asking Buildbucket for the build status
[08:53:12.385] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:53:12.385] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:20:0) after 1m0s
[08:54:12.506] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:20:0)
[08:54:12.506] Timer tick, asking Buildbucket for the build status
[08:54:12.609] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:54:12.609] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:21:0) after 1m0s
[08:55:12.668] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:21:0)
[08:55:12.668] Timer tick, asking Buildbucket for the build status
[08:55:12.800] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:55:12.800] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:22:0) after 1m0s
[08:56:12.918] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:22:0)
[08:56:12.918] Timer tick, asking Buildbucket for the build status
[08:56:13.082] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:56:13.082] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:23:0) after 1m0s
[08:57:13.174] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:23:0)
[08:57:13.174] Timer tick, asking Buildbucket for the build status
[08:57:13.547] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:57:13.547] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:24:0) after 1m0s
[08:58:13.726] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:24:0)
[08:58:13.726] Timer tick, asking Buildbucket for the build status
[08:58:14.121] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:58:14.121] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:25:0) after 1m0s
[08:59:14.163] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:25:0)
[08:59:14.163] Timer tick, asking Buildbucket for the build status
[08:59:14.531] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:59:14.531] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:26:0) after 1m0s
[09:00:14.669] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:26:0)
[09:00:14.669] Timer tick, asking Buildbucket for the build status
[09:00:15.222] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:00:15.222] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:27:0) after 1m0s
[09:01:15.277] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:27:0)
[09:01:15.277] Timer tick, asking Buildbucket for the build status
[09:01:15.632] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:01:15.632] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:28:0) after 1m0s
[09:02:15.813] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:28:0)
[09:02:15.813] Timer tick, asking Buildbucket for the build status
[09:02:16.164] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:02:16.164] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:29:0) after 1m0s
[09:03:16.225] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:29:0)
[09:03:16.225] Timer tick, asking Buildbucket for the build status
[09:03:16.673] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:03:16.674] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:30:0) after 1m0s
[09:04:16.799] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:30:0)
[09:04:16.799] Timer tick, asking Buildbucket for the build status
[09:04:17.141] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:04:17.141] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:31:0) after 1m0s
[09:05:17.352] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:31:0)
[09:05:17.352] Timer tick, asking Buildbucket for the build status
[09:05:17.725] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:05:17.725] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:32:0) after 1m0s
[09:06:17.868] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:32:0)
[09:06:17.868] Timer tick, asking Buildbucket for the build status
[09:06:18.282] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:06:18.282] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:33:0) after 1m0s
[09:07:18.412] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:33:0)
[09:07:18.412] Timer tick, asking Buildbucket for the build status
[09:07:18.705] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:07:18.705] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:34:0) after 1m0s
[09:08:18.809] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:34:0)
[09:08:18.809] Timer tick, asking Buildbucket for the build status
[09:08:19.283] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:08:19.283] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:35:0) after 1m0s
[09:09:19.507] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:35:0)
[09:09:19.507] Timer tick, asking Buildbucket for the build status
[09:09:19.884] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:09:19.884] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:36:0) after 1m0s
[09:10:19.930] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:36:0)
[09:10:19.930] Timer tick, asking Buildbucket for the build status
[09:10:20.303] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:10:20.303] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:37:0) after 1m0s
[09:11:20.587] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:37:0)
[09:11:20.587] Timer tick, asking Buildbucket for the build status
[09:11:20.962] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:11:20.962] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:38:0) after 1m0s
[09:12:21.091] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:38:0)
[09:12:21.091] Timer tick, asking Buildbucket for the build status
[09:12:21.346] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:12:21.346] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:39:0) after 1m0s
[09:13:21.565] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:39:0)
[09:13:21.565] Timer tick, asking Buildbucket for the build status
[09:13:21.915] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:13:21.915] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:40:0) after 1m0s
[09:14:22.037] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:40:0)
[09:14:22.037] Timer tick, asking Buildbucket for the build status
[09:14:22.402] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:14:22.402] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:41:0) after 1m0s
[09:15:22.451] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:41:0)
[09:15:22.451] Timer tick, asking Buildbucket for the build status
[09:15:22.827] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:15:22.827] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:42:0) after 1m0s
[09:16:22.926] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:42:0)
[09:16:22.926] Timer tick, asking Buildbucket for the build status
[09:16:23.293] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:16:23.293] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:43:0) after 1m0s
[09:17:23.429] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:43:0)
[09:17:23.429] Timer tick, asking Buildbucket for the build status
[09:17:23.825] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:17:23.825] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:44:0) after 1m0s
[09:18:23.898] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:44:0)
[09:18:23.898] Timer tick, asking Buildbucket for the build status
[09:18:24.547] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:18:24.547] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:45:0) after 1m0s
[09:19:24.725] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:45:0)
[09:19:24.725] Timer tick, asking Buildbucket for the build status
[09:19:25.110] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:19:25.110] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:46:0) after 1m0s
[09:20:25.167] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:46:0)
[09:20:25.167] Timer tick, asking Buildbucket for the build status
[09:20:25.551] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:20:25.551] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:47:0) after 1m0s
[09:21:25.570] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:47:0)
[09:21:25.570] Timer tick, asking Buildbucket for the build status
[09:21:25.938] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:21:25.938] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:48:0) after 1m0s
[09:22:25.969] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:48:0)
[09:22:25.969] Timer tick, asking Buildbucket for the build status
[09:22:26.277] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:22:26.277] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:49:0) after 1m0s
[09:23:26.294] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:49:0)
[09:23:26.294] Timer tick, asking Buildbucket for the build status
[09:23:26.675] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:23:26.675] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:50:0) after 1m0s
[09:24:26.782] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:50:0)
[09:24:26.782] Timer tick, asking Buildbucket for the build status
[09:24:27.138] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:24:27.138] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:51:0) after 1m0s
[09:25:27.367] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:51:0)
[09:25:27.367] Timer tick, asking Buildbucket for the build status
[09:25:27.767] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:25:27.767] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:52:0) after 1m0s
[09:26:27.948] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:52:0)
[09:26:27.948] Timer tick, asking Buildbucket for the build status
[09:26:28.049] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:26:28.049] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:53:0) after 1m0s
[09:27:28.225] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:53:0)
[09:27:28.225] Timer tick, asking Buildbucket for the build status
[09:27:28.628] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:27:28.628] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:54:0) after 1m0s
[09:28:28.761] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:54:0)
[09:28:28.761] Timer tick, asking Buildbucket for the build status
[09:28:29.095] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:28:29.095] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:55:0) after 1m0s
[09:29:29.311] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:55:0)
[09:29:29.311] Timer tick, asking Buildbucket for the build status
[09:29:29.584] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:29:29.584] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:56:0) after 1m0s
[09:30:29.724] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:56:0)
[09:30:29.724] Timer tick, asking Buildbucket for the build status
[09:30:30.203] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:30:30.203] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:57:0) after 1m0s
[09:31:30.427] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:57:0)
[09:31:30.427] Timer tick, asking Buildbucket for the build status
[09:31:30.826] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:31:30.826] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:58:0) after 1m0s
[09:32:30.856] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:58:0)
[09:32:30.856] Timer tick, asking Buildbucket for the build status
[09:32:31.208] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:32:31.208] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:59:0) after 1m0s
[09:33:31.225] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:59:0)
[09:33:31.225] Timer tick, asking Buildbucket for the build status
[09:33:33.075] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:33:33.075] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:60:0) after 1m0s
[09:34:33.103] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:60:0)
[09:34:33.103] Timer tick, asking Buildbucket for the build status
[09:34:33.417] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:34:33.417] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:61:0) after 1m0s
[09:35:33.554] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:61:0)
[09:35:33.554] Timer tick, asking Buildbucket for the build status
[09:35:33.987] Build 8946203507548169888: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[09:35:33.987] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111633569689666000:62:0) after 1m0s
[09:36:01.743] Received PubSub notification, asking Buildbucket for the build status
[09:36:01.845] Build 8946203507548169888: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[09:36:01.845] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526636160395820",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526632507715570",
"id": "8946203507548169888",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-18T08:35:08.019260\", \"name\": \"bb-8946203507548169888-infra-infra-continuous-win10-64\", \"task_id\": \"3d8b34f3db33c010\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2416\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8946203507548169888\", \"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/+/025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946203507548169888/+/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:9111633569689666000\", \"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\": [\"3555-5027238\"], \"abandoned_ts\": \"2018-05-18T09:36:00.395820\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-18T09:36:00.395820\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526636160984510",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2416",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111633569689666000",
"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/2416",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946203507548169888",
"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/+/025d1ba24e6d8b189d209fbfe4b49e1b8fbb095b",
"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/8946203507548169888/+/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:9111633569689666000",
"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:3d8b34f3db33c010",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526636160985410",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2416",
"utcnow_ts": "1526636161833640"
}
}
[09:36:01.845] Invocation finished in 1h0m55.556346833s with status FAILED