[11:34:16.327] New invocation is queued and will start shortly
[11:34:17.654] Starting the invocation (attempt 1)
[11:34:17.699] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[11:34:17.699] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[11:34:17.699] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111078715718341664",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"4f9f9fc683edcc51583979d4b895c5acbb470887\"}}",
"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:9111078715718341664",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/4f9f9fc683edcc51583979d4b895c5acbb470887",
"gitiles_ref:refs/heads/master"
]
}
[11:34:18.720] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1527161657815070",
"id": "8945648653453638768",
"lease_expiration_ts": "1527170658463930",
"lease_key": "720226272",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"4f9f9fc683edcc51583979d4b895c5acbb470887\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1527161658629940",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2480",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/4f9f9fc683edcc51583979d4b895c5acbb470887",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111078715718341664",
"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/2480",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945648653453638768",
"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/+/4f9f9fc683edcc51583979d4b895c5acbb470887",
"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/8945648653453638768/+/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:9111078715718341664",
"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:3daabf237e715510",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1527161658629950",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2480",
"utcnow_ts": "1527161658709540"
}
}
[11:34:18.720] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2480
[11:34:18.720] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:2:0) after 1m0s
[11:35:18.776] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:2:0)
[11:35:18.776] Timer tick, asking Buildbucket for the build status
[11:35:18.842] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:35:18.842] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:3:0) after 1m0s
[11:36:18.860] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:3:0)
[11:36:18.860] Timer tick, asking Buildbucket for the build status
[11:36:18.960] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:36:18.960] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:4:0) after 1m0s
[11:37:18.988] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:4:0)
[11:37:18.988] Timer tick, asking Buildbucket for the build status
[11:37:19.075] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:37:19.076] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:5:0) after 1m0s
[11:38:19.112] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:5:0)
[11:38:19.112] Timer tick, asking Buildbucket for the build status
[11:38:19.332] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:38:19.332] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:6:0) after 1m0s
[11:39:19.412] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:6:0)
[11:39:19.412] Timer tick, asking Buildbucket for the build status
[11:39:19.780] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:39:19.780] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:7:0) after 1m0s
[11:40:19.799] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:7:0)
[11:40:19.799] Timer tick, asking Buildbucket for the build status
[11:40:19.858] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:40:19.858] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:8:0) after 1m0s
[11:41:19.908] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:8:0)
[11:41:19.908] Timer tick, asking Buildbucket for the build status
[11:41:20.449] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:41:20.449] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:9:0) after 1m0s
[11:42:20.531] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:9:0)
[11:42:20.531] Timer tick, asking Buildbucket for the build status
[11:42:20.955] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:42:20.955] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:10:0) after 1m0s
[11:43:21.027] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:10:0)
[11:43:21.027] Timer tick, asking Buildbucket for the build status
[11:43:21.176] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:43:21.176] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:11:0) after 1m0s
[11:44:21.268] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:11:0)
[11:44:21.268] Timer tick, asking Buildbucket for the build status
[11:44:21.362] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:44:21.362] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:12:0) after 1m0s
[11:45:21.415] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:12:0)
[11:45:21.415] Timer tick, asking Buildbucket for the build status
[11:45:21.549] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:45:21.549] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:13:0) after 1m0s
[11:46:21.699] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:13:0)
[11:46:21.699] Timer tick, asking Buildbucket for the build status
[11:46:22.032] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:46:22.033] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:14:0) after 1m0s
[11:47:22.262] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:14:0)
[11:47:22.262] Timer tick, asking Buildbucket for the build status
[11:47:22.348] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:47:22.348] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:15:0) after 1m0s
[11:48:22.378] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:15:0)
[11:48:22.378] Timer tick, asking Buildbucket for the build status
[11:48:22.444] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:48:22.444] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:16:0) after 1m0s
[11:49:22.567] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:16:0)
[11:49:22.567] Timer tick, asking Buildbucket for the build status
[11:49:22.674] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:49:22.674] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:17:0) after 1m0s
[11:50:22.899] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:17:0)
[11:50:22.899] Timer tick, asking Buildbucket for the build status
[11:50:23.033] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:50:23.033] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:18:0) after 1m0s
[11:51:23.126] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:18:0)
[11:51:23.126] Timer tick, asking Buildbucket for the build status
[11:51:23.280] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:51:23.280] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:19:0) after 1m0s
[11:52:23.500] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:19:0)
[11:52:23.500] Timer tick, asking Buildbucket for the build status
[11:52:23.644] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:52:23.644] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:20:0) after 1m0s
[11:53:23.772] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:20:0)
[11:53:23.772] Timer tick, asking Buildbucket for the build status
[11:53:23.896] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:53:23.896] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:21:0) after 1m0s
[11:54:24.121] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:21:0)
[11:54:24.121] Timer tick, asking Buildbucket for the build status
[11:54:24.230] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:54:24.230] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:22:0) after 1m0s
[11:55:24.284] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:22:0)
[11:55:24.284] Timer tick, asking Buildbucket for the build status
[11:55:24.368] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:55:24.368] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:23:0) after 1m0s
[11:56:24.530] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:23:0)
[11:56:24.530] Timer tick, asking Buildbucket for the build status
[11:56:24.644] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:56:24.644] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:24:0) after 1m0s
[11:57:24.755] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:24:0)
[11:57:24.755] Timer tick, asking Buildbucket for the build status
[11:57:24.844] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:57:24.844] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:25:0) after 1m0s
[11:58:24.932] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:25:0)
[11:58:24.932] Timer tick, asking Buildbucket for the build status
[11:58:25.052] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:58:25.052] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:26:0) after 1m0s
[11:59:25.166] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:26:0)
[11:59:25.166] Timer tick, asking Buildbucket for the build status
[11:59:25.248] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:59:25.248] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:27:0) after 1m0s
[12:00:25.337] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:27:0)
[12:00:25.337] Timer tick, asking Buildbucket for the build status
[12:00:25.453] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:00:25.453] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:28:0) after 1m0s
[12:01:25.578] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:28:0)
[12:01:25.578] Timer tick, asking Buildbucket for the build status
[12:01:25.680] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:01:25.680] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:29:0) after 1m0s
[12:02:25.804] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:29:0)
[12:02:25.804] Timer tick, asking Buildbucket for the build status
[12:02:25.935] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:02:25.935] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:30:0) after 1m0s
[12:03:25.989] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:30:0)
[12:03:25.989] Timer tick, asking Buildbucket for the build status
[12:03:26.150] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:03:26.150] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:31:0) after 1m0s
[12:04:26.278] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:31:0)
[12:04:26.278] Timer tick, asking Buildbucket for the build status
[12:04:26.367] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:04:26.367] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:32:0) after 1m0s
[12:05:26.492] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:32:0)
[12:05:26.492] Timer tick, asking Buildbucket for the build status
[12:05:26.641] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:05:26.642] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:33:0) after 1m0s
[12:06:26.714] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:33:0)
[12:06:26.714] Timer tick, asking Buildbucket for the build status
[12:06:26.854] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:06:26.854] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:34:0) after 1m0s
[12:07:26.979] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:34:0)
[12:07:26.979] Timer tick, asking Buildbucket for the build status
[12:07:27.062] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:07:27.062] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:35:0) after 1m0s
[12:08:27.106] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:35:0)
[12:08:27.106] Timer tick, asking Buildbucket for the build status
[12:08:27.246] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:08:27.246] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:36:0) after 1m0s
[12:09:27.380] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:36:0)
[12:09:27.380] Timer tick, asking Buildbucket for the build status
[12:09:27.464] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:09:27.464] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:37:0) after 1m0s
[12:10:27.588] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:37:0)
[12:10:27.588] Timer tick, asking Buildbucket for the build status
[12:10:27.743] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:10:27.743] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:38:0) after 1m0s
[12:11:27.828] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:38:0)
[12:11:27.828] Timer tick, asking Buildbucket for the build status
[12:11:27.940] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:11:27.941] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:39:0) after 1m0s
[12:12:28.015] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:39:0)
[12:12:28.015] Timer tick, asking Buildbucket for the build status
[12:12:28.136] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:12:28.136] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:40:0) after 1m0s
[12:13:28.230] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:40:0)
[12:13:28.230] Timer tick, asking Buildbucket for the build status
[12:13:28.360] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:13:28.360] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:41:0) after 1m0s
[12:14:28.419] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:41:0)
[12:14:28.419] Timer tick, asking Buildbucket for the build status
[12:14:28.538] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:14:28.538] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:42:0) after 1m0s
[12:15:28.603] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:42:0)
[12:15:28.603] Timer tick, asking Buildbucket for the build status
[12:15:28.746] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:15:28.746] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:43:0) after 1m0s
[12:16:28.849] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:43:0)
[12:16:28.849] Timer tick, asking Buildbucket for the build status
[12:16:28.949] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:16:28.949] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:44:0) after 1m0s
[12:17:29.082] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:44:0)
[12:17:29.082] Timer tick, asking Buildbucket for the build status
[12:17:29.164] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:17:29.164] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:45:0) after 1m0s
[12:18:29.269] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:45:0)
[12:18:29.269] Timer tick, asking Buildbucket for the build status
[12:18:29.361] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:18:29.361] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:46:0) after 1m0s
[12:19:29.419] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:46:0)
[12:19:29.419] Timer tick, asking Buildbucket for the build status
[12:19:29.575] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:19:29.575] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:47:0) after 1m0s
[12:20:29.664] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:47:0)
[12:20:29.664] Timer tick, asking Buildbucket for the build status
[12:20:29.764] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:20:29.764] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:48:0) after 1m0s
[12:21:29.799] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:48:0)
[12:21:29.799] Timer tick, asking Buildbucket for the build status
[12:21:29.930] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:21:29.931] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:49:0) after 1m0s
[12:22:30.251] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:49:0)
[12:22:30.251] Timer tick, asking Buildbucket for the build status
[12:22:30.339] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:22:30.339] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:50:0) after 1m0s
[12:23:30.488] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:50:0)
[12:23:30.488] Timer tick, asking Buildbucket for the build status
[12:23:30.657] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:23:30.657] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:51:0) after 1m0s
[12:24:30.684] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:51:0)
[12:24:30.684] Timer tick, asking Buildbucket for the build status
[12:24:30.765] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:24:30.765] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:52:0) after 1m0s
[12:25:30.785] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:52:0)
[12:25:30.785] Timer tick, asking Buildbucket for the build status
[12:25:30.865] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:25:30.865] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:53:0) after 1m0s
[12:26:30.885] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:53:0)
[12:26:30.885] Timer tick, asking Buildbucket for the build status
[12:26:30.965] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:26:30.965] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:54:0) after 1m0s
[12:27:31.001] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:54:0)
[12:27:31.001] Timer tick, asking Buildbucket for the build status
[12:27:31.134] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:27:31.134] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:55:0) after 1m0s
[12:28:31.159] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:55:0)
[12:28:31.159] Timer tick, asking Buildbucket for the build status
[12:28:31.255] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:28:31.256] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:56:0) after 1m0s
[12:29:31.274] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:56:0)
[12:29:31.274] Timer tick, asking Buildbucket for the build status
[12:29:31.360] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:29:31.360] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:57:0) after 1m0s
[12:30:31.385] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:57:0)
[12:30:31.385] Timer tick, asking Buildbucket for the build status
[12:30:31.469] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:30:31.469] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:58:0) after 1m0s
[12:31:31.529] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:58:0)
[12:31:31.529] Timer tick, asking Buildbucket for the build status
[12:31:31.652] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:31:31.652] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:59:0) after 1m0s
[12:32:31.772] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:59:0)
[12:32:31.772] Timer tick, asking Buildbucket for the build status
[12:32:31.864] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:32:31.864] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:60:0) after 1m0s
[12:33:31.974] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:60:0)
[12:33:31.974] Timer tick, asking Buildbucket for the build status
[12:33:32.057] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:33:32.057] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:61:0) after 1m0s
[12:34:32.165] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:61:0)
[12:34:32.165] Timer tick, asking Buildbucket for the build status
[12:34:32.262] Build 8945648653453638768: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[12:34:32.262] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111078715718341664:62:0) after 1m0s
[12:35:04.061] Received PubSub notification, asking Buildbucket for the build status
[12:35:04.107] Build 8945648653453638768: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[12:35:04.107] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1527165302461160",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1527161657815070",
"id": "8945648653453638768",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"4f9f9fc683edcc51583979d4b895c5acbb470887\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-24T11:34:18.085610\", \"name\": \"bb-8945648653453638768-infra-infra-continuous-win10-64\", \"task_id\": \"3daabf237e715510\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2480\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8945648653453638768\", \"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/+/4f9f9fc683edcc51583979d4b895c5acbb470887\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8945648653453638768/+/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:9111078715718341664\", \"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\": [\"3581-e1f2952\"], \"abandoned_ts\": \"2018-05-24T12:35:02.461160\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-24T12:35:02.461160\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1527165303247350",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2480",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/4f9f9fc683edcc51583979d4b895c5acbb470887",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111078715718341664",
"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/2480",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945648653453638768",
"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/+/4f9f9fc683edcc51583979d4b895c5acbb470887",
"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/8945648653453638768/+/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:9111078715718341664",
"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:3daabf237e715510",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1527165303248340",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2480",
"utcnow_ts": "1527165304093340"
}
}
[12:35:04.107] Invocation finished in 1h0m47.836056732s with status FAILED