[07:34:00.275] New invocation is queued and will start shortly
[07:34:01.630] Starting the invocation (attempt 1)
[07:34:01.685] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[07:34:01.701] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[07:34:01.701] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111637413801025392",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"f3f09e0bb12e8aaf1d627bd605f34db780811199\"}}",
"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:9111637413801025392",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/f3f09e0bb12e8aaf1d627bd605f34db780811199",
"gitiles_ref:refs/heads/master"
]
}
[07:34:03.989] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526628841859000",
"id": "8946207351477394608",
"lease_expiration_ts": "1526637842901970",
"lease_key": "1164699560",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"f3f09e0bb12e8aaf1d627bd605f34db780811199\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526628843893900",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2415",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/f3f09e0bb12e8aaf1d627bd605f34db780811199",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111637413801025392",
"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/2415",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946207351477394608",
"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/+/f3f09e0bb12e8aaf1d627bd605f34db780811199",
"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/8946207351477394608/+/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:9111637413801025392",
"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:3d8afd04b1d41110",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526628843893910",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2415",
"utcnow_ts": "1526628843975870"
}
}
[07:34:03.989] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2415
[07:34:03.989] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:2:0) after 1m0s
[07:35:04.012] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:2:0)
[07:35:04.013] Timer tick, asking Buildbucket for the build status
[07:35:04.167] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:35:04.168] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:3:0) after 1m0s
[07:36:04.190] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:3:0)
[07:36:04.190] Timer tick, asking Buildbucket for the build status
[07:36:04.254] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:36:04.254] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:4:0) after 1m0s
[07:37:04.277] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:4:0)
[07:37:04.277] Timer tick, asking Buildbucket for the build status
[07:37:04.842] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:37:04.842] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:5:0) after 1m0s
[07:38:04.860] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:5:0)
[07:38:04.860] Timer tick, asking Buildbucket for the build status
[07:38:05.224] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:38:05.224] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:6:0) after 1m0s
[07:39:05.250] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:6:0)
[07:39:05.250] Timer tick, asking Buildbucket for the build status
[07:39:05.646] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:39:05.646] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:7:0) after 1m0s
[07:40:05.672] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:7:0)
[07:40:05.672] Timer tick, asking Buildbucket for the build status
[07:40:06.026] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:40:06.026] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:8:0) after 1m0s
[07:41:06.047] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:8:0)
[07:41:06.047] Timer tick, asking Buildbucket for the build status
[07:41:06.402] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:41:06.402] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:9:0) after 1m0s
[07:42:06.437] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:9:0)
[07:42:06.437] Timer tick, asking Buildbucket for the build status
[07:42:06.811] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:42:06.811] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:10:0) after 1m0s
[07:43:06.844] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:10:0)
[07:43:06.844] Timer tick, asking Buildbucket for the build status
[07:43:07.166] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:43:07.167] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:11:0) after 1m0s
[07:44:07.198] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:11:0)
[07:44:07.198] Timer tick, asking Buildbucket for the build status
[07:44:07.512] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:44:07.512] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:12:0) after 1m0s
[07:45:07.531] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:12:0)
[07:45:07.531] Timer tick, asking Buildbucket for the build status
[07:45:08.240] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:45:08.240] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:13:0) after 1m0s
[07:46:08.257] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:13:0)
[07:46:08.257] Timer tick, asking Buildbucket for the build status
[07:46:08.649] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:46:08.649] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:14:0) after 1m0s
[07:47:08.769] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:14:0)
[07:47:08.769] Timer tick, asking Buildbucket for the build status
[07:47:09.126] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:47:09.126] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:15:0) after 1m0s
[07:48:09.287] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:15:0)
[07:48:09.287] Timer tick, asking Buildbucket for the build status
[07:48:09.721] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:48:09.721] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:16:0) after 1m0s
[07:49:09.859] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:16:0)
[07:49:09.859] Timer tick, asking Buildbucket for the build status
[07:49:10.233] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:49:10.233] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:17:0) after 1m0s
[07:50:10.358] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:17:0)
[07:50:10.358] Timer tick, asking Buildbucket for the build status
[07:50:10.860] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:50:10.860] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:18:0) after 1m0s
[07:51:11.000] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:18:0)
[07:51:11.000] Timer tick, asking Buildbucket for the build status
[07:51:11.107] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:51:11.107] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:19:0) after 1m0s
[07:52:11.209] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:19:0)
[07:52:11.209] Timer tick, asking Buildbucket for the build status
[07:52:11.522] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:52:11.522] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:20:0) after 1m0s
[07:53:11.538] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:20:0)
[07:53:11.538] Timer tick, asking Buildbucket for the build status
[07:53:11.940] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:53:11.940] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:21:0) after 1m0s
[07:54:11.982] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:21:0)
[07:54:11.982] Timer tick, asking Buildbucket for the build status
[07:54:12.342] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:54:12.342] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:22:0) after 1m0s
[07:55:12.452] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:22:0)
[07:55:12.452] Timer tick, asking Buildbucket for the build status
[07:55:12.741] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:55:12.741] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:23:0) after 1m0s
[07:56:12.843] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:23:0)
[07:56:12.843] Timer tick, asking Buildbucket for the build status
[07:56:13.229] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:56:13.230] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:24:0) after 1m0s
[07:57:13.348] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:24:0)
[07:57:13.348] Timer tick, asking Buildbucket for the build status
[07:57:13.740] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:57:13.740] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:25:0) after 1m0s
[07:58:13.904] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:25:0)
[07:58:13.904] Timer tick, asking Buildbucket for the build status
[07:58:14.231] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:58:14.231] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:26:0) after 1m0s
[07:59:14.299] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:26:0)
[07:59:14.299] Timer tick, asking Buildbucket for the build status
[07:59:14.634] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[07:59:14.634] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:27:0) after 1m0s
[08:00:14.784] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:27:0)
[08:00:14.784] Timer tick, asking Buildbucket for the build status
[08:00:15.128] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:00:15.128] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:28:0) after 1m0s
[08:01:15.255] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:28:0)
[08:01:15.255] Timer tick, asking Buildbucket for the build status
[08:01:15.614] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:01:15.614] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:29:0) after 1m0s
[08:02:15.741] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:29:0)
[08:02:15.741] Timer tick, asking Buildbucket for the build status
[08:02:16.128] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:02:16.128] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:30:0) after 1m0s
[08:03:16.243] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:30:0)
[08:03:16.243] Timer tick, asking Buildbucket for the build status
[08:03:16.630] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:03:16.630] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:31:0) after 1m0s
[08:04:16.850] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:31:0)
[08:04:16.850] Timer tick, asking Buildbucket for the build status
[08:04:17.208] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:04:17.208] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:32:0) after 1m0s
[08:05:17.332] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:32:0)
[08:05:17.332] Timer tick, asking Buildbucket for the build status
[08:05:17.813] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:05:17.813] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:33:0) after 1m0s
[08:06:18.037] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:33:0)
[08:06:18.037] Timer tick, asking Buildbucket for the build status
[08:06:18.441] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:06:18.441] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:34:0) after 1m0s
[08:07:18.559] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:34:0)
[08:07:18.559] Timer tick, asking Buildbucket for the build status
[08:07:18.677] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:07:18.677] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:35:0) after 1m0s
[08:08:18.804] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:35:0)
[08:08:18.804] Timer tick, asking Buildbucket for the build status
[08:08:19.148] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:08:19.148] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:36:0) after 1m0s
[08:09:19.168] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:36:0)
[08:09:19.168] Timer tick, asking Buildbucket for the build status
[08:09:19.546] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:09:19.546] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:37:0) after 1m0s
[08:10:19.803] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:37:0)
[08:10:19.803] Timer tick, asking Buildbucket for the build status
[08:10:19.931] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:10:19.931] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:38:0) after 1m0s
[08:11:20.065] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:38:0)
[08:11:20.065] Timer tick, asking Buildbucket for the build status
[08:11:20.492] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:11:20.492] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:39:0) after 1m0s
[08:12:20.622] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:39:0)
[08:12:20.622] Timer tick, asking Buildbucket for the build status
[08:12:21.033] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:12:21.033] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:40:0) after 1m0s
[08:13:21.153] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:40:0)
[08:13:21.153] Timer tick, asking Buildbucket for the build status
[08:13:21.532] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:13:21.532] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:41:0) after 1m0s
[08:14:21.648] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:41:0)
[08:14:21.648] Timer tick, asking Buildbucket for the build status
[08:14:22.096] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:14:22.096] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:42:0) after 1m0s
[08:15:22.158] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:42:0)
[08:15:22.158] Timer tick, asking Buildbucket for the build status
[08:15:22.546] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:15:22.546] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:43:0) after 1m0s
[08:16:22.657] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:43:0)
[08:16:22.657] Timer tick, asking Buildbucket for the build status
[08:16:22.876] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:16:22.876] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:44:0) after 1m0s
[08:17:23.003] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:44:0)
[08:17:23.003] Timer tick, asking Buildbucket for the build status
[08:17:23.572] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:17:23.572] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:45:0) after 1m0s
[08:18:23.695] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:45:0)
[08:18:23.695] Timer tick, asking Buildbucket for the build status
[08:18:24.378] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:18:24.378] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:46:0) after 1m0s
[08:19:24.604] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:46:0)
[08:19:24.604] Timer tick, asking Buildbucket for the build status
[08:19:24.742] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:19:24.742] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:47:0) after 1m0s
[08:20:24.874] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:47:0)
[08:20:24.874] Timer tick, asking Buildbucket for the build status
[08:20:25.211] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:20:25.211] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:48:0) after 1m0s
[08:21:25.360] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:48:0)
[08:21:25.360] Timer tick, asking Buildbucket for the build status
[08:21:25.713] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:21:25.713] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:49:0) after 1m0s
[08:22:25.753] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:49:0)
[08:22:25.753] Timer tick, asking Buildbucket for the build status
[08:22:26.286] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:22:26.286] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:50:0) after 1m0s
[08:23:26.414] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:50:0)
[08:23:26.414] Timer tick, asking Buildbucket for the build status
[08:23:26.801] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:23:26.801] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:51:0) after 1m0s
[08:24:26.858] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:51:0)
[08:24:26.858] Timer tick, asking Buildbucket for the build status
[08:24:27.088] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:24:27.088] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:52:0) after 1m0s
[08:25:27.219] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:52:0)
[08:25:27.219] Timer tick, asking Buildbucket for the build status
[08:25:27.384] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:25:27.384] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:53:0) after 1m0s
[08:26:27.456] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:53:0)
[08:26:27.456] Timer tick, asking Buildbucket for the build status
[08:26:27.575] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:26:27.575] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:54:0) after 1m0s
[08:27:27.596] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:54:0)
[08:27:27.597] Timer tick, asking Buildbucket for the build status
[08:27:27.707] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:27:27.707] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:55:0) after 1m0s
[08:28:27.723] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:55:0)
[08:28:27.723] Timer tick, asking Buildbucket for the build status
[08:28:27.879] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:28:27.879] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:56:0) after 1m0s
[08:29:27.897] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:56:0)
[08:29:27.897] Timer tick, asking Buildbucket for the build status
[08:29:28.026] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:29:28.026] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:57:0) after 1m0s
[08:30:28.076] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:57:0)
[08:30:28.076] Timer tick, asking Buildbucket for the build status
[08:30:28.345] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:30:28.345] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:58:0) after 1m0s
[08:31:28.461] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:58:0)
[08:31:28.461] Timer tick, asking Buildbucket for the build status
[08:31:28.575] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:31:28.575] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:59:0) after 1m0s
[08:32:28.595] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:59:0)
[08:32:28.595] Timer tick, asking Buildbucket for the build status
[08:32:28.688] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:32:28.688] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:60:0) after 1m0s
[08:33:28.706] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:60:0)
[08:33:28.706] Timer tick, asking Buildbucket for the build status
[08:33:28.913] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:33:28.913] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:61:0) after 1m0s
[08:34:29.265] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:61:0)
[08:34:29.265] Timer tick, asking Buildbucket for the build status
[08:34:29.383] Build 8946207351477394608: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[08:34:29.383] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111637413801025392:62:0) after 1m0s
[08:35:03.937] Received PubSub notification, asking Buildbucket for the build status
[08:35:03.989] Build 8946207351477394608: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[08:35:03.989] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526632502441300",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526628841859000",
"id": "8946207351477394608",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"f3f09e0bb12e8aaf1d627bd605f34db780811199\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-18T07:34:02.241870\", \"name\": \"bb-8946207351477394608-infra-infra-continuous-win10-64\", \"task_id\": \"3d8afd04b1d41110\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2415\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8946207351477394608\", \"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/+/f3f09e0bb12e8aaf1d627bd605f34db780811199\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8946207351477394608/+/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:9111637413801025392\", \"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-18T08:35:02.441300\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-18T08:35:02.441300\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526632503235040",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2415",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/f3f09e0bb12e8aaf1d627bd605f34db780811199",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111637413801025392",
"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/2415",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8946207351477394608",
"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/+/f3f09e0bb12e8aaf1d627bd605f34db780811199",
"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/8946207351477394608/+/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:9111637413801025392",
"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:3d8afd04b1d41110",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526632503235900",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2415",
"utcnow_ts": "1526632503975760"
}
}
[08:35:03.989] Invocation finished in 1h1m3.730071002s with status FAILED