[10:38:33.378] New invocation is queued and will start shortly
[10:38:34.441] Starting the invocation (attempt 1)
[10:38:34.489] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[10:38:34.489] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[10:38:34.489] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9019398091015259264",
"parameters_json": "{\"builder_name\":\"linux-pnacl-x86_64-tests-x86_64\",\"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\":\"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\",\"title\":\"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux-pnacl-x86_64-tests-x86_64",
"scheduler_invocation_id:9019398091015259264",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_64",
"user_agent:luci-scheduler",
"buildset:commit/git/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a",
"gitiles_ref:refs/heads/master"
]
}
[10:38:36.896] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1614595115713740",
"id": "8853968027904389456",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_64\", \"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\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"title\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}}",
"project": "nacl",
"result_details_json": "{\"properties\": {}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1614595116607546",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_64/5132",
"builder:linux-pnacl-x86_64-tests-x86_64",
"buildset:commit/git/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9019398091015259264",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_64",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8853968027904389456/+/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": "1614595116607647",
"url": "https://ci.chromium.org/b/8853968027904389456",
"utcnow_ts": "1614595116885325"
}
}
[10:38:36.896] Task URL: https://ci.chromium.org/b/8853968027904389456
[10:38:36.896] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:2:0) after 1m0s
[10:39:37.567] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:2:0)
[10:39:37.567] Timer tick, asking Buildbucket for the build status
[10:39:37.670] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:39:37.670] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:3:0) after 1m0s
[10:40:37.783] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:3:0)
[10:40:37.783] Timer tick, asking Buildbucket for the build status
[10:40:37.931] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:40:37.931] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:4:0) after 1m0s
[10:41:38.008] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:4:0)
[10:41:38.008] Timer tick, asking Buildbucket for the build status
[10:41:38.147] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:41:38.147] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:5:0) after 1m0s
[10:42:38.396] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:5:0)
[10:42:38.396] Timer tick, asking Buildbucket for the build status
[10:42:38.600] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:42:38.600] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:6:0) after 1m0s
[10:43:38.651] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:6:0)
[10:43:38.651] Timer tick, asking Buildbucket for the build status
[10:43:38.835] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:43:38.835] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:7:0) after 1m0s
[10:44:38.873] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:7:0)
[10:44:38.873] Timer tick, asking Buildbucket for the build status
[10:44:39.236] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:44:39.236] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:8:0) after 1m0s
[10:45:39.268] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:8:0)
[10:45:39.268] Timer tick, asking Buildbucket for the build status
[10:45:39.469] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:45:39.469] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:9:0) after 1m0s
[10:46:39.536] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:9:0)
[10:46:39.536] Timer tick, asking Buildbucket for the build status
[10:46:39.598] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:46:39.598] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:10:0) after 1m0s
[10:47:39.649] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:10:0)
[10:47:39.649] Timer tick, asking Buildbucket for the build status
[10:47:39.797] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:47:39.797] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:11:0) after 1m0s
[10:48:39.801] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:11:0)
[10:48:39.801] Timer tick, asking Buildbucket for the build status
[10:48:39.877] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:48:39.877] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:12:0) after 1m0s
[10:49:39.846] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:12:0)
[10:49:39.846] Timer tick, asking Buildbucket for the build status
[10:49:39.960] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:49:39.960] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:13:0) after 1m0s
[10:50:40.008] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:13:0)
[10:50:40.008] Timer tick, asking Buildbucket for the build status
[10:50:40.075] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:50:40.075] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:14:0) after 1m0s
[10:51:40.091] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:14:0)
[10:51:40.091] Timer tick, asking Buildbucket for the build status
[10:51:40.158] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:51:40.158] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:15:0) after 1m0s
[10:52:40.183] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:15:0)
[10:52:40.184] Timer tick, asking Buildbucket for the build status
[10:52:40.256] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:52:40.256] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:16:0) after 1m0s
[10:53:40.287] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:16:0)
[10:53:40.287] Timer tick, asking Buildbucket for the build status
[10:53:40.438] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:53:40.438] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:17:0) after 1m0s
[10:54:40.461] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:17:0)
[10:54:40.461] Timer tick, asking Buildbucket for the build status
[10:54:40.546] Build 8853968027904389456: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[10:54:40.546] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:18:0) after 1m0s
[10:54:54.261] Received PubSub notification, asking Buildbucket for the build status
[10:54:54.357] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:55:40.566] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:18:0)
[10:55:40.566] Timer tick, asking Buildbucket for the build status
[10:55:40.674] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:55:40.674] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:20:0) after 1m0s
[10:56:40.774] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:20:0)
[10:56:40.774] Timer tick, asking Buildbucket for the build status
[10:56:40.866] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:56:40.866] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:21:0) after 1m0s
[10:57:40.869] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:21:0)
[10:57:40.869] Timer tick, asking Buildbucket for the build status
[10:57:41.153] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:57:41.153] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:22:0) after 1m0s
[10:58:41.172] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:22:0)
[10:58:41.172] Timer tick, asking Buildbucket for the build status
[10:58:41.257] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:58:41.257] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:23:0) after 1m0s
[10:59:41.282] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:23:0)
[10:59:41.282] Timer tick, asking Buildbucket for the build status
[10:59:41.441] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[10:59:41.441] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:24:0) after 1m0s
[11:00:41.498] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:24:0)
[11:00:41.498] Timer tick, asking Buildbucket for the build status
[11:00:41.582] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:00:41.582] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:25:0) after 1m0s
[11:01:41.608] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:25:0)
[11:01:41.608] Timer tick, asking Buildbucket for the build status
[11:01:41.695] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:01:41.695] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:26:0) after 1m0s
[11:02:41.750] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:26:0)
[11:02:41.750] Timer tick, asking Buildbucket for the build status
[11:02:41.828] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:02:41.828] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:27:0) after 1m0s
[11:03:41.843] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:27:0)
[11:03:41.843] Timer tick, asking Buildbucket for the build status
[11:03:41.922] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:03:41.922] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:28:0) after 1m0s
[11:04:41.976] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:28:0)
[11:04:41.976] Timer tick, asking Buildbucket for the build status
[11:04:42.114] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:04:42.114] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:29:0) after 1m0s
[11:05:42.130] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:29:0)
[11:05:42.130] Timer tick, asking Buildbucket for the build status
[11:05:42.219] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:05:42.219] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:30:0) after 1m0s
[11:06:42.238] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:30:0)
[11:06:42.238] Timer tick, asking Buildbucket for the build status
[11:06:42.319] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:06:42.319] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:31:0) after 1m0s
[11:07:42.337] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:31:0)
[11:07:42.337] Timer tick, asking Buildbucket for the build status
[11:07:42.433] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:07:42.433] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:32:0) after 1m0s
[11:08:42.423] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:32:0)
[11:08:42.423] Timer tick, asking Buildbucket for the build status
[11:08:42.509] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:08:42.509] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:33:0) after 1m0s
[11:09:42.534] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:33:0)
[11:09:42.534] Timer tick, asking Buildbucket for the build status
[11:09:42.618] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:09:42.618] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:34:0) after 1m0s
[11:10:42.616] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:34:0)
[11:10:42.616] Timer tick, asking Buildbucket for the build status
[11:10:42.826] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:10:42.826] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:35:0) after 1m0s
[11:11:42.851] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:35:0)
[11:11:42.851] Timer tick, asking Buildbucket for the build status
[11:11:43.383] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:11:43.383] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:36:0) after 1m0s
[11:12:43.437] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:36:0)
[11:12:43.437] Timer tick, asking Buildbucket for the build status
[11:12:43.529] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:12:43.529] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:37:0) after 1m0s
[11:13:43.578] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:37:0)
[11:13:43.578] Timer tick, asking Buildbucket for the build status
[11:13:43.649] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:13:43.649] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:38:0) after 1m0s
[11:14:43.715] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:38:0)
[11:14:43.715] Timer tick, asking Buildbucket for the build status
[11:14:43.837] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:14:43.837] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:39:0) after 1m0s
[11:15:43.974] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:39:0)
[11:15:43.974] Timer tick, asking Buildbucket for the build status
[11:15:44.307] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:15:44.307] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:40:0) after 1m0s
[11:16:44.408] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:40:0)
[11:16:44.408] Timer tick, asking Buildbucket for the build status
[11:16:44.720] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:16:44.720] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:41:0) after 1m0s
[11:17:44.726] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:41:0)
[11:17:44.726] Timer tick, asking Buildbucket for the build status
[11:17:44.796] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:17:44.796] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:42:0) after 1m0s
[11:18:44.817] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:42:0)
[11:18:44.817] Timer tick, asking Buildbucket for the build status
[11:18:44.903] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:18:44.903] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:43:0) after 1m0s
[11:19:44.947] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:43:0)
[11:19:44.947] Timer tick, asking Buildbucket for the build status
[11:19:45.051] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:19:45.051] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:44:0) after 1m0s
[11:20:45.076] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:44:0)
[11:20:45.076] Timer tick, asking Buildbucket for the build status
[11:20:45.156] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:20:45.156] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:45:0) after 1m0s
[11:21:45.217] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:45:0)
[11:21:45.217] Timer tick, asking Buildbucket for the build status
[11:21:45.322] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:21:45.322] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:46:0) after 1m0s
[11:22:45.334] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:46:0)
[11:22:45.334] Timer tick, asking Buildbucket for the build status
[11:22:45.875] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:22:45.875] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:47:0) after 1m0s
[11:23:45.989] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:47:0)
[11:23:45.989] Timer tick, asking Buildbucket for the build status
[11:23:46.072] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:23:46.072] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:48:0) after 1m0s
[11:24:46.061] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:48:0)
[11:24:46.061] Timer tick, asking Buildbucket for the build status
[11:24:46.194] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:24:46.194] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:49:0) after 1m0s
[11:25:46.240] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:49:0)
[11:25:46.240] Timer tick, asking Buildbucket for the build status
[11:25:46.319] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:25:46.319] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:50:0) after 1m0s
[11:26:46.339] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:50:0)
[11:26:46.339] Timer tick, asking Buildbucket for the build status
[11:26:46.566] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:26:46.566] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:51:0) after 1m0s
[11:27:46.628] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:51:0)
[11:27:46.628] Timer tick, asking Buildbucket for the build status
[11:27:46.705] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:27:46.705] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:52:0) after 1m0s
[11:28:46.719] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:52:0)
[11:28:46.720] Timer tick, asking Buildbucket for the build status
[11:28:46.931] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:28:46.931] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:53:0) after 1m0s
[11:29:46.951] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:53:0)
[11:29:46.951] Timer tick, asking Buildbucket for the build status
[11:29:47.061] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:29:47.061] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:54:0) after 1m0s
[11:30:47.114] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:54:0)
[11:30:47.114] Timer tick, asking Buildbucket for the build status
[11:30:47.201] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:30:47.201] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:55:0) after 1m0s
[11:31:47.488] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:55:0)
[11:31:47.488] Timer tick, asking Buildbucket for the build status
[11:31:47.599] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:31:47.599] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:56:0) after 1m0s
[11:32:47.704] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:56:0)
[11:32:47.704] Timer tick, asking Buildbucket for the build status
[11:32:47.783] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:32:47.783] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:57:0) after 1m0s
[11:33:47.885] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:57:0)
[11:33:47.885] Timer tick, asking Buildbucket for the build status
[11:33:47.973] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:33:47.973] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:58:0) after 1m0s
[11:34:47.949] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:58:0)
[11:34:47.949] Timer tick, asking Buildbucket for the build status
[11:34:48.053] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:34:48.053] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:59:0) after 1m0s
[11:35:48.076] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:59:0)
[11:35:48.076] Timer tick, asking Buildbucket for the build status
[11:35:48.158] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:35:48.158] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:60:0) after 1m0s
[11:36:48.178] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:60:0)
[11:36:48.178] Timer tick, asking Buildbucket for the build status
[11:36:48.291] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:36:48.291] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:61:0) after 1m0s
[11:37:48.294] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:61:0)
[11:37:48.294] Timer tick, asking Buildbucket for the build status
[11:37:48.432] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:37:48.432] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:62:0) after 1m0s
[11:38:48.515] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:62:0)
[11:38:48.515] Timer tick, asking Buildbucket for the build status
[11:38:48.595] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:38:48.595] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:63:0) after 1m0s
[11:39:48.633] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:63:0)
[11:39:48.633] Timer tick, asking Buildbucket for the build status
[11:39:48.702] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:39:48.702] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:64:0) after 1m0s
[11:40:48.724] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:64:0)
[11:40:48.724] Timer tick, asking Buildbucket for the build status
[11:40:48.811] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:40:48.811] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:65:0) after 1m0s
[11:41:48.836] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:65:0)
[11:41:48.836] Timer tick, asking Buildbucket for the build status
[11:41:48.955] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:41:48.955] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:66:0) after 1m0s
[11:42:49.248] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:66:0)
[11:42:49.248] Timer tick, asking Buildbucket for the build status
[11:42:49.319] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:42:49.319] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:67:0) after 1m0s
[11:43:49.351] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:67:0)
[11:43:49.351] Timer tick, asking Buildbucket for the build status
[11:43:49.426] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:43:49.426] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:68:0) after 1m0s
[11:44:49.457] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:68:0)
[11:44:49.457] Timer tick, asking Buildbucket for the build status
[11:44:49.718] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:44:49.718] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:69:0) after 1m0s
[11:45:49.771] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:69:0)
[11:45:49.771] Timer tick, asking Buildbucket for the build status
[11:45:50.695] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:45:50.695] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:70:0) after 1m0s
[11:46:50.773] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:70:0)
[11:46:50.774] Timer tick, asking Buildbucket for the build status
[11:46:50.852] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:46:50.852] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:71:0) after 1m0s
[11:47:50.960] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:71:0)
[11:47:50.960] Timer tick, asking Buildbucket for the build status
[11:47:51.032] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:47:51.033] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:72:0) after 1m0s
[11:48:51.059] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:72:0)
[11:48:51.059] Timer tick, asking Buildbucket for the build status
[11:48:51.231] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:48:51.231] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:73:0) after 1m0s
[11:49:51.234] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:73:0)
[11:49:51.234] Timer tick, asking Buildbucket for the build status
[11:49:51.455] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:49:51.455] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:74:0) after 1m0s
[11:50:51.614] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:74:0)
[11:50:51.614] Timer tick, asking Buildbucket for the build status
[11:50:51.712] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:50:51.712] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:75:0) after 1m0s
[11:51:51.917] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:75:0)
[11:51:51.917] Timer tick, asking Buildbucket for the build status
[11:51:51.982] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:51:51.982] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:76:0) after 1m0s
[11:52:52.009] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:76:0)
[11:52:52.009] Timer tick, asking Buildbucket for the build status
[11:52:52.116] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:52:52.116] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:77:0) after 1m0s
[11:53:52.161] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:77:0)
[11:53:52.161] Timer tick, asking Buildbucket for the build status
[11:53:52.236] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:53:52.236] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:78:0) after 1m0s
[11:54:52.384] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:78:0)
[11:54:52.384] Timer tick, asking Buildbucket for the build status
[11:54:52.616] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:54:52.616] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:79:0) after 1m0s
[11:55:52.737] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:79:0)
[11:55:52.737] Timer tick, asking Buildbucket for the build status
[11:55:52.804] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:55:52.804] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:80:0) after 1m0s
[11:56:52.918] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:80:0)
[11:56:52.918] Timer tick, asking Buildbucket for the build status
[11:56:53.009] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:56:53.009] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:81:0) after 1m0s
[11:57:53.330] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:81:0)
[11:57:53.330] Timer tick, asking Buildbucket for the build status
[11:57:53.617] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:57:53.617] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:82:0) after 1m0s
[11:58:53.633] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:82:0)
[11:58:53.633] Timer tick, asking Buildbucket for the build status
[11:58:53.702] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:58:53.702] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:83:0) after 1m0s
[11:59:53.764] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:83:0)
[11:59:53.764] Timer tick, asking Buildbucket for the build status
[11:59:53.847] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:59:53.847] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:84:0) after 1m0s
[12:00:53.872] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:84:0)
[12:00:53.872] Timer tick, asking Buildbucket for the build status
[12:00:53.948] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:00:53.948] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:85:0) after 1m0s
[12:01:53.966] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:85:0)
[12:01:53.966] Timer tick, asking Buildbucket for the build status
[12:01:54.218] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:01:54.218] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:86:0) after 1m0s
[12:02:54.411] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:86:0)
[12:02:54.411] Timer tick, asking Buildbucket for the build status
[12:02:54.905] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:02:54.905] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:87:0) after 1m0s
[12:03:54.885] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:87:0)
[12:03:54.885] Timer tick, asking Buildbucket for the build status
[12:03:54.985] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:03:54.985] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:88:0) after 1m0s
[12:04:55.056] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:88:0)
[12:04:55.056] Timer tick, asking Buildbucket for the build status
[12:04:55.205] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:04:55.205] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:89:0) after 1m0s
[12:05:55.293] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:89:0)
[12:05:55.293] Timer tick, asking Buildbucket for the build status
[12:05:55.368] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:05:55.368] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:90:0) after 1m0s
[12:06:55.373] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:90:0)
[12:06:55.373] Timer tick, asking Buildbucket for the build status
[12:06:55.455] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:06:55.455] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:91:0) after 1m0s
[12:07:55.533] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:91:0)
[12:07:55.533] Timer tick, asking Buildbucket for the build status
[12:07:55.646] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:07:55.646] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:92:0) after 1m0s
[12:08:55.665] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:92:0)
[12:08:55.665] Timer tick, asking Buildbucket for the build status
[12:08:55.857] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:08:55.857] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:93:0) after 1m0s
[12:09:55.873] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:93:0)
[12:09:55.873] Timer tick, asking Buildbucket for the build status
[12:09:56.027] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:09:56.027] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:94:0) after 1m0s
[12:10:56.079] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:94:0)
[12:10:56.079] Timer tick, asking Buildbucket for the build status
[12:10:56.150] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:10:56.150] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:95:0) after 1m0s
[12:11:56.223] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:95:0)
[12:11:56.223] Timer tick, asking Buildbucket for the build status
[12:11:56.329] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:11:56.329] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:96:0) after 1m0s
[12:12:56.354] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:96:0)
[12:12:56.354] Timer tick, asking Buildbucket for the build status
[12:12:56.451] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:12:56.451] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:97:0) after 1m0s
[12:13:56.507] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:97:0)
[12:13:56.507] Timer tick, asking Buildbucket for the build status
[12:13:56.609] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:13:56.609] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:98:0) after 1m0s
[12:14:56.610] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:98:0)
[12:14:56.610] Timer tick, asking Buildbucket for the build status
[12:14:56.700] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:14:56.700] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:99:0) after 1m0s
[12:15:56.754] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:99:0)
[12:15:56.754] Timer tick, asking Buildbucket for the build status
[12:15:56.834] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:15:56.834] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:100:0) after 1m0s
[12:16:56.926] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:100:0)
[12:16:56.926] Timer tick, asking Buildbucket for the build status
[12:16:56.998] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:16:56.998] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:101:0) after 1m0s
[12:17:57.016] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:101:0)
[12:17:57.016] Timer tick, asking Buildbucket for the build status
[12:17:57.227] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:17:57.227] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:102:0) after 1m0s
[12:18:57.221] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:102:0)
[12:18:57.221] Timer tick, asking Buildbucket for the build status
[12:18:57.282] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:18:57.282] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:103:0) after 1m0s
[12:19:57.332] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:103:0)
[12:19:57.332] Timer tick, asking Buildbucket for the build status
[12:19:57.411] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:19:57.411] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:104:0) after 1m0s
[12:20:57.429] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:104:0)
[12:20:57.429] Timer tick, asking Buildbucket for the build status
[12:20:57.512] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:20:57.512] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:105:0) after 1m0s
[12:21:57.564] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:105:0)
[12:21:57.564] Timer tick, asking Buildbucket for the build status
[12:21:57.643] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:21:57.643] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:106:0) after 1m0s
[12:22:57.714] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:106:0)
[12:22:57.714] Timer tick, asking Buildbucket for the build status
[12:22:57.918] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:22:57.918] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:107:0) after 1m0s
[12:23:57.934] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:107:0)
[12:23:57.934] Timer tick, asking Buildbucket for the build status
[12:23:58.009] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:23:58.009] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:108:0) after 1m0s
[12:24:58.029] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:108:0)
[12:24:58.029] Timer tick, asking Buildbucket for the build status
[12:24:58.130] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:24:58.130] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:109:0) after 1m0s
[12:25:58.110] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:109:0)
[12:25:58.110] Timer tick, asking Buildbucket for the build status
[12:25:58.179] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:25:58.179] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:110:0) after 1m0s
[12:26:58.208] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:110:0)
[12:26:58.208] Timer tick, asking Buildbucket for the build status
[12:26:58.282] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:26:58.282] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:111:0) after 1m0s
[12:27:58.328] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:111:0)
[12:27:58.328] Timer tick, asking Buildbucket for the build status
[12:27:58.393] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:27:58.393] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:112:0) after 1m0s
[12:28:58.476] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:112:0)
[12:28:58.476] Timer tick, asking Buildbucket for the build status
[12:28:58.549] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:28:58.549] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:113:0) after 1m0s
[12:29:58.602] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:113:0)
[12:29:58.602] Timer tick, asking Buildbucket for the build status
[12:29:58.702] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:29:58.703] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:114:0) after 1m0s
[12:30:58.686] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:114:0)
[12:30:58.686] Timer tick, asking Buildbucket for the build status
[12:30:59.015] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:30:59.015] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:115:0) after 1m0s
[12:31:59.027] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:115:0)
[12:31:59.027] Timer tick, asking Buildbucket for the build status
[12:31:59.095] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:31:59.096] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:116:0) after 1m0s
[12:32:59.115] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:116:0)
[12:32:59.115] Timer tick, asking Buildbucket for the build status
[12:32:59.211] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:32:59.211] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:117:0) after 1m0s
[12:33:59.233] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:117:0)
[12:33:59.233] Timer tick, asking Buildbucket for the build status
[12:33:59.356] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:33:59.356] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:118:0) after 1m0s
[12:34:59.369] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:118:0)
[12:34:59.369] Timer tick, asking Buildbucket for the build status
[12:34:59.461] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:34:59.461] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:119:0) after 1m0s
[12:35:59.460] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:119:0)
[12:35:59.460] Timer tick, asking Buildbucket for the build status
[12:35:59.652] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:35:59.652] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:120:0) after 1m0s
[12:36:59.702] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:120:0)
[12:36:59.702] Timer tick, asking Buildbucket for the build status
[12:36:59.774] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:36:59.774] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:121:0) after 1m0s
[12:37:59.796] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:121:0)
[12:37:59.796] Timer tick, asking Buildbucket for the build status
[12:37:59.868] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:37:59.868] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:122:0) after 1m0s
[12:38:59.893] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:122:0)
[12:38:59.893] Timer tick, asking Buildbucket for the build status
[12:39:00.134] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:39:00.134] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:123:0) after 1m0s
[12:40:00.184] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:123:0)
[12:40:00.184] Timer tick, asking Buildbucket for the build status
[12:40:00.356] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:40:00.356] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:124:0) after 1m0s
[12:41:00.376] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:124:0)
[12:41:00.376] Timer tick, asking Buildbucket for the build status
[12:41:00.716] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:41:00.716] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:125:0) after 1m0s
[12:42:00.773] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:125:0)
[12:42:00.773] Timer tick, asking Buildbucket for the build status
[12:42:00.861] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:42:00.861] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:126:0) after 1m0s
[12:43:00.903] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:126:0)
[12:43:00.903] Timer tick, asking Buildbucket for the build status
[12:43:01.064] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:43:01.064] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:127:0) after 1m0s
[12:44:01.480] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:127:0)
[12:44:01.480] Timer tick, asking Buildbucket for the build status
[12:44:01.562] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:44:01.562] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:128:0) after 1m0s
[12:45:01.799] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:128:0)
[12:45:01.799] Timer tick, asking Buildbucket for the build status
[12:45:01.954] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:45:01.954] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:129:0) after 1m0s
[12:46:03.878] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:129:0)
[12:46:03.878] Timer tick, asking Buildbucket for the build status
[12:46:04.062] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:46:04.062] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:130:0) after 1m0s
[12:47:04.377] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:130:0)
[12:47:04.377] Timer tick, asking Buildbucket for the build status
[12:47:04.658] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:47:04.658] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:131:0) after 1m0s
[12:48:04.856] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:131:0)
[12:48:04.856] Timer tick, asking Buildbucket for the build status
[12:48:04.945] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:48:04.945] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:132:0) after 1m0s
[12:49:05.188] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:132:0)
[12:49:05.188] Timer tick, asking Buildbucket for the build status
[12:49:05.276] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:49:05.276] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:133:0) after 1m0s
[12:50:05.385] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:133:0)
[12:50:05.385] Timer tick, asking Buildbucket for the build status
[12:50:05.488] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:50:05.488] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:134:0) after 1m0s
[12:51:05.668] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:134:0)
[12:51:05.668] Timer tick, asking Buildbucket for the build status
[12:51:05.735] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:51:05.735] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:135:0) after 1m0s
[12:52:05.777] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:135:0)
[12:52:05.777] Timer tick, asking Buildbucket for the build status
[12:52:05.849] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:52:05.849] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:136:0) after 1m0s
[12:53:05.902] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:136:0)
[12:53:05.902] Timer tick, asking Buildbucket for the build status
[12:53:06.045] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:53:06.045] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:137:0) after 1m0s
[12:54:06.184] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:137:0)
[12:54:06.184] Timer tick, asking Buildbucket for the build status
[12:54:06.284] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:54:06.284] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:138:0) after 1m0s
[12:55:06.352] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:138:0)
[12:55:06.352] Timer tick, asking Buildbucket for the build status
[12:55:06.481] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:55:06.481] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:139:0) after 1m0s
[12:56:06.529] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:139:0)
[12:56:06.529] Timer tick, asking Buildbucket for the build status
[12:56:06.596] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:56:06.596] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:140:0) after 1m0s
[12:57:06.674] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:140:0)
[12:57:06.674] Timer tick, asking Buildbucket for the build status
[12:57:07.440] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:57:07.440] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:141:0) after 1m0s
[12:58:07.585] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:141:0)
[12:58:07.585] Timer tick, asking Buildbucket for the build status
[12:58:07.684] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:58:07.684] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:142:0) after 1m0s
[12:59:07.814] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:142:0)
[12:59:07.814] Timer tick, asking Buildbucket for the build status
[12:59:07.955] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:59:07.955] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:143:0) after 1m0s
[13:00:08.001] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:143:0)
[13:00:08.001] Timer tick, asking Buildbucket for the build status
[13:00:08.284] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:00:08.284] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:144:0) after 1m0s
[13:01:08.477] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:144:0)
[13:01:08.477] Timer tick, asking Buildbucket for the build status
[13:01:08.571] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:01:08.571] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:145:0) after 1m0s
[13:02:08.692] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:145:0)
[13:02:08.692] Timer tick, asking Buildbucket for the build status
[13:02:08.831] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:02:08.831] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:146:0) after 1m0s
[13:03:08.888] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:146:0)
[13:03:08.888] Timer tick, asking Buildbucket for the build status
[13:03:08.987] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:03:08.987] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:147:0) after 1m0s
[13:04:09.177] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:147:0)
[13:04:09.177] Timer tick, asking Buildbucket for the build status
[13:04:09.305] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:04:09.305] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:148:0) after 1m0s
[13:05:09.500] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:148:0)
[13:05:09.500] Timer tick, asking Buildbucket for the build status
[13:05:09.824] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:05:09.824] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:149:0) after 1m0s
[13:06:09.994] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:149:0)
[13:06:09.994] Timer tick, asking Buildbucket for the build status
[13:06:10.096] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:06:10.096] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:150:0) after 1m0s
[13:07:10.277] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:150:0)
[13:07:10.277] Timer tick, asking Buildbucket for the build status
[13:07:10.353] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:07:10.353] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:151:0) after 1m0s
[13:08:10.540] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:151:0)
[13:08:10.540] Timer tick, asking Buildbucket for the build status
[13:08:10.672] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:08:10.672] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:152:0) after 1m0s
[13:09:10.723] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:152:0)
[13:09:10.723] Timer tick, asking Buildbucket for the build status
[13:09:10.818] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:09:10.818] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:153:0) after 1m0s
[13:10:11.047] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:153:0)
[13:10:11.047] Timer tick, asking Buildbucket for the build status
[13:10:11.350] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:10:11.350] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:154:0) after 1m0s
[13:11:11.376] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:154:0)
[13:11:11.376] Timer tick, asking Buildbucket for the build status
[13:11:11.454] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:11:11.454] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:155:0) after 1m0s
[13:12:11.537] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:155:0)
[13:12:11.537] Timer tick, asking Buildbucket for the build status
[13:12:11.597] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:12:11.597] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:156:0) after 1m0s
[13:13:11.714] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:156:0)
[13:13:11.714] Timer tick, asking Buildbucket for the build status
[13:13:11.854] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:13:11.854] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:157:0) after 1m0s
[13:14:11.910] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:157:0)
[13:14:11.910] Timer tick, asking Buildbucket for the build status
[13:14:11.979] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:14:11.979] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:158:0) after 1m0s
[13:15:12.033] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:158:0)
[13:15:12.033] Timer tick, asking Buildbucket for the build status
[13:15:12.138] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:15:12.138] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:159:0) after 1m0s
[13:16:12.748] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:159:0)
[13:16:12.748] Timer tick, asking Buildbucket for the build status
[13:16:12.809] Build 8853968027904389456: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:16:12.809] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9019398091015259264:160:0) after 1m0s
[13:17:02.956] Received PubSub notification, asking Buildbucket for the build status
[13:17:03.153] Build 8853968027904389456: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[13:17:03.153] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1614604622348994",
"created_by": "project:nacl",
"created_ts": "1614595115713740",
"failure_reason": "BUILD_FAILURE",
"id": "8853968027904389456",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_64\", \"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\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"title\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}}",
"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\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"title\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\"}]}, \"bot_id\": \"luci-nacl-toolchain-xenial-0-hk5k\", \"branch\": \"refs/heads/master\", \"builder_group\": \"client.nacl.toolchain\", \"buildername\": \"linux-pnacl-x86_64-tests-x86_64\", \"buildnumber\": 5132, \"got_revision\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a\", \"slavetype\": \"BuilderTester\"}, \"swarming\": {\"bot_dimensions\": {\"caches\": [\"builder_5e264a2b33887b9708d9efa4d555f48b42be33439102d42d27d93f0b7d878c19_v2\", \"git\", \"goma_v2\", \"vpython\"], \"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-hk5k\"], \"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\": [\"5712-339372b\"], \"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": "1614596093631797",
"status": "COMPLETED",
"status_changed_ts": "1614596094043049",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_64/5132",
"builder:linux-pnacl-x86_64-tests-x86_64",
"buildset:commit/git/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/b76bff4a0db45a20d41646ddd76b7e9ab7bf4a6a",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9019398091015259264",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_64",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8853968027904389456/+/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:52062fded6a8b610",
"user_agent:luci-scheduler"
],
"updated_ts": "1614604622349838",
"url": "https://ci.chromium.org/b/8853968027904389456",
"utcnow_ts": "1614604623139992"
}
}
[13:17:03.153] Invocation finished in 2h38m29.789660568s with status FAILED