[09:32:00.426] New invocation is queued and will start shortly
[09:32:01.655] Starting the invocation (attempt 1)
[09:32:01.696] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[09:32:01.696] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[09:32:01.697] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9023479141437664352",
"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\":\"cb31feffa500401c95c6c44d88b7c358236bca36\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@cb31feffa500401c95c6c44d88b7c358236bca36\",\"title\":\"cb31feffa500401c95c6c44d88b7c358236bca36\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/cb31feffa500401c95c6c44d88b7c358236bca36\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"cb31feffa500401c95c6c44d88b7c358236bca36\"}}",
"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:9023479141437664352",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
"user_agent:luci-scheduler",
"buildset:commit/git/cb31feffa500401c95c6c44d88b7c358236bca36",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/cb31feffa500401c95c6c44d88b7c358236bca36",
"gitiles_ref:refs/heads/master"
]
}
[09:32:02.704] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1610703121847113",
"id": "8858049079264772480",
"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\": \"cb31feffa500401c95c6c44d88b7c358236bca36\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@cb31feffa500401c95c6c44d88b7c358236bca36\", \"title\": \"cb31feffa500401c95c6c44d88b7c358236bca36\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/cb31feffa500401c95c6c44d88b7c358236bca36\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"cb31feffa500401c95c6c44d88b7c358236bca36\"}}",
"project": "nacl",
"result_details_json": "{\"properties\": {}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1610703122381754",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_32/5176",
"builder:linux-pnacl-x86_64-tests-x86_32",
"buildset:commit/git/cb31feffa500401c95c6c44d88b7c358236bca36",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/cb31feffa500401c95c6c44d88b7c358236bca36",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9023479141437664352",
"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/8858049079264772480/+/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": "1610703122382577",
"url": "https://ci.chromium.org/b/8858049079264772480",
"utcnow_ts": "1610703122696417"
}
}
[09:32:02.704] Task URL: https://ci.chromium.org/b/8858049079264772480
[09:32:02.704] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:2:0) after 1m0s
[09:32:59.783] Received PubSub notification, asking Buildbucket for the build status
[09:32:59.872] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:33:02.761] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:2:0)
[09:33:02.761] Timer tick, asking Buildbucket for the build status
[09:33:02.972] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:33:02.972] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:4:0) after 1m0s
[09:34:03.069] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:4:0)
[09:34:03.069] Timer tick, asking Buildbucket for the build status
[09:34:03.294] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:34:03.294] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:5:0) after 1m0s
[09:35:03.335] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:5:0)
[09:35:03.335] Timer tick, asking Buildbucket for the build status
[09:35:03.436] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:35:03.436] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:6:0) after 1m0s
[09:36:03.646] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:6:0)
[09:36:03.646] Timer tick, asking Buildbucket for the build status
[09:36:03.751] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:36:03.751] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:7:0) after 1m0s
[09:37:03.806] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:7:0)
[09:37:03.806] Timer tick, asking Buildbucket for the build status
[09:37:04.170] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:37:04.170] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:8:0) after 1m0s
[09:38:04.303] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:8:0)
[09:38:04.303] Timer tick, asking Buildbucket for the build status
[09:38:04.403] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:38:04.403] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:9:0) after 1m0s
[09:39:04.468] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:9:0)
[09:39:04.468] Timer tick, asking Buildbucket for the build status
[09:39:04.755] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:39:04.755] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:10:0) after 1m0s
[09:40:04.777] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:10:0)
[09:40:04.777] Timer tick, asking Buildbucket for the build status
[09:40:04.959] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:40:04.959] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:11:0) after 1m0s
[09:41:05.152] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:11:0)
[09:41:05.152] Timer tick, asking Buildbucket for the build status
[09:41:05.358] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:41:05.358] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:12:0) after 1m0s
[09:42:05.516] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:12:0)
[09:42:05.516] Timer tick, asking Buildbucket for the build status
[09:42:05.608] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:42:05.608] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:13:0) after 1m0s
[09:43:05.631] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:13:0)
[09:43:05.631] Timer tick, asking Buildbucket for the build status
[09:43:05.698] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:43:05.698] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:14:0) after 1m0s
[09:44:05.735] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:14:0)
[09:44:05.735] Timer tick, asking Buildbucket for the build status
[09:44:06.118] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:44:06.118] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:15:0) after 1m0s
[09:45:06.172] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:15:0)
[09:45:06.172] Timer tick, asking Buildbucket for the build status
[09:45:06.233] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:45:06.233] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:16:0) after 1m0s
[09:46:06.258] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:16:0)
[09:46:06.258] Timer tick, asking Buildbucket for the build status
[09:46:06.326] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:46:06.326] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:17:0) after 1m0s
[09:47:06.362] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:17:0)
[09:47:06.362] Timer tick, asking Buildbucket for the build status
[09:47:07.231] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:47:07.231] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:18:0) after 1m0s
[09:48:07.297] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:18:0)
[09:48:07.297] Timer tick, asking Buildbucket for the build status
[09:48:07.390] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:48:07.390] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:19:0) after 1m0s
[09:49:07.461] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:19:0)
[09:49:07.461] Timer tick, asking Buildbucket for the build status
[09:49:07.567] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:49:07.567] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:20:0) after 1m0s
[09:50:07.649] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:20:0)
[09:50:07.649] Timer tick, asking Buildbucket for the build status
[09:50:07.808] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:50:07.808] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:21:0) after 1m0s
[09:51:07.884] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:21:0)
[09:51:07.884] Timer tick, asking Buildbucket for the build status
[09:51:08.361] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:51:08.361] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:22:0) after 1m0s
[09:52:08.386] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:22:0)
[09:52:08.386] Timer tick, asking Buildbucket for the build status
[09:52:09.258] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:52:09.258] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:23:0) after 1m0s
[09:53:09.325] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:23:0)
[09:53:09.325] Timer tick, asking Buildbucket for the build status
[09:53:09.413] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:53:09.413] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:24:0) after 1m0s
[09:54:09.399] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:24:0)
[09:54:09.399] Timer tick, asking Buildbucket for the build status
[09:54:09.748] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:54:09.748] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:25:0) after 1m0s
[09:55:09.768] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:25:0)
[09:55:09.768] Timer tick, asking Buildbucket for the build status
[09:55:09.883] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:55:09.883] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:26:0) after 1m0s
[09:56:09.939] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:26:0)
[09:56:09.939] Timer tick, asking Buildbucket for the build status
[09:56:10.032] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:56:10.032] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:27:0) after 1m0s
[09:57:10.117] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:27:0)
[09:57:10.117] Timer tick, asking Buildbucket for the build status
[09:57:10.212] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:57:10.212] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:28:0) after 1m0s
[09:58:10.298] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:28:0)
[09:58:10.298] Timer tick, asking Buildbucket for the build status
[09:58:10.364] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:58:10.364] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:29:0) after 1m0s
[09:59:10.524] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:29:0)
[09:59:10.524] Timer tick, asking Buildbucket for the build status
[09:59:10.744] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[09:59:10.744] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:30:0) after 1m0s
[10:00:10.808] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:30:0)
[10:00:10.808] Timer tick, asking Buildbucket for the build status
[10:00:11.111] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:00:11.111] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:31:0) after 1m0s
[10:01:11.201] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:31:0)
[10:01:11.201] Timer tick, asking Buildbucket for the build status
[10:01:11.413] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:01:11.413] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:32:0) after 1m0s
[10:02:11.675] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:32:0)
[10:02:11.675] Timer tick, asking Buildbucket for the build status
[10:02:11.785] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:02:11.785] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:33:0) after 1m0s
[10:03:11.801] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:33:0)
[10:03:11.801] Timer tick, asking Buildbucket for the build status
[10:03:11.879] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:03:11.879] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:34:0) after 1m0s
[10:04:11.923] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:34:0)
[10:04:11.923] Timer tick, asking Buildbucket for the build status
[10:04:12.298] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:04:12.298] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:35:0) after 1m0s
[10:05:12.354] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:35:0)
[10:05:12.354] Timer tick, asking Buildbucket for the build status
[10:05:12.414] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:05:12.414] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:36:0) after 1m0s
[10:06:12.506] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:36:0)
[10:06:12.506] Timer tick, asking Buildbucket for the build status
[10:06:12.622] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:06:12.622] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:37:0) after 1m0s
[10:07:12.612] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:37:0)
[10:07:12.612] Timer tick, asking Buildbucket for the build status
[10:07:12.945] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:07:12.945] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:38:0) after 1m0s
[10:08:13.028] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:38:0)
[10:08:13.028] Timer tick, asking Buildbucket for the build status
[10:08:13.533] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:08:13.533] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:39:0) after 1m0s
[10:09:13.635] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:39:0)
[10:09:13.635] Timer tick, asking Buildbucket for the build status
[10:09:13.720] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:09:13.720] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:40:0) after 1m0s
[10:10:13.779] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:40:0)
[10:10:13.779] Timer tick, asking Buildbucket for the build status
[10:10:13.836] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:10:13.836] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:41:0) after 1m0s
[10:11:13.861] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:41:0)
[10:11:13.861] Timer tick, asking Buildbucket for the build status
[10:11:13.928] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:11:13.928] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:42:0) after 1m0s
[10:12:13.949] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:42:0)
[10:12:13.949] Timer tick, asking Buildbucket for the build status
[10:12:14.364] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:12:14.364] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:43:0) after 1m0s
[10:13:14.444] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:43:0)
[10:13:14.444] Timer tick, asking Buildbucket for the build status
[10:13:14.513] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:13:14.513] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:44:0) after 1m0s
[10:14:14.508] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:44:0)
[10:14:14.508] Timer tick, asking Buildbucket for the build status
[10:14:14.588] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:14:14.588] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:45:0) after 1m0s
[10:15:14.611] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:45:0)
[10:15:14.611] Timer tick, asking Buildbucket for the build status
[10:15:14.687] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:15:14.687] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:46:0) after 1m0s
[10:16:14.745] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:46:0)
[10:16:14.745] Timer tick, asking Buildbucket for the build status
[10:16:14.825] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:16:14.825] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:47:0) after 1m0s
[10:17:14.863] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:47:0)
[10:17:14.863] Timer tick, asking Buildbucket for the build status
[10:17:15.036] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:17:15.037] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:48:0) after 1m0s
[10:18:15.146] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:48:0)
[10:18:15.146] Timer tick, asking Buildbucket for the build status
[10:18:15.234] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:18:15.234] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:49:0) after 1m0s
[10:19:15.268] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:49:0)
[10:19:15.268] Timer tick, asking Buildbucket for the build status
[10:19:15.396] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:19:15.396] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:50:0) after 1m0s
[10:20:15.491] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:50:0)
[10:20:15.491] Timer tick, asking Buildbucket for the build status
[10:20:16.073] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:20:16.073] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:51:0) after 1m0s
[10:21:16.205] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:51:0)
[10:21:16.205] Timer tick, asking Buildbucket for the build status
[10:21:16.502] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:21:16.502] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:52:0) after 1m0s
[10:22:16.591] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:52:0)
[10:22:16.591] Timer tick, asking Buildbucket for the build status
[10:22:16.686] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:22:16.686] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:53:0) after 1m0s
[10:23:16.783] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:53:0)
[10:23:16.783] Timer tick, asking Buildbucket for the build status
[10:23:17.218] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:23:17.218] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:54:0) after 1m0s
[10:24:17.263] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:54:0)
[10:24:17.263] Timer tick, asking Buildbucket for the build status
[10:24:17.359] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:24:17.359] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:55:0) after 1m0s
[10:25:17.383] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:55:0)
[10:25:17.383] Timer tick, asking Buildbucket for the build status
[10:25:17.448] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:25:17.448] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:56:0) after 1m0s
[10:26:17.548] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:56:0)
[10:26:17.548] Timer tick, asking Buildbucket for the build status
[10:26:17.626] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:26:17.626] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:57:0) after 1m0s
[10:27:17.739] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:57:0)
[10:27:17.739] Timer tick, asking Buildbucket for the build status
[10:27:17.838] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:27:17.838] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:58:0) after 1m0s
[10:28:17.888] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:58:0)
[10:28:17.888] Timer tick, asking Buildbucket for the build status
[10:28:17.951] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:28:17.951] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:59:0) after 1m0s
[10:29:18.044] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:59:0)
[10:29:18.045] Timer tick, asking Buildbucket for the build status
[10:29:18.111] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:29:18.111] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:60:0) after 1m0s
[10:30:18.190] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:60:0)
[10:30:18.190] Timer tick, asking Buildbucket for the build status
[10:30:18.438] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:30:18.438] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:61:0) after 1m0s
[10:31:18.529] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:61:0)
[10:31:18.529] Timer tick, asking Buildbucket for the build status
[10:31:18.604] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:31:18.604] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:62:0) after 1m0s
[10:32:18.629] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:62:0)
[10:32:18.629] Timer tick, asking Buildbucket for the build status
[10:32:18.721] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:32:18.721] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:63:0) after 1m0s
[10:33:18.784] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:63:0)
[10:33:18.784] Timer tick, asking Buildbucket for the build status
[10:33:18.912] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:33:18.912] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:64:0) after 1m0s
[10:34:18.977] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:64:0)
[10:34:18.977] Timer tick, asking Buildbucket for the build status
[10:34:19.037] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:34:19.037] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:65:0) after 1m0s
[10:35:19.154] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:65:0)
[10:35:19.154] Timer tick, asking Buildbucket for the build status
[10:35:19.335] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:35:19.335] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:66:0) after 1m0s
[10:36:19.417] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:66:0)
[10:36:19.417] Timer tick, asking Buildbucket for the build status
[10:36:19.474] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:36:19.474] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:67:0) after 1m0s
[10:37:19.545] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:67:0)
[10:37:19.545] Timer tick, asking Buildbucket for the build status
[10:37:19.667] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:37:19.667] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:68:0) after 1m0s
[10:38:19.724] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:68:0)
[10:38:19.724] Timer tick, asking Buildbucket for the build status
[10:38:19.798] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:38:19.798] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:69:0) after 1m0s
[10:39:19.910] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:69:0)
[10:39:19.910] Timer tick, asking Buildbucket for the build status
[10:39:20.102] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:39:20.102] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:70:0) after 1m0s
[10:40:20.229] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:70:0)
[10:40:20.229] Timer tick, asking Buildbucket for the build status
[10:40:20.443] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:40:20.444] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:71:0) after 1m0s
[10:41:20.519] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:71:0)
[10:41:20.519] Timer tick, asking Buildbucket for the build status
[10:41:20.597] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:41:20.598] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:72:0) after 1m0s
[10:42:20.746] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:72:0)
[10:42:20.746] Timer tick, asking Buildbucket for the build status
[10:42:21.055] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:42:21.055] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:73:0) after 1m0s
[10:43:21.172] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:73:0)
[10:43:21.172] Timer tick, asking Buildbucket for the build status
[10:43:21.347] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:43:21.347] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:74:0) after 1m0s
[10:44:21.506] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:74:0)
[10:44:21.506] Timer tick, asking Buildbucket for the build status
[10:44:21.598] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:44:21.598] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:75:0) after 1m0s
[10:45:21.714] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:75:0)
[10:45:21.714] Timer tick, asking Buildbucket for the build status
[10:45:21.773] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:45:21.773] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:76:0) after 1m0s
[10:46:21.849] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:76:0)
[10:46:21.849] Timer tick, asking Buildbucket for the build status
[10:46:22.279] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:46:22.279] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:77:0) after 1m0s
[10:47:22.442] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:77:0)
[10:47:22.442] Timer tick, asking Buildbucket for the build status
[10:47:22.612] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:47:22.612] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:78:0) after 1m0s
[10:48:22.649] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:78:0)
[10:48:22.649] Timer tick, asking Buildbucket for the build status
[10:48:22.741] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:48:22.741] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:79:0) after 1m0s
[10:49:22.823] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:79:0)
[10:49:22.823] Timer tick, asking Buildbucket for the build status
[10:49:22.883] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:49:22.883] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:80:0) after 1m0s
[10:50:22.895] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:80:0)
[10:50:22.895] Timer tick, asking Buildbucket for the build status
[10:50:23.074] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:50:23.074] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:81:0) after 1m0s
[10:51:23.129] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:81:0)
[10:51:23.129] Timer tick, asking Buildbucket for the build status
[10:51:23.332] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:51:23.332] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:82:0) after 1m0s
[10:52:23.385] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:82:0)
[10:52:23.385] Timer tick, asking Buildbucket for the build status
[10:52:23.805] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:52:23.805] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:83:0) after 1m0s
[10:53:23.854] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:83:0)
[10:53:23.854] Timer tick, asking Buildbucket for the build status
[10:53:23.907] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:53:23.907] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:84:0) after 1m0s
[10:54:24.349] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:84:0)
[10:54:24.349] Timer tick, asking Buildbucket for the build status
[10:54:24.420] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:54:24.420] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:85:0) after 1m0s
[10:55:26.655] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:85:0)
[10:55:26.655] Timer tick, asking Buildbucket for the build status
[10:55:26.719] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:55:26.719] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:86:0) after 1m0s
[10:56:26.762] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:86:0)
[10:56:26.762] Timer tick, asking Buildbucket for the build status
[10:56:27.020] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:56:27.020] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:87:0) after 1m0s
[10:57:27.023] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:87:0)
[10:57:27.023] Timer tick, asking Buildbucket for the build status
[10:57:27.136] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:57:27.136] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:88:0) after 1m0s
[10:58:27.179] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:88:0)
[10:58:27.179] Timer tick, asking Buildbucket for the build status
[10:58:27.240] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:58:27.240] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:89:0) after 1m0s
[10:59:27.299] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:89:0)
[10:59:27.299] Timer tick, asking Buildbucket for the build status
[10:59:27.367] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:59:27.368] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:90:0) after 1m0s
[11:00:27.459] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:90:0)
[11:00:27.459] Timer tick, asking Buildbucket for the build status
[11:00:28.228] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:00:28.229] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:91:0) after 1m0s
[11:01:28.377] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:91:0)
[11:01:28.377] Timer tick, asking Buildbucket for the build status
[11:01:28.448] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:01:28.448] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:92:0) after 1m0s
[11:02:28.512] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:92:0)
[11:02:28.512] Timer tick, asking Buildbucket for the build status
[11:02:29.133] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:02:29.133] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:93:0) after 1m0s
[11:03:29.232] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:93:0)
[11:03:29.232] Timer tick, asking Buildbucket for the build status
[11:03:29.290] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:03:29.290] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:94:0) after 1m0s
[11:04:29.326] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:94:0)
[11:04:29.326] Timer tick, asking Buildbucket for the build status
[11:04:29.386] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:04:29.386] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:95:0) after 1m0s
[11:05:29.447] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:95:0)
[11:05:29.447] Timer tick, asking Buildbucket for the build status
[11:05:29.646] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:05:29.646] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:96:0) after 1m0s
[11:06:29.707] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:96:0)
[11:06:29.707] Timer tick, asking Buildbucket for the build status
[11:06:29.822] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:06:29.822] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:97:0) after 1m0s
[11:07:29.843] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:97:0)
[11:07:29.843] Timer tick, asking Buildbucket for the build status
[11:07:30.015] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:07:30.015] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:98:0) after 1m0s
[11:08:30.078] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:98:0)
[11:08:30.078] Timer tick, asking Buildbucket for the build status
[11:08:30.162] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:08:30.162] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:99:0) after 1m0s
[11:09:30.309] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:99:0)
[11:09:30.309] Timer tick, asking Buildbucket for the build status
[11:09:30.422] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:09:30.422] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:100:0) after 1m0s
[11:10:30.450] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:100:0)
[11:10:30.450] Timer tick, asking Buildbucket for the build status
[11:10:30.725] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:10:30.725] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:101:0) after 1m0s
[11:11:30.751] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:101:0)
[11:11:30.751] Timer tick, asking Buildbucket for the build status
[11:11:31.032] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:11:31.032] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:102:0) after 1m0s
[11:12:31.071] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:102:0)
[11:12:31.071] Timer tick, asking Buildbucket for the build status
[11:12:31.591] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:12:31.592] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:103:0) after 1m0s
[11:13:31.648] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:103:0)
[11:13:31.648] Timer tick, asking Buildbucket for the build status
[11:13:31.967] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:13:31.967] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:104:0) after 1m0s
[11:14:32.045] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:104:0)
[11:14:32.045] Timer tick, asking Buildbucket for the build status
[11:14:32.117] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:14:32.117] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:105:0) after 1m0s
[11:15:32.194] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:105:0)
[11:15:32.194] Timer tick, asking Buildbucket for the build status
[11:15:32.304] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:15:32.304] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:106:0) after 1m0s
[11:16:32.401] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:106:0)
[11:16:32.401] Timer tick, asking Buildbucket for the build status
[11:16:32.535] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:16:32.535] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:107:0) after 1m0s
[11:17:32.584] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:107:0)
[11:17:32.584] Timer tick, asking Buildbucket for the build status
[11:17:32.691] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:17:32.692] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:108:0) after 1m0s
[11:18:32.742] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:108:0)
[11:18:32.742] Timer tick, asking Buildbucket for the build status
[11:18:32.849] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:18:32.849] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:109:0) after 1m0s
[11:19:32.898] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:109:0)
[11:19:32.898] Timer tick, asking Buildbucket for the build status
[11:19:32.998] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:19:32.998] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:110:0) after 1m0s
[11:20:33.031] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:110:0)
[11:20:33.031] Timer tick, asking Buildbucket for the build status
[11:20:33.159] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:20:33.159] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:111:0) after 1m0s
[11:21:33.231] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:111:0)
[11:21:33.231] Timer tick, asking Buildbucket for the build status
[11:21:33.336] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:21:33.336] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:112:0) after 1m0s
[11:22:33.767] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:112:0)
[11:22:33.767] Timer tick, asking Buildbucket for the build status
[11:22:34.204] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:22:34.204] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:113:0) after 1m0s
[11:23:34.321] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:113:0)
[11:23:34.321] Timer tick, asking Buildbucket for the build status
[11:23:34.390] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:23:34.390] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:114:0) after 1m0s
[11:24:34.442] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:114:0)
[11:24:34.442] Timer tick, asking Buildbucket for the build status
[11:24:34.502] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:24:34.502] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:115:0) after 1m0s
[11:25:34.524] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:115:0)
[11:25:34.524] Timer tick, asking Buildbucket for the build status
[11:25:34.618] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:25:34.618] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:116:0) after 1m0s
[11:26:34.677] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:116:0)
[11:26:34.677] Timer tick, asking Buildbucket for the build status
[11:26:34.827] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:26:34.827] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:117:0) after 1m0s
[11:27:34.942] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:117:0)
[11:27:34.942] Timer tick, asking Buildbucket for the build status
[11:27:35.045] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:27:35.046] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:118:0) after 1m0s
[11:28:35.095] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:118:0)
[11:28:35.095] Timer tick, asking Buildbucket for the build status
[11:28:35.230] Build 8858049079264772480: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:28:35.230] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9023479141437664352:119:0) after 1m0s
[11:29:08.374] Received PubSub notification, asking Buildbucket for the build status
[11:29:08.437] Build 8858049079264772480: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[11:29:08.437] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1610710147513178",
"created_by": "project:nacl",
"created_ts": "1610703121847113",
"failure_reason": "BUILD_FAILURE",
"id": "8858049079264772480",
"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\": \"cb31feffa500401c95c6c44d88b7c358236bca36\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@cb31feffa500401c95c6c44d88b7c358236bca36\", \"title\": \"cb31feffa500401c95c6c44d88b7c358236bca36\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/cb31feffa500401c95c6c44d88b7c358236bca36\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"cb31feffa500401c95c6c44d88b7c358236bca36\"}}",
"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\": \"cb31feffa500401c95c6c44d88b7c358236bca36\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@cb31feffa500401c95c6c44d88b7c358236bca36\", \"title\": \"cb31feffa500401c95c6c44d88b7c358236bca36\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/cb31feffa500401c95c6c44d88b7c358236bca36\"}]}, \"bot_id\": \"luci-nacl-toolchain-xenial-0-27hj\", \"branch\": \"refs/heads/master\", \"builder_group\": \"client.nacl.toolchain\", \"buildername\": \"linux-pnacl-x86_64-tests-x86_32\", \"buildnumber\": 5176, \"got_revision\": \"cb31feffa500401c95c6c44d88b7c358236bca36\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"cb31feffa500401c95c6c44d88b7c358236bca36\", \"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-0-27hj\"], \"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\": [\"5666-679c9bd\"], \"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": "1610703178903070",
"status": "COMPLETED",
"status_changed_ts": "1610703179406174",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_32/5176",
"builder:linux-pnacl-x86_64-tests-x86_32",
"buildset:commit/git/cb31feffa500401c95c6c44d88b7c358236bca36",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/cb31feffa500401c95c6c44d88b7c358236bca36",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9023479141437664352",
"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/8858049079264772480/+/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:511e34bc2d019910",
"user_agent:luci-scheduler"
],
"updated_ts": "1610710147879166",
"url": "https://ci.chromium.org/b/8858049079264772480",
"utcnow_ts": "1610710148429907"
}
}
[11:29:08.437] Invocation finished in 1h57m8.045602858s with status FAILED