[01:53:10.302] New invocation is queued and will start shortly
[01:53:11.714] Starting the invocation (attempt 1)
[01:53:11.762] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[01:53:11.762] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[01:53:11.762] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9112474229861518368",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"0d8504f69f0b8872da91dcac3f009287973651ac\"}}",
"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:9112474229861518368",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/0d8504f69f0b8872da91dcac3f009287973651ac",
"gitiles_ref:refs/heads/master"
]
}
[01:53:13.367] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1525830791850930",
"id": "8947044167563644464",
"lease_expiration_ts": "1525839793005090",
"lease_key": "857700323",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"0d8504f69f0b8872da91dcac3f009287973651ac\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1525830793274880",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2270",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/0d8504f69f0b8872da91dcac3f009287973651ac",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9112474229861518368",
"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/2270",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8947044167563644464",
"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/+/0d8504f69f0b8872da91dcac3f009287973651ac",
"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/8947044167563644464/+/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:9112474229861518368",
"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:3d5b6bbe96166e10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1525830793274890",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2270",
"utcnow_ts": "1525830793353100"
}
}
[01:53:13.367] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2270
[01:53:13.367] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:2:0) after 1m0s
[01:54:13.393] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:2:0)
[01:54:13.393] Timer tick, asking Buildbucket for the build status
[01:54:13.459] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:54:13.459] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:3:0) after 1m0s
[01:55:13.474] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:3:0)
[01:55:13.474] Timer tick, asking Buildbucket for the build status
[01:55:13.562] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:55:13.562] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:4:0) after 1m0s
[01:56:13.585] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:4:0)
[01:56:13.585] Timer tick, asking Buildbucket for the build status
[01:56:13.637] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:56:13.637] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:5:0) after 1m0s
[01:57:13.661] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:5:0)
[01:57:13.661] Timer tick, asking Buildbucket for the build status
[01:57:13.723] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:57:13.723] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:6:0) after 1m0s
[01:58:13.741] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:6:0)
[01:58:13.741] Timer tick, asking Buildbucket for the build status
[01:58:13.851] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:58:13.851] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:7:0) after 1m0s
[01:59:13.868] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:7:0)
[01:59:13.868] Timer tick, asking Buildbucket for the build status
[01:59:14.147] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:59:14.147] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:8:0) after 1m0s
[02:00:14.249] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:8:0)
[02:00:14.249] Timer tick, asking Buildbucket for the build status
[02:00:14.418] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:00:14.418] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:9:0) after 1m0s
[02:01:14.491] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:9:0)
[02:01:14.491] Timer tick, asking Buildbucket for the build status
[02:01:14.544] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:01:14.544] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:10:0) after 1m0s
[02:02:14.572] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:10:0)
[02:02:14.572] Timer tick, asking Buildbucket for the build status
[02:02:14.650] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:02:14.650] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:11:0) after 1m0s
[02:03:14.672] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:11:0)
[02:03:14.672] Timer tick, asking Buildbucket for the build status
[02:03:14.739] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:03:14.739] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:12:0) after 1m0s
[02:04:14.778] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:12:0)
[02:04:14.778] Timer tick, asking Buildbucket for the build status
[02:04:14.855] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:04:14.855] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:13:0) after 1m0s
[02:05:14.880] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:13:0)
[02:05:14.880] Timer tick, asking Buildbucket for the build status
[02:05:15.040] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:05:15.040] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:14:0) after 1m0s
[02:06:15.057] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:14:0)
[02:06:15.057] Timer tick, asking Buildbucket for the build status
[02:06:15.135] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:06:15.135] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:15:0) after 1m0s
[02:07:15.153] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:15:0)
[02:07:15.153] Timer tick, asking Buildbucket for the build status
[02:07:15.254] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:07:15.254] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:16:0) after 1m0s
[02:08:15.272] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:16:0)
[02:08:15.272] Timer tick, asking Buildbucket for the build status
[02:08:15.353] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:08:15.353] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:17:0) after 1m0s
[02:09:15.372] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:17:0)
[02:09:15.372] Timer tick, asking Buildbucket for the build status
[02:09:15.538] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:09:15.538] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:18:0) after 1m0s
[02:10:15.612] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:18:0)
[02:10:15.612] Timer tick, asking Buildbucket for the build status
[02:10:15.767] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:10:15.767] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:19:0) after 1m0s
[02:11:15.847] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:19:0)
[02:11:15.847] Timer tick, asking Buildbucket for the build status
[02:11:16.059] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:11:16.059] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:20:0) after 1m0s
[02:12:16.113] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:20:0)
[02:12:16.113] Timer tick, asking Buildbucket for the build status
[02:12:16.227] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:12:16.227] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:21:0) after 1m0s
[02:13:16.316] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:21:0)
[02:13:16.316] Timer tick, asking Buildbucket for the build status
[02:13:16.466] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:13:16.466] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:22:0) after 1m0s
[02:14:16.548] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:22:0)
[02:14:16.548] Timer tick, asking Buildbucket for the build status
[02:14:16.635] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:14:16.635] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:23:0) after 1m0s
[02:15:16.750] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:23:0)
[02:15:16.750] Timer tick, asking Buildbucket for the build status
[02:15:16.985] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:15:16.985] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:24:0) after 1m0s
[02:16:17.091] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:24:0)
[02:16:17.091] Timer tick, asking Buildbucket for the build status
[02:16:17.472] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:16:17.472] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:25:0) after 1m0s
[02:17:17.488] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:25:0)
[02:17:17.488] Timer tick, asking Buildbucket for the build status
[02:17:17.716] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:17:17.716] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:26:0) after 1m0s
[02:18:17.733] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:26:0)
[02:18:17.733] Timer tick, asking Buildbucket for the build status
[02:18:17.883] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:18:17.883] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:27:0) after 1m0s
[02:19:17.903] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:27:0)
[02:19:17.903] Timer tick, asking Buildbucket for the build status
[02:19:18.022] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:19:18.023] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:28:0) after 1m0s
[02:20:18.130] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:28:0)
[02:20:18.130] Timer tick, asking Buildbucket for the build status
[02:20:18.279] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:20:18.279] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:29:0) after 1m0s
[02:21:18.363] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:29:0)
[02:21:18.363] Timer tick, asking Buildbucket for the build status
[02:21:18.620] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:21:18.620] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:30:0) after 1m0s
[02:22:18.707] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:30:0)
[02:22:18.707] Timer tick, asking Buildbucket for the build status
[02:22:18.882] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:22:18.882] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:31:0) after 1m0s
[02:23:18.936] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:31:0)
[02:23:18.936] Timer tick, asking Buildbucket for the build status
[02:23:19.090] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:23:19.090] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:32:0) after 1m0s
[02:24:19.249] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:32:0)
[02:24:19.249] Timer tick, asking Buildbucket for the build status
[02:24:19.495] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:24:19.495] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:33:0) after 1m0s
[02:25:19.640] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:33:0)
[02:25:19.640] Timer tick, asking Buildbucket for the build status
[02:25:19.808] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:25:19.808] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:34:0) after 1m0s
[02:26:19.862] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:34:0)
[02:26:19.862] Timer tick, asking Buildbucket for the build status
[02:26:20.248] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:26:20.248] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:35:0) after 1m0s
[02:27:20.360] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:35:0)
[02:27:20.360] Timer tick, asking Buildbucket for the build status
[02:27:20.483] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:27:20.483] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:36:0) after 1m0s
[02:28:20.545] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:36:0)
[02:28:20.545] Timer tick, asking Buildbucket for the build status
[02:28:20.678] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:28:20.678] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:37:0) after 1m0s
[02:29:20.705] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:37:0)
[02:29:20.705] Timer tick, asking Buildbucket for the build status
[02:29:20.878] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:29:20.878] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:38:0) after 1m0s
[02:30:20.895] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:38:0)
[02:30:20.895] Timer tick, asking Buildbucket for the build status
[02:30:21.106] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:30:21.106] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:39:0) after 1m0s
[02:31:21.239] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:39:0)
[02:31:21.239] Timer tick, asking Buildbucket for the build status
[02:31:21.409] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:31:21.409] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:40:0) after 1m0s
[02:32:21.428] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:40:0)
[02:32:21.428] Timer tick, asking Buildbucket for the build status
[02:32:21.570] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:32:21.570] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:41:0) after 1m0s
[02:33:21.598] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:41:0)
[02:33:21.598] Timer tick, asking Buildbucket for the build status
[02:33:21.790] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:33:21.790] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:42:0) after 1m0s
[02:34:21.901] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:42:0)
[02:34:21.901] Timer tick, asking Buildbucket for the build status
[02:34:22.152] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:34:22.152] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:43:0) after 1m0s
[02:35:22.251] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:43:0)
[02:35:22.251] Timer tick, asking Buildbucket for the build status
[02:35:22.357] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:35:22.357] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:44:0) after 1m0s
[02:36:22.575] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:44:0)
[02:36:22.575] Timer tick, asking Buildbucket for the build status
[02:36:22.654] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:36:22.654] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:45:0) after 1m0s
[02:37:22.675] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:45:0)
[02:37:22.675] Timer tick, asking Buildbucket for the build status
[02:37:23.005] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:37:23.005] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:46:0) after 1m0s
[02:38:23.030] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:46:0)
[02:38:23.030] Timer tick, asking Buildbucket for the build status
[02:38:23.181] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:38:23.181] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:47:0) after 1m0s
[02:39:23.302] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:47:0)
[02:39:23.302] Timer tick, asking Buildbucket for the build status
[02:39:23.496] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:39:23.496] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:48:0) after 1m0s
[02:40:23.529] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:48:0)
[02:40:23.529] Timer tick, asking Buildbucket for the build status
[02:40:23.685] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:40:23.685] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:49:0) after 1m0s
[02:41:23.710] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:49:0)
[02:41:23.710] Timer tick, asking Buildbucket for the build status
[02:41:23.908] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:41:23.909] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:50:0) after 1m0s
[02:42:24.023] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:50:0)
[02:42:24.023] Timer tick, asking Buildbucket for the build status
[02:42:24.265] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:42:24.265] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:51:0) after 1m0s
[02:43:24.292] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:51:0)
[02:43:24.292] Timer tick, asking Buildbucket for the build status
[02:43:24.408] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:43:24.408] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:52:0) after 1m0s
[02:44:24.627] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:52:0)
[02:44:24.627] Timer tick, asking Buildbucket for the build status
[02:44:24.729] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:44:24.729] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:53:0) after 1m0s
[02:45:24.770] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:53:0)
[02:45:24.770] Timer tick, asking Buildbucket for the build status
[02:45:24.905] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:45:24.905] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:54:0) after 1m0s
[02:46:25.028] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:54:0)
[02:46:25.028] Timer tick, asking Buildbucket for the build status
[02:46:25.115] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:46:25.115] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:55:0) after 1m0s
[02:47:25.221] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:55:0)
[02:47:25.222] Timer tick, asking Buildbucket for the build status
[02:47:25.309] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:47:25.309] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:56:0) after 1m0s
[02:48:25.436] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:56:0)
[02:48:25.436] Timer tick, asking Buildbucket for the build status
[02:48:25.607] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:48:25.607] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:57:0) after 1m0s
[02:49:25.645] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:57:0)
[02:49:25.645] Timer tick, asking Buildbucket for the build status
[02:49:25.837] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:49:25.837] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:58:0) after 1m0s
[02:50:25.923] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:58:0)
[02:50:25.923] Timer tick, asking Buildbucket for the build status
[02:50:25.990] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:50:25.990] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:59:0) after 1m0s
[02:51:26.058] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:59:0)
[02:51:26.058] Timer tick, asking Buildbucket for the build status
[02:51:26.276] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:51:26.276] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:60:0) after 1m0s
[02:52:26.378] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:60:0)
[02:52:26.378] Timer tick, asking Buildbucket for the build status
[02:52:26.517] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:52:26.517] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:61:0) after 1m0s
[02:53:26.554] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:61:0)
[02:53:26.554] Timer tick, asking Buildbucket for the build status
[02:53:26.690] Build 8947044167563644464: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[02:53:26.690] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9112474229861518368:62:0) after 1m0s
[02:54:06.062] Received PubSub notification, asking Buildbucket for the build status
[02:54:06.105] Build 8947044167563644464: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[02:54:06.105] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1525834442934940",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1525830791850930",
"id": "8947044167563644464",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"0d8504f69f0b8872da91dcac3f009287973651ac\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-09T01:53:12.413020\", \"name\": \"bb-8947044167563644464-infra-infra-continuous-win10-64\", \"task_id\": \"3d5b6bbe96166e10\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2270\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8947044167563644464\", \"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/+/0d8504f69f0b8872da91dcac3f009287973651ac\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8947044167563644464/+/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:9112474229861518368\", \"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\": [\"3520-3eb90da-tainted-smut\"], \"abandoned_ts\": \"2018-05-09T02:54:02.934940\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-09T02:54:02.934940\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1525834444324690",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2270",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/0d8504f69f0b8872da91dcac3f009287973651ac",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9112474229861518368",
"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/2270",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8947044167563644464",
"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/+/0d8504f69f0b8872da91dcac3f009287973651ac",
"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/8947044167563644464/+/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:9112474229861518368",
"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:3d5b6bbe96166e10",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1525834444326770",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2270",
"utcnow_ts": "1525834446094650"
}
}
[02:54:06.105] Invocation finished in 1h0m55.830628088s with status FAILED