[02:04:00.933] New invocation is queued and will start shortly
[02:04:02.216] Starting the invocation (attempt 1)
[02:04:02.261] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[02:04:02.261] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[02:04:02.261] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9021061208517984800",
"parameters_json": "{\"builder_name\":\"linux-pnacl-x86_64-tests-x86_32\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"gitiles\":{\"ref\":\"refs/heads/master\",\"repo\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\",\"title\":\"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux-pnacl-x86_64-tests-x86_32",
"scheduler_invocation_id:9021061208517984800",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
"user_agent:luci-scheduler",
"buildset:commit/git/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5",
"gitiles_ref:refs/heads/master"
]
}
[02:04:03.192] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1613009042458091",
"id": "8855631146253859168",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_32\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"title\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}}",
"project": "nacl",
"result_details_json": "{\"properties\": {}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1613009043071751",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_32/5181",
"builder:linux-pnacl-x86_64-tests-x86_32",
"buildset:commit/git/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9021061208517984800",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8855631146253859168/+/annotations",
"swarming_tag:luci_project:nacl",
"swarming_tag:recipe_name:nacl",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:",
"user_agent:luci-scheduler"
],
"updated_ts": "1613009043071866",
"url": "https://ci.chromium.org/b/8855631146253859168",
"utcnow_ts": "1613009043184138"
}
}
[02:04:03.192] Task URL: https://ci.chromium.org/b/8855631146253859168
[02:04:03.192] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:2:0) after 1m0s
[02:04:14.014] Received PubSub notification, asking Buildbucket for the build status
[02:04:14.111] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:05:03.199] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:2:0)
[02:05:03.199] Timer tick, asking Buildbucket for the build status
[02:05:03.292] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:05:03.292] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:4:0) after 1m0s
[02:06:03.265] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:4:0)
[02:06:03.265] Timer tick, asking Buildbucket for the build status
[02:06:03.486] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:06:03.486] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:5:0) after 1m0s
[02:07:03.533] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:5:0)
[02:07:03.533] Timer tick, asking Buildbucket for the build status
[02:07:04.145] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:07:04.145] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:6:0) after 1m0s
[02:08:04.256] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:6:0)
[02:08:04.256] Timer tick, asking Buildbucket for the build status
[02:08:04.336] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:08:04.336] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:7:0) after 1m0s
[02:09:04.346] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:7:0)
[02:09:04.346] Timer tick, asking Buildbucket for the build status
[02:09:04.448] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:09:04.448] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:8:0) after 1m0s
[02:10:04.538] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:8:0)
[02:10:04.538] Timer tick, asking Buildbucket for the build status
[02:10:04.738] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:10:04.738] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:9:0) after 1m0s
[02:11:04.711] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:9:0)
[02:11:04.711] Timer tick, asking Buildbucket for the build status
[02:11:04.838] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:11:04.838] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:10:0) after 1m0s
[02:12:04.845] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:10:0)
[02:12:04.845] Timer tick, asking Buildbucket for the build status
[02:12:04.946] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:12:04.946] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:11:0) after 1m0s
[02:13:05.002] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:11:0)
[02:13:05.002] Timer tick, asking Buildbucket for the build status
[02:13:05.219] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:13:05.219] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:12:0) after 1m0s
[02:14:05.282] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:12:0)
[02:14:05.282] Timer tick, asking Buildbucket for the build status
[02:14:05.558] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:14:05.558] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:13:0) after 1m0s
[02:15:05.619] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:13:0)
[02:15:05.620] Timer tick, asking Buildbucket for the build status
[02:15:05.762] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:15:05.762] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:14:0) after 1m0s
[02:16:05.765] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:14:0)
[02:16:05.765] Timer tick, asking Buildbucket for the build status
[02:16:05.898] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:16:05.898] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:15:0) after 1m0s
[02:17:05.917] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:15:0)
[02:17:05.917] Timer tick, asking Buildbucket for the build status
[02:17:06.048] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:17:06.048] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:16:0) after 1m0s
[02:18:06.130] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:16:0)
[02:18:06.130] Timer tick, asking Buildbucket for the build status
[02:18:06.214] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:18:06.214] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:17:0) after 1m0s
[02:19:06.237] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:17:0)
[02:19:06.237] Timer tick, asking Buildbucket for the build status
[02:19:06.373] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:19:06.373] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:18:0) after 1m0s
[02:20:06.444] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:18:0)
[02:20:06.444] Timer tick, asking Buildbucket for the build status
[02:20:06.662] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:20:06.662] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:19:0) after 1m0s
[02:21:06.786] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:19:0)
[02:21:06.786] Timer tick, asking Buildbucket for the build status
[02:21:06.894] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:21:06.895] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:20:0) after 1m0s
[02:22:07.039] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:20:0)
[02:22:07.039] Timer tick, asking Buildbucket for the build status
[02:22:07.117] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:22:07.118] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:21:0) after 1m0s
[02:23:07.313] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:21:0)
[02:23:07.313] Timer tick, asking Buildbucket for the build status
[02:23:07.600] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:23:07.600] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:22:0) after 1m0s
[02:24:07.681] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:22:0)
[02:24:07.681] Timer tick, asking Buildbucket for the build status
[02:24:08.126] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:24:08.126] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:23:0) after 1m0s
[02:25:08.268] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:23:0)
[02:25:08.268] Timer tick, asking Buildbucket for the build status
[02:25:08.450] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:25:08.450] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:24:0) after 1m0s
[02:26:08.486] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:24:0)
[02:26:08.486] Timer tick, asking Buildbucket for the build status
[02:26:08.632] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:26:08.632] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:25:0) after 1m0s
[02:27:08.679] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:25:0)
[02:27:08.679] Timer tick, asking Buildbucket for the build status
[02:27:08.828] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:27:08.828] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:26:0) after 1m0s
[02:28:08.925] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:26:0)
[02:28:08.925] Timer tick, asking Buildbucket for the build status
[02:28:09.334] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:28:09.334] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:27:0) after 1m0s
[02:29:09.367] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:27:0)
[02:29:09.367] Timer tick, asking Buildbucket for the build status
[02:29:09.475] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:29:09.475] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:28:0) after 1m0s
[02:30:09.571] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:28:0)
[02:30:09.571] Timer tick, asking Buildbucket for the build status
[02:30:09.663] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:30:09.663] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:29:0) after 1m0s
[02:31:09.699] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:29:0)
[02:31:09.699] Timer tick, asking Buildbucket for the build status
[02:31:09.812] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:31:09.812] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:30:0) after 1m0s
[02:32:09.912] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:30:0)
[02:32:09.912] Timer tick, asking Buildbucket for the build status
[02:32:10.068] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:32:10.068] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:31:0) after 1m0s
[02:33:10.123] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:31:0)
[02:33:10.123] Timer tick, asking Buildbucket for the build status
[02:33:10.404] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:33:10.404] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:32:0) after 1m0s
[02:34:10.449] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:32:0)
[02:34:10.449] Timer tick, asking Buildbucket for the build status
[02:34:10.576] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:34:10.576] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:33:0) after 1m0s
[02:35:10.602] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:33:0)
[02:35:10.602] Timer tick, asking Buildbucket for the build status
[02:35:10.685] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:35:10.685] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:34:0) after 1m0s
[02:36:10.755] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:34:0)
[02:36:10.755] Timer tick, asking Buildbucket for the build status
[02:36:10.875] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:36:10.875] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:35:0) after 1m0s
[02:37:10.911] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:35:0)
[02:37:10.911] Timer tick, asking Buildbucket for the build status
[02:37:11.002] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:37:11.002] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:36:0) after 1m0s
[02:38:11.015] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:36:0)
[02:38:11.015] Timer tick, asking Buildbucket for the build status
[02:38:11.147] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:38:11.147] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:37:0) after 1m0s
[02:39:11.187] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:37:0)
[02:39:11.187] Timer tick, asking Buildbucket for the build status
[02:39:11.345] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:39:11.345] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:38:0) after 1m0s
[02:40:11.357] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:38:0)
[02:40:11.357] Timer tick, asking Buildbucket for the build status
[02:40:11.598] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:40:11.598] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:39:0) after 1m0s
[02:41:11.634] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:39:0)
[02:41:11.634] Timer tick, asking Buildbucket for the build status
[02:41:11.735] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:41:11.735] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:40:0) after 1m0s
[02:42:11.817] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:40:0)
[02:42:11.817] Timer tick, asking Buildbucket for the build status
[02:42:11.974] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:42:11.974] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:41:0) after 1m0s
[02:43:12.020] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:41:0)
[02:43:12.020] Timer tick, asking Buildbucket for the build status
[02:43:12.212] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:43:12.212] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:42:0) after 1m0s
[02:44:12.277] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:42:0)
[02:44:12.277] Timer tick, asking Buildbucket for the build status
[02:44:12.395] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:44:12.395] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:43:0) after 1m0s
[02:45:12.467] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:43:0)
[02:45:12.467] Timer tick, asking Buildbucket for the build status
[02:45:12.736] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:45:12.736] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:44:0) after 1m0s
[02:46:12.817] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:44:0)
[02:46:12.817] Timer tick, asking Buildbucket for the build status
[02:46:13.007] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:46:13.007] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:45:0) after 1m0s
[02:47:13.115] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:45:0)
[02:47:13.115] Timer tick, asking Buildbucket for the build status
[02:47:13.440] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:47:13.440] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:46:0) after 1m0s
[02:48:13.440] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:46:0)
[02:48:13.440] Timer tick, asking Buildbucket for the build status
[02:48:13.555] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:48:13.555] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:47:0) after 1m0s
[02:49:13.607] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:47:0)
[02:49:13.607] Timer tick, asking Buildbucket for the build status
[02:49:13.708] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:49:13.708] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:48:0) after 1m0s
[02:50:13.754] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:48:0)
[02:50:13.754] Timer tick, asking Buildbucket for the build status
[02:50:13.869] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:50:13.869] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:49:0) after 1m0s
[02:51:13.887] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:49:0)
[02:51:13.887] Timer tick, asking Buildbucket for the build status
[02:51:13.974] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:51:13.974] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:50:0) after 1m0s
[02:52:14.022] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:50:0)
[02:52:14.022] Timer tick, asking Buildbucket for the build status
[02:52:14.395] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:52:14.395] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:51:0) after 1m0s
[02:53:14.416] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:51:0)
[02:53:14.416] Timer tick, asking Buildbucket for the build status
[02:53:14.512] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:53:14.512] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:52:0) after 1m0s
[02:54:14.489] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:52:0)
[02:54:14.489] Timer tick, asking Buildbucket for the build status
[02:54:15.454] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:54:15.454] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:53:0) after 1m0s
[02:55:15.517] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:53:0)
[02:55:15.517] Timer tick, asking Buildbucket for the build status
[02:55:15.645] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:55:15.645] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:54:0) after 1m0s
[02:56:15.656] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:54:0)
[02:56:15.656] Timer tick, asking Buildbucket for the build status
[02:56:15.753] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:56:15.753] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:55:0) after 1m0s
[02:57:15.847] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:55:0)
[02:57:15.847] Timer tick, asking Buildbucket for the build status
[02:57:15.981] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:57:15.981] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:56:0) after 1m0s
[02:58:15.995] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:56:0)
[02:58:15.995] Timer tick, asking Buildbucket for the build status
[02:58:16.727] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:58:16.727] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:57:0) after 1m0s
[02:59:16.778] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:57:0)
[02:59:16.778] Timer tick, asking Buildbucket for the build status
[02:59:16.939] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:59:16.939] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:58:0) after 1m0s
[03:00:16.971] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:58:0)
[03:00:16.971] Timer tick, asking Buildbucket for the build status
[03:00:17.263] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:00:17.263] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:59:0) after 1m0s
[03:01:17.322] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:59:0)
[03:01:17.322] Timer tick, asking Buildbucket for the build status
[03:01:17.433] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:01:17.433] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:60:0) after 1m0s
[03:02:17.464] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:60:0)
[03:02:17.464] Timer tick, asking Buildbucket for the build status
[03:02:17.567] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:02:17.567] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:61:0) after 1m0s
[03:03:17.601] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:61:0)
[03:03:17.601] Timer tick, asking Buildbucket for the build status
[03:03:18.001] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:03:18.001] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:62:0) after 1m0s
[03:04:18.078] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:62:0)
[03:04:18.078] Timer tick, asking Buildbucket for the build status
[03:04:18.332] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:04:18.332] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:63:0) after 1m0s
[03:05:18.397] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:63:0)
[03:05:18.397] Timer tick, asking Buildbucket for the build status
[03:05:18.706] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:05:18.706] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:64:0) after 1m0s
[03:06:18.829] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:64:0)
[03:06:18.829] Timer tick, asking Buildbucket for the build status
[03:06:19.126] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:06:19.126] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:65:0) after 1m0s
[03:07:19.234] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:65:0)
[03:07:19.234] Timer tick, asking Buildbucket for the build status
[03:07:19.443] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:07:19.443] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:66:0) after 1m0s
[03:08:19.499] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:66:0)
[03:08:19.500] Timer tick, asking Buildbucket for the build status
[03:08:19.672] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:08:19.672] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:67:0) after 1m0s
[03:09:19.683] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:67:0)
[03:09:19.683] Timer tick, asking Buildbucket for the build status
[03:09:19.811] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:09:19.811] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:68:0) after 1m0s
[03:10:19.837] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:68:0)
[03:10:19.837] Timer tick, asking Buildbucket for the build status
[03:10:20.140] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:10:20.140] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:69:0) after 1m0s
[03:11:20.184] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:69:0)
[03:11:20.184] Timer tick, asking Buildbucket for the build status
[03:11:20.282] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:11:20.282] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:70:0) after 1m0s
[03:12:20.347] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:70:0)
[03:12:20.347] Timer tick, asking Buildbucket for the build status
[03:12:20.477] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:12:20.477] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:71:0) after 1m0s
[03:13:20.524] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:71:0)
[03:13:20.524] Timer tick, asking Buildbucket for the build status
[03:13:20.773] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:13:20.773] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:72:0) after 1m0s
[03:14:20.890] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:72:0)
[03:14:20.890] Timer tick, asking Buildbucket for the build status
[03:14:21.019] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:14:21.019] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:73:0) after 1m0s
[03:15:21.127] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:73:0)
[03:15:21.127] Timer tick, asking Buildbucket for the build status
[03:15:21.254] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:15:21.255] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:74:0) after 1m0s
[03:16:21.250] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:74:0)
[03:16:21.250] Timer tick, asking Buildbucket for the build status
[03:16:21.353] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:16:21.353] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:75:0) after 1m0s
[03:17:21.352] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:75:0)
[03:17:21.352] Timer tick, asking Buildbucket for the build status
[03:17:21.599] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:17:21.599] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:76:0) after 1m0s
[03:18:21.648] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:76:0)
[03:18:21.648] Timer tick, asking Buildbucket for the build status
[03:18:21.751] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:18:21.751] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:77:0) after 1m0s
[03:19:21.832] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:77:0)
[03:19:21.832] Timer tick, asking Buildbucket for the build status
[03:19:22.136] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:19:22.136] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:78:0) after 1m0s
[03:20:22.208] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:78:0)
[03:20:22.208] Timer tick, asking Buildbucket for the build status
[03:20:22.893] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:20:22.893] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:79:0) after 1m0s
[03:21:22.984] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:79:0)
[03:21:22.984] Timer tick, asking Buildbucket for the build status
[03:21:23.262] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:21:23.262] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:80:0) after 1m0s
[03:22:23.265] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:80:0)
[03:22:23.265] Timer tick, asking Buildbucket for the build status
[03:22:23.368] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:22:23.368] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:81:0) after 1m0s
[03:23:23.452] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:81:0)
[03:23:23.452] Timer tick, asking Buildbucket for the build status
[03:23:23.641] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:23:23.641] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:82:0) after 1m0s
[03:24:23.740] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:82:0)
[03:24:23.740] Timer tick, asking Buildbucket for the build status
[03:24:23.866] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:24:23.866] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:83:0) after 1m0s
[03:25:23.909] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:83:0)
[03:25:23.909] Timer tick, asking Buildbucket for the build status
[03:25:24.021] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:25:24.021] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:84:0) after 1m0s
[03:26:24.045] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:84:0)
[03:26:24.045] Timer tick, asking Buildbucket for the build status
[03:26:24.149] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:26:24.149] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:85:0) after 1m0s
[03:27:24.165] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:85:0)
[03:27:24.165] Timer tick, asking Buildbucket for the build status
[03:27:24.299] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:27:24.299] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:86:0) after 1m0s
[03:28:24.308] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:86:0)
[03:28:24.308] Timer tick, asking Buildbucket for the build status
[03:28:24.465] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:28:24.465] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:87:0) after 1m0s
[03:29:24.442] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:87:0)
[03:29:24.442] Timer tick, asking Buildbucket for the build status
[03:29:24.547] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:29:24.547] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:88:0) after 1m0s
[03:30:24.576] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:88:0)
[03:30:24.576] Timer tick, asking Buildbucket for the build status
[03:30:24.677] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:30:24.677] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:89:0) after 1m0s
[03:31:24.699] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:89:0)
[03:31:24.699] Timer tick, asking Buildbucket for the build status
[03:31:25.136] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:31:25.136] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:90:0) after 1m0s
[03:32:25.237] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:90:0)
[03:32:25.237] Timer tick, asking Buildbucket for the build status
[03:32:25.327] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:32:25.327] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:91:0) after 1m0s
[03:33:25.402] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:91:0)
[03:33:25.402] Timer tick, asking Buildbucket for the build status
[03:33:25.491] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:33:25.491] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:92:0) after 1m0s
[03:34:25.555] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:92:0)
[03:34:25.555] Timer tick, asking Buildbucket for the build status
[03:34:25.689] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:34:25.689] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:93:0) after 1m0s
[03:35:25.675] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:93:0)
[03:35:25.675] Timer tick, asking Buildbucket for the build status
[03:35:25.788] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:35:25.788] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:94:0) after 1m0s
[03:36:25.881] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:94:0)
[03:36:25.881] Timer tick, asking Buildbucket for the build status
[03:36:26.059] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:36:26.059] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:95:0) after 1m0s
[03:37:26.238] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:95:0)
[03:37:26.238] Timer tick, asking Buildbucket for the build status
[03:37:26.334] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:37:26.334] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:96:0) after 1m0s
[03:38:26.429] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:96:0)
[03:38:26.429] Timer tick, asking Buildbucket for the build status
[03:38:26.734] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:38:26.734] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:97:0) after 1m0s
[03:39:26.763] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:97:0)
[03:39:26.763] Timer tick, asking Buildbucket for the build status
[03:39:26.915] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:39:26.915] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:98:0) after 1m0s
[03:40:26.938] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:98:0)
[03:40:26.938] Timer tick, asking Buildbucket for the build status
[03:40:27.319] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:40:27.319] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:99:0) after 1m0s
[03:41:27.369] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:99:0)
[03:41:27.369] Timer tick, asking Buildbucket for the build status
[03:41:27.510] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:41:27.510] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:100:0) after 1m0s
[03:42:27.553] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:100:0)
[03:42:27.554] Timer tick, asking Buildbucket for the build status
[03:42:27.667] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:42:27.667] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:101:0) after 1m0s
[03:43:27.728] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:101:0)
[03:43:27.728] Timer tick, asking Buildbucket for the build status
[03:43:28.006] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:43:28.006] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:102:0) after 1m0s
[03:44:28.053] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:102:0)
[03:44:28.053] Timer tick, asking Buildbucket for the build status
[03:44:28.308] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:44:28.308] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:103:0) after 1m0s
[03:45:28.481] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:103:0)
[03:45:28.481] Timer tick, asking Buildbucket for the build status
[03:45:28.564] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:45:28.564] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:104:0) after 1m0s
[03:46:28.718] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:104:0)
[03:46:28.718] Timer tick, asking Buildbucket for the build status
[03:46:28.820] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:46:28.820] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:105:0) after 1m0s
[03:47:28.847] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:105:0)
[03:47:28.847] Timer tick, asking Buildbucket for the build status
[03:47:29.114] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:47:29.114] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:106:0) after 1m0s
[03:48:29.160] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:106:0)
[03:48:29.160] Timer tick, asking Buildbucket for the build status
[03:48:29.263] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:48:29.263] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:107:0) after 1m0s
[03:49:29.294] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:107:0)
[03:49:29.294] Timer tick, asking Buildbucket for the build status
[03:49:29.399] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:49:29.399] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:108:0) after 1m0s
[03:50:29.437] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:108:0)
[03:50:29.437] Timer tick, asking Buildbucket for the build status
[03:50:29.710] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:50:29.710] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:109:0) after 1m0s
[03:51:29.731] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:109:0)
[03:51:29.731] Timer tick, asking Buildbucket for the build status
[03:51:30.041] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:51:30.041] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:110:0) after 1m0s
[03:52:30.036] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:110:0)
[03:52:30.036] Timer tick, asking Buildbucket for the build status
[03:52:30.265] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:52:30.265] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:111:0) after 1m0s
[03:53:30.309] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:111:0)
[03:53:30.309] Timer tick, asking Buildbucket for the build status
[03:53:30.434] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:53:30.434] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:112:0) after 1m0s
[03:54:30.431] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:112:0)
[03:54:30.431] Timer tick, asking Buildbucket for the build status
[03:54:30.571] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:54:30.571] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:113:0) after 1m0s
[03:55:30.587] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:113:0)
[03:55:30.587] Timer tick, asking Buildbucket for the build status
[03:55:30.674] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:55:30.674] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:114:0) after 1m0s
[03:56:30.718] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:114:0)
[03:56:30.718] Timer tick, asking Buildbucket for the build status
[03:56:30.835] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:56:30.835] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:115:0) after 1m0s
[03:57:30.825] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:115:0)
[03:57:30.825] Timer tick, asking Buildbucket for the build status
[03:57:31.008] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:57:31.008] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:116:0) after 1m0s
[03:58:30.990] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:116:0)
[03:58:30.990] Timer tick, asking Buildbucket for the build status
[03:58:31.087] Build 8855631146253859168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:58:31.087] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9021061208517984800:117:0) after 1m0s
[03:59:22.436] Received PubSub notification, asking Buildbucket for the build status
[03:59:22.544] Build 8855631146253859168: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[03:59:22.544] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1613015961991260",
"created_by": "project:nacl",
"created_ts": "1613009042458091",
"failure_reason": "BUILD_FAILURE",
"id": "8855631146253859168",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_32\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"title\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}}",
"project": "nacl",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step('annotated steps') (retcode: 1)\"}, \"properties\": {\"$build/goma\": {\"enable_ats\": true, \"rpc_extra_params\": \"?prod\", \"server_host\": \"goma.chromium.org\"}, \"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"title\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\"}]}, \"bot_id\": \"luci-nacl-toolchain-xenial-1-0vnt\", \"branch\": \"refs/heads/master\", \"builder_group\": \"client.nacl.toolchain\", \"buildername\": \"linux-pnacl-x86_64-tests-x86_32\", \"buildnumber\": 5181, \"got_revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"82ac8c0a6f0d3ffc843c693dd5149a356b866ae5\", \"slavetype\": \"BuilderTester\"}, \"swarming\": {\"bot_dimensions\": {\"cores\": [\"16\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gcp\": [\"google.com:chromecompute\"], \"gpu\": [\"none\"], \"id\": [\"luci-nacl-toolchain-xenial-1-0vnt\"], \"image\": [\"chrome-xenial-21011100-9488e34e558\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"n1-standard-16\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16\", \"Ubuntu-16.04\", \"Ubuntu-16.04.6\"], \"pool\": [\"luci.nacl.toolchain\"], \"python\": [\"2.7.12\"], \"server_version\": [\"5685-1877293\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-b\"]}}, \"ui\": {\"info\": \"Step('annotated steps') (retcode: 1)\"}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1613009048742759",
"status": "COMPLETED",
"status_changed_ts": "1613009053366950",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_32/5181",
"builder:linux-pnacl-x86_64-tests-x86_32",
"buildset:commit/git/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/82ac8c0a6f0d3ffc843c693dd5149a356b866ae5",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9021061208517984800",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8855631146253859168/+/annotations",
"swarming_tag:luci_project:nacl",
"swarming_tag:os:Linux",
"swarming_tag:recipe_name:nacl",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:51a7a6560acf2510",
"user_agent:luci-scheduler"
],
"updated_ts": "1613015962062368",
"url": "https://ci.chromium.org/b/8855631146253859168",
"utcnow_ts": "1613015962535813"
}
}
[03:59:22.544] Invocation finished in 1h55m21.628845391s with status FAILED