[16:49:02.265] New invocation is queued and will start shortly
[16:49:03.446] Starting the invocation (attempt 1)
[16:49:03.492] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[16:49:03.492] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[16:49:03.492] Buildbucket request:
{
"bucket": "luci.chromium.ci",
"client_operation_id": "9106619660989401216",
"parameters_json": "{\"builder_name\":\"Windows deterministic\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/chromium/src.git\",\"revision\":\"4cce6875386037980e3245c630a9b9bac926f91e\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Windows deterministic",
"scheduler_invocation_id:9106619660989401216",
"scheduler_job_id:chromium/Windows deterministic",
"user_agent:luci-scheduler",
"buildset:commit/git/4cce6875386037980e3245c630a9b9bac926f91e",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4cce6875386037980e3245c630a9b9bac926f91e",
"gitiles_ref:refs/heads/master"
]
}
[16:49:04.770] Buildbucket response:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1531414143568530",
"id": "8941189598952645200",
"lease_expiration_ts": "1531475344351260",
"lease_key": "1283575250",
"parameters_json": "{\"builder_name\": \"Windows deterministic\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src.git\", \"revision\": \"4cce6875386037980e3245c630a9b9bac926f91e\"}}",
"project": "chromium",
"result_details_json": "null",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1531414144552680",
"tags": [
"build_address:luci.chromium.ci/Windows deterministic/9485",
"builder:Windows deterministic",
"buildset:commit/git/4cce6875386037980e3245c630a9b9bac926f91e",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4cce6875386037980e3245c630a9b9bac926f91e",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9106619660989401216",
"scheduler_job_id:chromium/Windows deterministic",
"swarming_dimension:builder:Windows deterministic",
"swarming_dimension:cores:8",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Windows-10",
"swarming_dimension:pool:luci.chromium.ci",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:build_address:luci.chromium.ci/Windows deterministic/9485",
"swarming_tag:buildbucket_bucket:luci.chromium.ci",
"swarming_tag:buildbucket_build_id:8941189598952645200",
"swarming_tag:buildbucket_hostname:cr-buildbucket.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:4e8cd6081d2622e2214b4bbd0cdf5e2ba5406635",
"swarming_tag:builder:Windows deterministic",
"swarming_tag:buildset:commit/git/4cce6875386037980e3245c630a9b9bac926f91e",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4cce6875386037980e3245c630a9b9bac926f91e",
"swarming_tag:cores:8",
"swarming_tag:cpu:x86-64",
"swarming_tag:gitiles_ref:refs/heads/master",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8941189598952645200/+/annotations",
"swarming_tag:luci_project:chromium",
"swarming_tag:os:Windows-10",
"swarming_tag:pool:luci.chromium.ci",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:swarming/deterministic_build",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_tag:scheduler_invocation_id:9106619660989401216",
"swarming_tag:scheduler_job_id:chromium/Windows deterministic",
"swarming_tag:service_account:chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"swarming_tag:swarming.pool.template:skip",
"swarming_tag:swarming.pool.version:e88d470b9c2f5c70f671b923f8c86b50fee14973",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler",
"swarming_tag:vpython:native-python-wrapper",
"swarming_task_id:3ea836ec78e0ea10",
"user_agent:luci-scheduler"
],
"updated_ts": "1531414144552820",
"url": "https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Windows deterministic/9485",
"utcnow_ts": "1531414144724580"
}
}
[16:49:04.770] Task URL: https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Windows deterministic/9485
[16:49:04.770] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:2:0) after 1m0s
[16:50:04.911] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:2:0)
[16:50:04.911] Timer tick, asking Buildbucket for the build status
[16:50:05.007] Build 8941189598952645200: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[16:50:05.007] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:3:0) after 1m0s
[16:50:51.417] Received PubSub notification, asking Buildbucket for the build status
[16:50:51.601] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:51:05.144] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:3:0)
[16:51:05.144] Timer tick, asking Buildbucket for the build status
[16:51:05.187] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:51:05.187] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:5:0) after 1m0s
[16:52:05.209] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:5:0)
[16:52:05.209] Timer tick, asking Buildbucket for the build status
[16:52:05.336] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:52:05.336] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:6:0) after 1m0s
[16:53:05.362] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:6:0)
[16:53:05.362] Timer tick, asking Buildbucket for the build status
[16:53:05.419] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:53:05.419] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:7:0) after 1m0s
[16:54:05.451] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:7:0)
[16:54:05.451] Timer tick, asking Buildbucket for the build status
[16:54:05.735] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:54:05.735] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:8:0) after 1m0s
[16:55:05.752] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:8:0)
[16:55:05.752] Timer tick, asking Buildbucket for the build status
[16:55:05.812] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:55:05.812] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:9:0) after 1m0s
[16:56:05.828] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:9:0)
[16:56:05.828] Timer tick, asking Buildbucket for the build status
[16:56:05.949] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:56:05.949] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:10:0) after 1m0s
[16:57:05.970] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:10:0)
[16:57:05.970] Timer tick, asking Buildbucket for the build status
[16:57:06.078] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:57:06.078] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:11:0) after 1m0s
[16:58:06.197] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:11:0)
[16:58:06.197] Timer tick, asking Buildbucket for the build status
[16:58:06.280] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:58:06.280] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:12:0) after 1m0s
[16:59:06.376] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:12:0)
[16:59:06.376] Timer tick, asking Buildbucket for the build status
[16:59:06.704] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:59:06.704] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:13:0) after 1m0s
[17:00:06.734] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:13:0)
[17:00:06.734] Timer tick, asking Buildbucket for the build status
[17:00:06.818] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:00:06.818] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:14:0) after 1m0s
[17:01:06.838] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:14:0)
[17:01:06.838] Timer tick, asking Buildbucket for the build status
[17:01:06.917] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:01:06.917] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:15:0) after 1m0s
[17:02:06.944] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:15:0)
[17:02:06.944] Timer tick, asking Buildbucket for the build status
[17:02:07.024] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:02:07.024] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:16:0) after 1m0s
[17:03:07.050] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:16:0)
[17:03:07.050] Timer tick, asking Buildbucket for the build status
[17:03:07.129] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:03:07.129] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:17:0) after 1m0s
[17:04:07.160] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:17:0)
[17:04:07.160] Timer tick, asking Buildbucket for the build status
[17:04:07.219] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:04:07.219] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:18:0) after 1m0s
[17:05:07.247] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:18:0)
[17:05:07.247] Timer tick, asking Buildbucket for the build status
[17:05:07.304] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:05:07.304] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:19:0) after 1m0s
[17:06:07.324] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:19:0)
[17:06:07.324] Timer tick, asking Buildbucket for the build status
[17:06:07.379] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:06:07.379] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:20:0) after 1m0s
[17:07:07.401] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:20:0)
[17:07:07.401] Timer tick, asking Buildbucket for the build status
[17:07:07.615] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:07:07.615] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:21:0) after 1m0s
[17:08:07.648] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:21:0)
[17:08:07.648] Timer tick, asking Buildbucket for the build status
[17:08:07.699] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:08:07.699] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:22:0) after 1m0s
[17:09:07.722] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:22:0)
[17:09:07.722] Timer tick, asking Buildbucket for the build status
[17:09:08.008] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:09:08.008] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:23:0) after 1m0s
[17:10:08.031] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:23:0)
[17:10:08.031] Timer tick, asking Buildbucket for the build status
[17:10:08.178] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:10:08.178] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:24:0) after 1m0s
[17:11:08.362] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:24:0)
[17:11:08.362] Timer tick, asking Buildbucket for the build status
[17:11:08.433] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:11:08.433] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:25:0) after 1m0s
[17:12:08.539] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:25:0)
[17:12:08.539] Timer tick, asking Buildbucket for the build status
[17:12:08.619] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:12:08.619] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:26:0) after 1m0s
[17:13:08.646] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:26:0)
[17:13:08.646] Timer tick, asking Buildbucket for the build status
[17:13:08.744] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:13:08.744] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:27:0) after 1m0s
[17:14:08.771] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:27:0)
[17:14:08.772] Timer tick, asking Buildbucket for the build status
[17:14:08.846] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:14:08.846] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:28:0) after 1m0s
[17:15:08.916] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:28:0)
[17:15:08.916] Timer tick, asking Buildbucket for the build status
[17:15:09.203] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:15:09.203] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:29:0) after 1m0s
[17:16:09.280] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:29:0)
[17:16:09.280] Timer tick, asking Buildbucket for the build status
[17:16:09.308] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:16:09.308] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:30:0) after 1m0s
[17:17:09.325] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:30:0)
[17:17:09.325] Timer tick, asking Buildbucket for the build status
[17:17:09.389] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:17:09.389] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:31:0) after 1m0s
[17:18:09.411] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:31:0)
[17:18:09.411] Timer tick, asking Buildbucket for the build status
[17:18:09.586] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:18:09.586] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:32:0) after 1m0s
[17:19:09.615] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:32:0)
[17:19:09.615] Timer tick, asking Buildbucket for the build status
[17:19:09.717] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:19:09.717] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:33:0) after 1m0s
[17:20:09.743] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:33:0)
[17:20:09.743] Timer tick, asking Buildbucket for the build status
[17:20:09.898] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:20:09.898] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:34:0) after 1m0s
[17:21:09.918] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:34:0)
[17:21:09.918] Timer tick, asking Buildbucket for the build status
[17:21:09.993] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:21:09.993] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:35:0) after 1m0s
[17:22:10.015] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:35:0)
[17:22:10.015] Timer tick, asking Buildbucket for the build status
[17:22:10.049] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:22:10.049] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:36:0) after 1m0s
[17:23:10.120] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:36:0)
[17:23:10.120] Timer tick, asking Buildbucket for the build status
[17:23:10.183] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:23:10.183] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:37:0) after 1m0s
[17:24:10.271] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:37:0)
[17:24:10.271] Timer tick, asking Buildbucket for the build status
[17:24:10.340] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:24:10.340] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:38:0) after 1m0s
[17:25:10.385] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:38:0)
[17:25:10.385] Timer tick, asking Buildbucket for the build status
[17:25:10.530] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:25:10.530] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:39:0) after 1m0s
[17:26:10.558] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:39:0)
[17:26:10.558] Timer tick, asking Buildbucket for the build status
[17:26:10.786] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:26:10.786] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:40:0) after 1m0s
[17:27:10.809] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:40:0)
[17:27:10.809] Timer tick, asking Buildbucket for the build status
[17:27:10.890] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:27:10.890] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:41:0) after 1m0s
[17:28:10.912] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:41:0)
[17:28:10.912] Timer tick, asking Buildbucket for the build status
[17:28:10.975] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:28:10.975] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:42:0) after 1m0s
[17:29:11.002] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:42:0)
[17:29:11.002] Timer tick, asking Buildbucket for the build status
[17:29:11.218] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:29:11.218] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:43:0) after 1m0s
[17:30:11.243] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:43:0)
[17:30:11.243] Timer tick, asking Buildbucket for the build status
[17:30:11.317] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:30:11.317] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:44:0) after 1m0s
[17:31:11.347] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:44:0)
[17:31:11.347] Timer tick, asking Buildbucket for the build status
[17:31:11.394] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:31:11.394] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:45:0) after 1m0s
[17:32:11.518] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:45:0)
[17:32:11.518] Timer tick, asking Buildbucket for the build status
[17:32:11.567] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:32:11.567] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:46:0) after 1m0s
[17:33:11.665] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:46:0)
[17:33:11.665] Timer tick, asking Buildbucket for the build status
[17:33:11.747] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:33:11.747] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:47:0) after 1m0s
[17:34:11.771] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:47:0)
[17:34:11.771] Timer tick, asking Buildbucket for the build status
[17:34:11.851] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:34:11.851] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:48:0) after 1m0s
[17:35:11.940] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:48:0)
[17:35:11.940] Timer tick, asking Buildbucket for the build status
[17:35:12.074] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:35:12.075] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:49:0) after 1m0s
[17:36:12.109] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:49:0)
[17:36:12.109] Timer tick, asking Buildbucket for the build status
[17:36:12.167] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:36:12.167] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:50:0) after 1m0s
[17:37:12.197] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:50:0)
[17:37:12.198] Timer tick, asking Buildbucket for the build status
[17:37:12.326] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:37:12.326] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:51:0) after 1m0s
[17:38:12.346] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:51:0)
[17:38:12.346] Timer tick, asking Buildbucket for the build status
[17:38:12.434] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:38:12.434] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:52:0) after 1m0s
[17:39:12.458] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:52:0)
[17:39:12.458] Timer tick, asking Buildbucket for the build status
[17:39:12.520] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:39:12.520] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:53:0) after 1m0s
[17:40:12.562] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:53:0)
[17:40:12.562] Timer tick, asking Buildbucket for the build status
[17:40:12.631] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:40:12.631] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:54:0) after 1m0s
[17:41:12.651] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:54:0)
[17:41:12.651] Timer tick, asking Buildbucket for the build status
[17:41:12.764] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:41:12.764] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:55:0) after 1m0s
[17:42:12.784] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:55:0)
[17:42:12.784] Timer tick, asking Buildbucket for the build status
[17:42:12.909] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:42:12.909] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:56:0) after 1m0s
[17:43:12.930] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:56:0)
[17:43:12.930] Timer tick, asking Buildbucket for the build status
[17:43:13.025] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:43:13.025] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:57:0) after 1m0s
[17:44:13.050] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:57:0)
[17:44:13.050] Timer tick, asking Buildbucket for the build status
[17:44:13.188] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:44:13.188] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:58:0) after 1m0s
[17:45:13.231] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:58:0)
[17:45:13.231] Timer tick, asking Buildbucket for the build status
[17:45:13.282] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:45:13.282] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:59:0) after 1m0s
[17:46:13.303] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:59:0)
[17:46:13.303] Timer tick, asking Buildbucket for the build status
[17:46:13.467] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:46:13.467] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:60:0) after 1m0s
[17:47:13.525] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:60:0)
[17:47:13.525] Timer tick, asking Buildbucket for the build status
[17:47:13.590] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:47:13.590] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:61:0) after 1m0s
[17:48:13.621] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:61:0)
[17:48:13.621] Timer tick, asking Buildbucket for the build status
[17:48:13.757] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:48:13.757] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:62:0) after 1m0s
[17:49:13.819] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:62:0)
[17:49:13.819] Timer tick, asking Buildbucket for the build status
[17:49:13.941] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:49:13.941] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:63:0) after 1m0s
[17:50:13.963] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:63:0)
[17:50:13.963] Timer tick, asking Buildbucket for the build status
[17:50:14.033] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:50:14.033] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:64:0) after 1m0s
[17:51:14.056] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:64:0)
[17:51:14.056] Timer tick, asking Buildbucket for the build status
[17:51:14.174] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:51:14.174] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:65:0) after 1m0s
[17:52:14.228] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:65:0)
[17:52:14.228] Timer tick, asking Buildbucket for the build status
[17:52:14.281] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:52:14.281] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:66:0) after 1m0s
[17:53:14.303] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:66:0)
[17:53:14.303] Timer tick, asking Buildbucket for the build status
[17:53:14.385] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:53:14.386] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:67:0) after 1m0s
[17:54:14.406] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:67:0)
[17:54:14.406] Timer tick, asking Buildbucket for the build status
[17:54:14.456] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:54:14.456] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:68:0) after 1m0s
[17:55:14.484] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:68:0)
[17:55:14.484] Timer tick, asking Buildbucket for the build status
[17:55:14.657] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:55:14.657] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:69:0) after 1m0s
[17:56:14.691] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:69:0)
[17:56:14.691] Timer tick, asking Buildbucket for the build status
[17:56:14.846] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:56:14.846] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:70:0) after 1m0s
[17:57:14.873] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:70:0)
[17:57:14.873] Timer tick, asking Buildbucket for the build status
[17:57:14.945] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:57:14.945] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:71:0) after 1m0s
[17:58:15.042] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:71:0)
[17:58:15.042] Timer tick, asking Buildbucket for the build status
[17:58:15.115] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:58:15.115] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:72:0) after 1m0s
[17:59:15.142] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:72:0)
[17:59:15.142] Timer tick, asking Buildbucket for the build status
[17:59:15.243] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:59:15.243] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:73:0) after 1m0s
[18:00:15.265] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:73:0)
[18:00:15.265] Timer tick, asking Buildbucket for the build status
[18:00:15.429] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:00:15.429] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:74:0) after 1m0s
[18:01:15.475] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:74:0)
[18:01:15.475] Timer tick, asking Buildbucket for the build status
[18:01:15.576] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:01:15.576] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:75:0) after 1m0s
[18:02:15.600] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:75:0)
[18:02:15.600] Timer tick, asking Buildbucket for the build status
[18:02:15.677] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:02:15.677] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:76:0) after 1m0s
[18:03:15.712] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:76:0)
[18:03:15.712] Timer tick, asking Buildbucket for the build status
[18:03:15.780] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:03:15.780] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:77:0) after 1m0s
[18:04:15.803] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:77:0)
[18:04:15.803] Timer tick, asking Buildbucket for the build status
[18:04:15.871] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:04:15.871] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:78:0) after 1m0s
[18:05:15.916] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:78:0)
[18:05:15.916] Timer tick, asking Buildbucket for the build status
[18:05:15.982] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:05:15.982] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:79:0) after 1m0s
[18:06:16.347] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:79:0)
[18:06:16.347] Timer tick, asking Buildbucket for the build status
[18:06:16.432] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:06:16.432] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:80:0) after 1m0s
[18:07:16.472] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:80:0)
[18:07:16.472] Timer tick, asking Buildbucket for the build status
[18:07:16.528] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:07:16.528] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:81:0) after 1m0s
[18:08:16.564] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:81:0)
[18:08:16.564] Timer tick, asking Buildbucket for the build status
[18:08:16.617] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:08:16.617] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:82:0) after 1m0s
[18:09:16.645] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:82:0)
[18:09:16.645] Timer tick, asking Buildbucket for the build status
[18:09:16.865] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:09:16.865] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:83:0) after 1m0s
[18:10:17.106] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:83:0)
[18:10:17.106] Timer tick, asking Buildbucket for the build status
[18:10:17.440] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:10:17.440] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:84:0) after 1m0s
[18:11:17.557] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:84:0)
[18:11:17.557] Timer tick, asking Buildbucket for the build status
[18:11:17.677] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:11:17.677] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:85:0) after 1m0s
[18:12:17.704] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:85:0)
[18:12:17.704] Timer tick, asking Buildbucket for the build status
[18:12:17.766] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:12:17.766] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:86:0) after 1m0s
[18:13:17.828] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:86:0)
[18:13:17.828] Timer tick, asking Buildbucket for the build status
[18:13:17.927] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:13:17.927] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:87:0) after 1m0s
[18:14:17.974] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:87:0)
[18:14:17.974] Timer tick, asking Buildbucket for the build status
[18:14:18.074] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:14:18.074] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:88:0) after 1m0s
[18:15:18.103] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:88:0)
[18:15:18.103] Timer tick, asking Buildbucket for the build status
[18:15:18.150] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:15:18.150] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:89:0) after 1m0s
[18:16:18.178] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:89:0)
[18:16:18.178] Timer tick, asking Buildbucket for the build status
[18:16:18.266] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:16:18.266] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:90:0) after 1m0s
[18:17:18.289] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:90:0)
[18:17:18.289] Timer tick, asking Buildbucket for the build status
[18:17:18.410] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:17:18.410] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:91:0) after 1m0s
[18:18:18.434] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:91:0)
[18:18:18.434] Timer tick, asking Buildbucket for the build status
[18:18:18.592] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:18:18.592] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:92:0) after 1m0s
[18:19:18.635] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:92:0)
[18:19:18.635] Timer tick, asking Buildbucket for the build status
[18:19:18.715] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:19:18.715] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:93:0) after 1m0s
[18:20:18.739] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:93:0)
[18:20:18.739] Timer tick, asking Buildbucket for the build status
[18:20:18.898] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:20:18.898] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:94:0) after 1m0s
[18:21:18.925] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:94:0)
[18:21:18.925] Timer tick, asking Buildbucket for the build status
[18:21:18.978] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:21:18.978] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:95:0) after 1m0s
[18:22:19.004] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:95:0)
[18:22:19.004] Timer tick, asking Buildbucket for the build status
[18:22:19.092] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:22:19.092] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:96:0) after 1m0s
[18:23:19.256] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:96:0)
[18:23:19.256] Timer tick, asking Buildbucket for the build status
[18:23:19.309] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:23:19.309] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:97:0) after 1m0s
[18:24:19.333] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:97:0)
[18:24:19.333] Timer tick, asking Buildbucket for the build status
[18:24:19.374] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:24:19.374] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:98:0) after 1m0s
[18:25:19.401] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:98:0)
[18:25:19.401] Timer tick, asking Buildbucket for the build status
[18:25:19.616] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:25:19.616] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:99:0) after 1m0s
[18:26:19.646] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:99:0)
[18:26:19.646] Timer tick, asking Buildbucket for the build status
[18:26:19.813] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:26:19.813] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:100:0) after 1m0s
[18:27:19.837] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:100:0)
[18:27:19.837] Timer tick, asking Buildbucket for the build status
[18:27:19.985] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:27:19.985] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:101:0) after 1m0s
[18:28:20.011] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:101:0)
[18:28:20.011] Timer tick, asking Buildbucket for the build status
[18:28:20.158] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:28:20.158] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:102:0) after 1m0s
[18:29:20.197] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:102:0)
[18:29:20.197] Timer tick, asking Buildbucket for the build status
[18:29:20.448] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:29:20.448] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:103:0) after 1m0s
[18:30:20.472] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:103:0)
[18:30:20.472] Timer tick, asking Buildbucket for the build status
[18:30:20.508] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:30:20.508] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:104:0) after 1m0s
[18:31:20.541] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:104:0)
[18:31:20.541] Timer tick, asking Buildbucket for the build status
[18:31:20.623] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:31:20.623] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:105:0) after 1m0s
[18:32:20.648] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:105:0)
[18:32:20.648] Timer tick, asking Buildbucket for the build status
[18:32:20.771] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:32:20.771] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:106:0) after 1m0s
[18:33:20.797] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:106:0)
[18:33:20.797] Timer tick, asking Buildbucket for the build status
[18:33:20.861] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:33:20.861] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:107:0) after 1m0s
[18:34:20.899] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:107:0)
[18:34:20.899] Timer tick, asking Buildbucket for the build status
[18:34:21.006] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:34:21.006] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:108:0) after 1m0s
[18:35:21.029] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:108:0)
[18:35:21.029] Timer tick, asking Buildbucket for the build status
[18:35:21.231] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:35:21.231] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:109:0) after 1m0s
[18:36:21.518] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:109:0)
[18:36:21.518] Timer tick, asking Buildbucket for the build status
[18:36:21.654] Build 8941189598952645200: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:36:21.654] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:9106619660989401216:110:0) after 1m0s
[18:36:53.715] Received PubSub notification, asking Buildbucket for the build status
[18:36:53.770] Build 8941189598952645200: status "COMPLETED", result "FAILURE", failure_reason "INFRA_FAILURE", cancelation_reason ""
[18:36:53.770] Buildbucket build:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "AUTO",
"completed_ts": "1531420611492180",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1531414143568530",
"failure_reason": "INFRA_FAILURE",
"id": "8941189598952645200",
"parameters_json": "{\"builder_name\": \"Windows deterministic\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src.git\", \"revision\": \"4cce6875386037980e3245c630a9b9bac926f91e\"}}",
"project": "chromium",
"result": "FAILURE",
"result_details_json": "{\"ui\": {\"info\": \"Failure compare_build_artifacts\\nFailure Uncaught Exception\"}, \"build_run_result\": {\"infraFailure\": {\"text\": \"recipe infra failure: Uncaught Exception: AttributeError(\\\"'NoneType' object has no attribute 'itervalues'\\\",)\", \"bootstrapperCallStack\": [], \"type\": \"RECIPE_INFRA_FAILURE\"}, \"recipeResult\": {\"failure\": {\"exception\": {\"traceback\": [\"Traceback (most recent call last):\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\recipe_engine\\\\recipe_engine\\\\run.py\\\", line 287, in _new_run\", \" recipe_result = recipe_script.run(api, self.properties, self.environ)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\recipe_engine\\\\recipe_engine\\\\loader.py\\\", line 108, in run\", \" self.run_steps, properties, environ, self.PROPERTIES, api=api)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\recipe_engine\\\\recipe_engine\\\\loader.py\\\", line 636, in invoke_with_properties\", \" arg_names, **additional_args)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\recipe_engine\\\\recipe_engine\\\\loader.py\\\", line 599, in _invoke_with_properties\", \" return callable_obj(*props, **additional_args)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\build\\\\scripts/slave\\\\recipes\\\\swarming/deterministic_build.py\\\", line 194, in RunSteps\", \" str(api.chromium.output_dir).rstrip('\\\\\\\\/') + '.2')\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\recipe_engine\\\\recipe_engine\\\\recipe_api.py\\\", line 759, in _inner\", \" return func(*a, **kw)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\build\\\\scripts/slave\\\\recipe_modules\\\\isolate\\\\api.py\\\", line 350, in compare_build_artifacts\", \" self.archive_differences(first_dir, second_dir, step_result.json.output)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\recipe_engine\\\\recipe_engine\\\\recipe_api.py\\\", line 759, in _inner\", \" return func(*a, **kw)\", \" File \\\"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\kitchen-checkout\\\\build\\\\scripts/slave\\\\recipe_modules\\\\isolate\\\\api.py\\\", line 302, in archive_differences\", \" diffs = list(itertools.chain.from_iterable(values.itervalues()))\", \"AttributeError: 'NoneType' object has no attribute 'itervalues'\"]}, \"humanReason\": \"Uncaught Exception: AttributeError(\\\"'NoneType' object has no attribute 'itervalues'\\\",)\"}}, \"recipeExitCode\": {\"value\": 1}, \"recipe\": {\"name\": \"swarming/deterministic_build\", \"repository\": \"\", \"revision\": \"\"}, \"annotationUrl\": \"logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8941189598952645200/+/annotations\"}, \"swarming\": {\"bot_dimensions\": {\"machine_type\": [\"n1-standard-8\"], \"zone\": [\"us\", \"us-central\", \"us-central1\", \"us-central1-b\"], \"locale\": [\"en_US.cp1252\"], \"os\": [\"Windows\", \"Windows-10\", \"Windows-10-15063\"], \"builder\": [\"Windows deterministic\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Haswell_GCE\"], \"python\": [\"2.7.6\"], \"server_version\": [\"3675-21ffa58\"], \"image\": [\"chrome-win10-1703-2018-04-20-61acaf8983f\"], \"gpu\": [\"none\"], \"cores\": [\"8\"], \"integrity\": [\"high\"], \"id\": [\"swarm2173-c4\"], \"pool\": [\"luci.chromium.ci\"], \"caches\": [\"git\", \"goma_v2\", \"vpython\"]}}, \"properties\": {\"got_nacl_revision\": \"e6ce828ef60c4c1438867b535efbbb5d9a177c0e\", \"got_swarming_client_revision\": \"9a518d097dca20b7b00ce3bdfc5d418ccc79893a\", \"got_revision\": \"4cce6875386037980e3245c630a9b9bac926f91e\", \"recipe\": \"swarming/deterministic_build\", \"got_webrtc_revision_cp\": \"refs/heads/master@{#23950}\", \"$recipe_engine/path\": {\"cache_dir\": \"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\cache\", \"temp_dir\": \"C:\\\\b\\\\swarming\\\\w\\\\ir\\\\tmp\\\\rt\"}, \"got_revision_cp\": \"refs/heads/master@{#574599}\", \"branch\": \"refs/heads/master\", \"revision\": \"4cce6875386037980e3245c630a9b9bac926f91e\", \"repository\": \"https://chromium.googlesource.com/chromium/src.git\", \"buildername\": \"Windows deterministic\", \"got_webrtc_revision\": \"58c79f66dd3afef0ec2d77053e44f26b998b84b1\", \"mastername\": \"chromium.fyi\", \"got_angle_revision\": \"5598148b761380773c4e650b5b67f47553b0f090\", \"buildbucket\": {\"hostname\": \"cr-buildbucket.appspot.com\", \"build\": {\"created_ts\": 1531414143568530, \"tags\": [\"builder:Windows deterministic\", \"buildset:commit/git/4cce6875386037980e3245c630a9b9bac926f91e\", \"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4cce6875386037980e3245c630a9b9bac926f91e\", \"gitiles_ref:refs/heads/master\", \"scheduler_invocation_id:9106619660989401216\", \"scheduler_job_id:chromium/Windows deterministic\", \"user_agent:luci-scheduler\"], \"bucket\": \"luci.chromium.ci\", \"created_by\": \"user:luci-scheduler@appspot.gserviceaccount.com\", \"project\": \"chromium\", \"id\": \"8941189598952645200\"}}, \"got_v8_revision\": \"8b17db68f75a95d69debfa85b70aea3ec0766aaf\", \"got_v8_revision_cp\": \"refs/heads/6.9.352@{#1}\", \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"buildnumber\": 9485, \"path_config\": \"generic\", \"bot_id\": \"swarm2173-c4\", \"got_buildtools_revision\": \"0dd5c6f980d22be96b728155249df2da355989d9\"}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1531414250444810",
"status": "COMPLETED",
"status_changed_ts": "1531420613121800",
"tags": [
"build_address:luci.chromium.ci/Windows deterministic/9485",
"builder:Windows deterministic",
"buildset:commit/git/4cce6875386037980e3245c630a9b9bac926f91e",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4cce6875386037980e3245c630a9b9bac926f91e",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9106619660989401216",
"scheduler_job_id:chromium/Windows deterministic",
"swarming_dimension:builder:Windows deterministic",
"swarming_dimension:cores:8",
"swarming_dimension:cpu:x86-64",
"swarming_dimension:os:Windows-10",
"swarming_dimension:pool:luci.chromium.ci",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:build_address:luci.chromium.ci/Windows deterministic/9485",
"swarming_tag:buildbucket_bucket:luci.chromium.ci",
"swarming_tag:buildbucket_build_id:8941189598952645200",
"swarming_tag:buildbucket_hostname:cr-buildbucket.appspot.com",
"swarming_tag:buildbucket_template_canary:0",
"swarming_tag:buildbucket_template_revision:4e8cd6081d2622e2214b4bbd0cdf5e2ba5406635",
"swarming_tag:builder:Windows deterministic",
"swarming_tag:buildset:commit/git/4cce6875386037980e3245c630a9b9bac926f91e",
"swarming_tag:buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4cce6875386037980e3245c630a9b9bac926f91e",
"swarming_tag:cores:8",
"swarming_tag:cpu:x86-64",
"swarming_tag:gitiles_ref:refs/heads/master",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8941189598952645200/+/annotations",
"swarming_tag:luci_project:chromium",
"swarming_tag:os:Windows-10",
"swarming_tag:pool:luci.chromium.ci",
"swarming_tag:priority:30",
"swarming_tag:recipe_name:swarming/deterministic_build",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_tag:scheduler_invocation_id:9106619660989401216",
"swarming_tag:scheduler_job_id:chromium/Windows deterministic",
"swarming_tag:service_account:chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"swarming_tag:swarming.pool.template:skip",
"swarming_tag:swarming.pool.version:e88d470b9c2f5c70f671b923f8c86b50fee14973",
"swarming_tag:user:None",
"swarming_tag:user_agent:luci-scheduler",
"swarming_tag:vpython:native-python-wrapper",
"swarming_task_id:3ea836ec78e0ea10",
"user_agent:luci-scheduler"
],
"updated_ts": "1531420613123590",
"url": "https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Windows deterministic/9485",
"utcnow_ts": "1531420613757130"
}
}
[18:36:53.775] Invocation finished in 1h47m51.532393276s with status FAILED