[03:21:02.293] New invocation is queued and will start shortly
[03:21:03.562] Starting the invocation (attempt 1)
[03:21:03.664] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[03:21:03.681] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[03:21:03.681] Buildbucket request:
{
"bucket": "luci.infra.ci",
"client_operation_id": "9111290941206946688",
"parameters_json": "{\"builder_name\":\"infra-continuous-win10-64\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/infra/infra.git\",\"revision\":\"98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02\"}}",
"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:9111290941206946688",
"scheduler_job_id:infra/infra-continuous-win10-64",
"user_agent:luci-scheduler-dev",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02",
"gitiles_ref:refs/heads/master"
]
}
[03:21:04.512] Buildbucket response:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526959263748980",
"id": "8945860879014712480",
"lease_expiration_ts": "1526968264269300",
"lease_key": "545489701",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02\"}}",
"project": "infra",
"result_details_json": "null",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1526959264430950",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2443",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111290941206946688",
"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/2443",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945860879014712480",
"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/+/98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02",
"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/8945860879014712480/+/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:9111290941206946688",
"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:3d9eaed92471b410",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526959264430960",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2443",
"utcnow_ts": "1526959264500880"
}
}
[03:21:04.512] Task URL: https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2443
[03:21:04.512] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:2:0) after 1m0s
[03:22:04.540] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:2:0)
[03:22:04.540] Timer tick, asking Buildbucket for the build status
[03:22:04.675] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:22:04.675] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:3:0) after 1m0s
[03:23:04.867] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:3:0)
[03:23:04.867] Timer tick, asking Buildbucket for the build status
[03:23:05.574] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:23:05.574] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:4:0) after 1m0s
[03:24:05.593] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:4:0)
[03:24:05.593] Timer tick, asking Buildbucket for the build status
[03:24:05.652] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:24:05.652] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:5:0) after 1m0s
[03:25:05.668] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:5:0)
[03:25:05.668] Timer tick, asking Buildbucket for the build status
[03:25:05.814] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:25:05.814] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:6:0) after 1m0s
[03:26:05.838] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:6:0)
[03:26:05.838] Timer tick, asking Buildbucket for the build status
[03:26:05.951] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:26:05.951] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:7:0) after 1m0s
[03:27:05.969] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:7:0)
[03:27:05.969] Timer tick, asking Buildbucket for the build status
[03:27:06.026] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:27:06.026] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:8:0) after 1m0s
[03:28:06.041] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:8:0)
[03:28:06.041] Timer tick, asking Buildbucket for the build status
[03:28:06.195] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:28:06.195] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:9:0) after 1m0s
[03:29:06.411] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:9:0)
[03:29:06.411] Timer tick, asking Buildbucket for the build status
[03:29:06.553] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:29:06.553] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:10:0) after 1m0s
[03:30:06.571] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:10:0)
[03:30:06.571] Timer tick, asking Buildbucket for the build status
[03:30:06.692] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:30:06.692] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:11:0) after 1m0s
[03:31:06.919] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:11:0)
[03:31:06.919] Timer tick, asking Buildbucket for the build status
[03:31:06.995] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:31:06.995] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:12:0) after 1m0s
[03:32:07.073] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:12:0)
[03:32:07.073] Timer tick, asking Buildbucket for the build status
[03:32:07.210] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:32:07.210] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:13:0) after 1m0s
[03:33:07.453] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:13:0)
[03:33:07.453] Timer tick, asking Buildbucket for the build status
[03:33:07.663] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:33:07.663] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:14:0) after 1m0s
[03:34:07.764] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:14:0)
[03:34:07.764] Timer tick, asking Buildbucket for the build status
[03:34:08.053] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:34:08.053] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:15:0) after 1m0s
[03:35:08.225] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:15:0)
[03:35:08.225] Timer tick, asking Buildbucket for the build status
[03:35:08.313] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:35:08.313] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:16:0) after 1m0s
[03:36:08.515] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:16:0)
[03:36:08.515] Timer tick, asking Buildbucket for the build status
[03:36:08.851] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:36:08.851] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:17:0) after 1m0s
[03:37:08.964] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:17:0)
[03:37:08.964] Timer tick, asking Buildbucket for the build status
[03:37:09.148] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:37:09.148] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:18:0) after 1m0s
[03:38:09.272] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:18:0)
[03:38:09.272] Timer tick, asking Buildbucket for the build status
[03:38:09.442] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:38:09.442] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:19:0) after 1m0s
[03:39:09.674] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:19:0)
[03:39:09.674] Timer tick, asking Buildbucket for the build status
[03:39:09.881] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:39:09.881] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:20:0) after 1m0s
[03:40:09.921] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:20:0)
[03:40:09.921] Timer tick, asking Buildbucket for the build status
[03:40:10.196] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:40:10.196] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:21:0) after 1m0s
[03:41:10.214] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:21:0)
[03:41:10.214] Timer tick, asking Buildbucket for the build status
[03:41:10.356] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:41:10.356] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:22:0) after 1m0s
[03:42:10.491] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:22:0)
[03:42:10.491] Timer tick, asking Buildbucket for the build status
[03:42:10.594] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:42:10.595] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:23:0) after 1m0s
[03:43:10.656] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:23:0)
[03:43:10.656] Timer tick, asking Buildbucket for the build status
[03:43:10.802] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:43:10.802] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:24:0) after 1m0s
[03:44:10.915] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:24:0)
[03:44:10.915] Timer tick, asking Buildbucket for the build status
[03:44:10.990] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:44:10.990] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:25:0) after 1m0s
[03:45:11.219] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:25:0)
[03:45:11.219] Timer tick, asking Buildbucket for the build status
[03:45:11.388] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:45:11.388] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:26:0) after 1m0s
[03:46:11.413] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:26:0)
[03:46:11.413] Timer tick, asking Buildbucket for the build status
[03:46:11.847] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:46:11.847] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:27:0) after 1m0s
[03:47:12.006] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:27:0)
[03:47:12.006] Timer tick, asking Buildbucket for the build status
[03:47:12.176] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:47:12.176] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:28:0) after 1m0s
[03:48:12.286] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:28:0)
[03:48:12.286] Timer tick, asking Buildbucket for the build status
[03:48:12.473] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:48:12.473] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:29:0) after 1m0s
[03:49:12.575] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:29:0)
[03:49:12.575] Timer tick, asking Buildbucket for the build status
[03:49:12.788] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:49:12.788] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:30:0) after 1m0s
[03:50:12.911] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:30:0)
[03:50:12.911] Timer tick, asking Buildbucket for the build status
[03:50:13.173] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:50:13.173] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:31:0) after 1m0s
[03:51:13.280] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:31:0)
[03:51:13.280] Timer tick, asking Buildbucket for the build status
[03:51:13.490] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:51:13.490] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:32:0) after 1m0s
[03:52:13.505] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:32:0)
[03:52:13.505] Timer tick, asking Buildbucket for the build status
[03:52:13.710] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:52:13.710] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:33:0) after 1m0s
[03:53:13.792] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:33:0)
[03:53:13.792] Timer tick, asking Buildbucket for the build status
[03:53:13.976] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:53:13.976] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:34:0) after 1m0s
[03:54:14.527] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:34:0)
[03:54:14.527] Timer tick, asking Buildbucket for the build status
[03:54:14.775] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:54:14.775] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:35:0) after 1m0s
[03:55:14.909] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:35:0)
[03:55:14.909] Timer tick, asking Buildbucket for the build status
[03:55:15.092] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:55:15.092] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:36:0) after 1m0s
[03:56:15.176] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:36:0)
[03:56:15.176] Timer tick, asking Buildbucket for the build status
[03:56:15.656] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:56:15.656] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:37:0) after 1m0s
[03:57:15.693] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:37:0)
[03:57:15.693] Timer tick, asking Buildbucket for the build status
[03:57:15.869] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:57:15.869] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:38:0) after 1m0s
[03:58:16.023] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:38:0)
[03:58:16.023] Timer tick, asking Buildbucket for the build status
[03:58:16.160] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:58:16.160] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:39:0) after 1m0s
[03:59:16.336] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:39:0)
[03:59:16.337] Timer tick, asking Buildbucket for the build status
[03:59:16.509] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[03:59:16.509] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:40:0) after 1m0s
[04:00:16.526] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:40:0)
[04:00:16.526] Timer tick, asking Buildbucket for the build status
[04:00:16.667] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:00:16.667] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:41:0) after 1m0s
[04:01:16.691] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:41:0)
[04:01:16.691] Timer tick, asking Buildbucket for the build status
[04:01:16.897] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:01:16.897] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:42:0) after 1m0s
[04:02:16.962] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:42:0)
[04:02:16.962] Timer tick, asking Buildbucket for the build status
[04:02:17.093] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:02:17.093] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:43:0) after 1m0s
[04:03:17.119] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:43:0)
[04:03:17.119] Timer tick, asking Buildbucket for the build status
[04:03:17.357] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:03:17.357] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:44:0) after 1m0s
[04:04:17.384] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:44:0)
[04:04:17.384] Timer tick, asking Buildbucket for the build status
[04:04:17.583] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:04:17.583] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:45:0) after 1m0s
[04:05:17.603] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:45:0)
[04:05:17.603] Timer tick, asking Buildbucket for the build status
[04:05:17.777] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:05:17.777] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:46:0) after 1m0s
[04:06:17.801] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:46:0)
[04:06:17.801] Timer tick, asking Buildbucket for the build status
[04:06:17.968] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:06:17.968] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:47:0) after 1m0s
[04:07:17.987] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:47:0)
[04:07:17.987] Timer tick, asking Buildbucket for the build status
[04:07:18.401] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:07:18.401] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:48:0) after 1m0s
[04:08:18.420] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:48:0)
[04:08:18.420] Timer tick, asking Buildbucket for the build status
[04:08:18.579] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:08:18.579] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:49:0) after 1m0s
[04:09:18.601] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:49:0)
[04:09:18.601] Timer tick, asking Buildbucket for the build status
[04:09:18.878] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:09:18.878] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:50:0) after 1m0s
[04:10:18.899] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:50:0)
[04:10:18.899] Timer tick, asking Buildbucket for the build status
[04:10:19.064] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:10:19.064] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:51:0) after 1m0s
[04:11:19.089] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:51:0)
[04:11:19.089] Timer tick, asking Buildbucket for the build status
[04:11:19.460] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:11:19.460] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:52:0) after 1m0s
[04:12:19.483] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:52:0)
[04:12:19.483] Timer tick, asking Buildbucket for the build status
[04:12:19.578] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:12:19.578] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:53:0) after 1m0s
[04:13:19.594] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:53:0)
[04:13:19.595] Timer tick, asking Buildbucket for the build status
[04:13:19.750] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:13:19.750] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:54:0) after 1m0s
[04:14:19.797] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:54:0)
[04:14:19.797] Timer tick, asking Buildbucket for the build status
[04:14:19.864] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:14:19.864] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:55:0) after 1m0s
[04:15:19.881] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:55:0)
[04:15:19.881] Timer tick, asking Buildbucket for the build status
[04:15:19.942] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:15:19.942] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:56:0) after 1m0s
[04:16:19.961] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:56:0)
[04:16:19.961] Timer tick, asking Buildbucket for the build status
[04:16:20.013] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:16:20.013] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:57:0) after 1m0s
[04:17:20.030] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:57:0)
[04:17:20.030] Timer tick, asking Buildbucket for the build status
[04:17:20.269] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:17:20.269] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:58:0) after 1m0s
[04:18:20.289] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:58:0)
[04:18:20.289] Timer tick, asking Buildbucket for the build status
[04:18:20.489] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:18:20.489] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:59:0) after 1m0s
[04:19:20.506] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:59:0)
[04:19:20.506] Timer tick, asking Buildbucket for the build status
[04:19:20.677] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:19:20.677] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:60:0) after 1m0s
[04:20:20.721] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:60:0)
[04:20:20.721] Timer tick, asking Buildbucket for the build status
[04:20:20.898] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:20:20.898] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:61:0) after 1m0s
[04:21:20.916] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:61:0)
[04:21:20.916] Timer tick, asking Buildbucket for the build status
[04:21:21.507] Build 8945860879014712480: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[04:21:21.507] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:9111290941206946688:62:0) after 1m0s
[04:22:08.198] Received PubSub notification, asking Buildbucket for the build status
[04:22:08.241] Build 8945860879014712480: status "COMPLETED", result "CANCELED", failure_reason "", cancelation_reason "TIMEOUT"
[04:22:08.241] Buildbucket build:
{
"build": {
"bucket": "luci.infra.ci",
"canary_preference": "AUTO",
"cancelation_reason": "TIMEOUT",
"completed_ts": "1526962922996760",
"created_by": "user:luci-scheduler-dev@appspot.gserviceaccount.com",
"created_ts": "1526959263748980",
"id": "8945860879014712480",
"parameters_json": "{\"builder_name\": \"infra-continuous-win10-64\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/infra/infra.git\", \"revision\": \"98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02\"}}",
"project": "infra",
"result": "CANCELED",
"result_details_json": "{\"swarming\": {\"task_result\": {\"created_ts\": \"2018-05-22T03:21:03.942980\", \"name\": \"bb-8945860879014712480-infra-infra-continuous-win10-64\", \"task_id\": \"3d9eaed92471b410\", \"tags\": [\"allow_milo:1\", \"build_address:luci.infra.ci/infra-continuous-win10-64/2443\", \"buildbucket_bucket:luci.infra.ci\", \"buildbucket_build_id:8945860879014712480\", \"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/+/98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02\", \"cpu:x86-64\", \"gitiles_ref:refs/heads/master\", \"log_location:logdog://luci-logdog-dev.appspot.com/infra/buildbucket/cr-buildbucket-dev.appspot.com/8945860879014712480/+/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:9111290941206946688\", \"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\": [\"3561-435d49c-tainted-smut\"], \"abandoned_ts\": \"2018-05-22T04:22:02.996760\", \"failure\": false, \"state\": \"EXPIRED\", \"modified_ts\": \"2018-05-22T04:22:02.996760\", \"user\": \"\", \"current_task_slice\": \"0\"}}}",
"service_account": "adhoc-testing@luci-token-server-dev.iam.gserviceaccount.com",
"status": "COMPLETED",
"status_changed_ts": "1526962927604540",
"tags": [
"build_address:luci.infra.ci/infra-continuous-win10-64/2443",
"builder:infra-continuous-win10-64",
"buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9111290941206946688",
"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/2443",
"swarming_tag:buildbucket_bucket:luci.infra.ci",
"swarming_tag:buildbucket_build_id:8945860879014712480",
"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/+/98fc4bfa0dbe8642d490aaa827ee3f87dd8f4d02",
"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/8945860879014712480/+/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:9111290941206946688",
"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:3d9eaed92471b410",
"user_agent:luci-scheduler-dev"
],
"updated_ts": "1526962927605470",
"url": "https://luci-milo-dev.appspot.com/p/infra/builders/luci.infra.ci/infra-continuous-win10-64/2443",
"utcnow_ts": "1526962928230660"
}
}
[04:22:08.241] Invocation finished in 1h1m5.966997026s with status FAILED