[17:39:47.384] New invocation is queued and will start shortly
[17:39:51.194] Starting the invocation (attempt 1)
[17:39:51.228] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[17:39:51.228] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[17:39:51.228] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9040661876423100960",
"parameters_json": "{\"builder_name\":\"linux-pnacl-x86_32-tests-mips\",\"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\":\"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@f2b7d37238a5f49ba00fc1c152cbd5caa278d030\",\"title\":\"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux-pnacl-x86_32-tests-mips",
"scheduler_invocation_id:9040661876423100960",
"scheduler_job_id:nacl/linux-pnacl-x86_32-tests-mips",
"user_agent:luci-scheduler",
"buildset:commit/git/f2b7d37238a5f49ba00fc1c152cbd5caa278d030",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030",
"gitiles_ref:refs/heads/master"
]
}
[17:39:52.194] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1594316391342798",
"id": "8875231811590667856",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_32-tests-mips\", \"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\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"title\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}}",
"project": "nacl",
"result_details_json": "{\"properties\": {}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1594316391931981",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_32-tests-mips/5008",
"builder:linux-pnacl-x86_32-tests-mips",
"buildset:commit/git/f2b7d37238a5f49ba00fc1c152cbd5caa278d030",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9040661876423100960",
"scheduler_job_id:nacl/linux-pnacl-x86_32-tests-mips",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8875231811590667856/+/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": "1594316391932154",
"url": "https://ci.chromium.org/b/8875231811590667856",
"utcnow_ts": "1594316392184378"
}
}
[17:39:52.194] Task URL: https://ci.chromium.org/b/8875231811590667856
[17:39:52.194] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:2:0) after 1m0s
[17:40:52.290] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:2:0)
[17:40:52.290] Timer tick, asking Buildbucket for the build status
[17:40:52.427] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:40:52.427] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:3:0) after 1m0s
[17:41:52.599] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:3:0)
[17:41:52.599] Timer tick, asking Buildbucket for the build status
[17:41:52.740] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:41:52.740] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:4:0) after 1m0s
[17:42:52.918] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:4:0)
[17:42:52.918] Timer tick, asking Buildbucket for the build status
[17:42:53.172] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:42:53.172] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:5:0) after 1m0s
[17:43:53.322] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:5:0)
[17:43:53.322] Timer tick, asking Buildbucket for the build status
[17:43:53.460] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:43:53.460] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:6:0) after 1m0s
[17:44:54.361] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:6:0)
[17:44:54.362] Timer tick, asking Buildbucket for the build status
[17:44:56.890] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:44:56.890] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:7:0) after 1m0s
[17:45:57.937] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:7:0)
[17:45:57.937] Timer tick, asking Buildbucket for the build status
[17:45:58.068] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:45:58.068] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:8:0) after 1m0s
[17:46:58.199] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:8:0)
[17:46:58.199] Timer tick, asking Buildbucket for the build status
[17:46:58.298] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:46:58.298] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:9:0) after 1m0s
[17:47:58.584] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:9:0)
[17:47:58.584] Timer tick, asking Buildbucket for the build status
[17:47:59.110] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:47:59.110] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:10:0) after 1m0s
[17:48:59.231] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:10:0)
[17:48:59.231] Timer tick, asking Buildbucket for the build status
[17:48:59.383] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:48:59.383] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:11:0) after 1m0s
[17:49:59.866] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:11:0)
[17:49:59.866] Timer tick, asking Buildbucket for the build status
[17:50:02.910] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:50:02.910] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:12:0) after 1m0s
[17:51:03.492] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:12:0)
[17:51:03.492] Timer tick, asking Buildbucket for the build status
[17:51:03.690] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:51:03.690] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:13:0) after 1m0s
[17:52:03.710] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:13:0)
[17:52:03.710] Timer tick, asking Buildbucket for the build status
[17:52:04.107] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:52:04.107] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:14:0) after 1m0s
[17:53:04.160] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:14:0)
[17:53:04.160] Timer tick, asking Buildbucket for the build status
[17:53:04.373] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:53:04.373] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:15:0) after 1m0s
[17:54:04.450] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:15:0)
[17:54:04.450] Timer tick, asking Buildbucket for the build status
[17:54:04.569] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:54:04.569] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:16:0) after 1m0s
[17:55:04.783] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:16:0)
[17:55:04.783] Timer tick, asking Buildbucket for the build status
[17:55:05.198] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:55:05.198] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:17:0) after 1m0s
[17:56:05.297] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:17:0)
[17:56:05.297] Timer tick, asking Buildbucket for the build status
[17:56:06.715] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:56:06.716] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:18:0) after 1m0s
[17:57:06.974] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:18:0)
[17:57:06.974] Timer tick, asking Buildbucket for the build status
[17:57:07.159] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:57:07.163] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:19:0) after 1m0s
[17:58:07.340] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:19:0)
[17:58:07.340] Timer tick, asking Buildbucket for the build status
[17:58:07.777] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:58:07.777] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:20:0) after 1m0s
[17:59:07.962] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:20:0)
[17:59:07.962] Timer tick, asking Buildbucket for the build status
[17:59:08.377] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:59:08.377] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:21:0) after 1m0s
[18:00:08.778] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:21:0)
[18:00:08.778] Timer tick, asking Buildbucket for the build status
[18:00:08.947] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:00:08.947] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:22:0) after 1m0s
[18:01:09.200] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:22:0)
[18:01:09.200] Timer tick, asking Buildbucket for the build status
[18:01:09.944] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:01:09.944] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:23:0) after 1m0s
[18:02:10.159] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:23:0)
[18:02:10.159] Timer tick, asking Buildbucket for the build status
[18:02:10.292] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:02:10.292] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:24:0) after 1m0s
[18:03:10.345] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:24:0)
[18:03:10.345] Timer tick, asking Buildbucket for the build status
[18:03:10.905] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:03:10.905] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:25:0) after 1m0s
[18:04:10.925] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:25:0)
[18:04:10.925] Timer tick, asking Buildbucket for the build status
[18:04:11.079] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:04:11.079] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:26:0) after 1m0s
[18:05:11.107] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:26:0)
[18:05:11.107] Timer tick, asking Buildbucket for the build status
[18:05:12.234] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:05:12.234] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:27:0) after 1m0s
[18:06:12.254] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:27:0)
[18:06:12.254] Timer tick, asking Buildbucket for the build status
[18:06:12.539] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:06:12.539] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:28:0) after 1m0s
[18:07:12.674] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:28:0)
[18:07:12.674] Timer tick, asking Buildbucket for the build status
[18:07:12.817] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:07:12.817] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:29:0) after 1m0s
[18:08:12.881] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:29:0)
[18:08:12.881] Timer tick, asking Buildbucket for the build status
[18:08:13.282] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:08:13.282] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:30:0) after 1m0s
[18:09:13.307] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:30:0)
[18:09:13.307] Timer tick, asking Buildbucket for the build status
[18:09:13.465] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:09:13.465] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:31:0) after 1m0s
[18:10:13.512] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:31:0)
[18:10:13.512] Timer tick, asking Buildbucket for the build status
[18:10:13.886] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:10:13.886] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:32:0) after 1m0s
[18:11:13.932] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:32:0)
[18:11:13.932] Timer tick, asking Buildbucket for the build status
[18:11:14.098] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:11:14.098] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:33:0) after 1m0s
[18:12:14.120] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:33:0)
[18:12:14.120] Timer tick, asking Buildbucket for the build status
[18:12:14.256] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:12:14.256] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:34:0) after 1m0s
[18:13:14.298] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:34:0)
[18:13:14.298] Timer tick, asking Buildbucket for the build status
[18:13:14.456] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:13:14.456] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:35:0) after 1m0s
[18:14:14.482] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:35:0)
[18:14:14.482] Timer tick, asking Buildbucket for the build status
[18:14:17.284] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:14:17.284] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:36:0) after 1m0s
[18:15:17.381] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:36:0)
[18:15:17.381] Timer tick, asking Buildbucket for the build status
[18:15:17.634] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:15:17.634] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:37:0) after 1m0s
[18:16:17.707] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:37:0)
[18:16:17.707] Timer tick, asking Buildbucket for the build status
[18:16:17.960] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:16:17.960] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:38:0) after 1m0s
[18:17:18.039] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:38:0)
[18:17:18.039] Timer tick, asking Buildbucket for the build status
[18:17:18.352] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:17:18.352] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:39:0) after 1m0s
[18:18:18.481] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:39:0)
[18:18:18.481] Timer tick, asking Buildbucket for the build status
[18:18:18.811] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:18:18.811] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:40:0) after 1m0s
[18:19:18.842] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:40:0)
[18:19:18.842] Timer tick, asking Buildbucket for the build status
[18:19:18.993] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:19:18.993] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:41:0) after 1m0s
[18:20:19.080] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:41:0)
[18:20:19.080] Timer tick, asking Buildbucket for the build status
[18:20:19.207] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:20:19.207] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:42:0) after 1m0s
[18:21:19.285] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:42:0)
[18:21:19.285] Timer tick, asking Buildbucket for the build status
[18:21:19.422] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:21:19.422] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:43:0) after 1m0s
[18:22:19.628] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:43:0)
[18:22:19.628] Timer tick, asking Buildbucket for the build status
[18:22:20.433] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:22:20.433] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:44:0) after 1m0s
[18:23:20.427] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:44:0)
[18:23:20.427] Timer tick, asking Buildbucket for the build status
[18:23:20.617] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:23:20.617] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:45:0) after 1m0s
[18:24:20.605] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:45:0)
[18:24:20.605] Timer tick, asking Buildbucket for the build status
[18:24:20.734] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:24:20.734] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:46:0) after 1m0s
[18:25:20.760] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:46:0)
[18:25:20.760] Timer tick, asking Buildbucket for the build status
[18:25:21.155] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:25:21.155] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:47:0) after 1m0s
[18:26:21.199] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:47:0)
[18:26:21.199] Timer tick, asking Buildbucket for the build status
[18:26:21.698] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:26:21.698] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:48:0) after 1m0s
[18:27:21.753] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:48:0)
[18:27:21.753] Timer tick, asking Buildbucket for the build status
[18:27:21.904] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:27:21.904] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:49:0) after 1m0s
[18:28:21.957] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:49:0)
[18:28:21.957] Timer tick, asking Buildbucket for the build status
[18:28:22.161] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:28:22.161] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:50:0) after 1m0s
[18:29:22.214] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:50:0)
[18:29:22.214] Timer tick, asking Buildbucket for the build status
[18:29:22.526] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:29:22.526] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:51:0) after 1m0s
[18:30:22.619] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:51:0)
[18:30:22.619] Timer tick, asking Buildbucket for the build status
[18:30:22.758] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:30:22.758] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:52:0) after 1m0s
[18:31:22.814] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:52:0)
[18:31:22.814] Timer tick, asking Buildbucket for the build status
[18:31:23.012] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:31:23.012] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:53:0) after 1m0s
[18:32:23.044] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:53:0)
[18:32:23.044] Timer tick, asking Buildbucket for the build status
[18:32:25.856] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:32:25.856] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:54:0) after 1m0s
[18:33:25.905] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:54:0)
[18:33:25.905] Timer tick, asking Buildbucket for the build status
[18:33:26.152] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:33:26.152] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:55:0) after 1m0s
[18:34:26.181] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:55:0)
[18:34:26.181] Timer tick, asking Buildbucket for the build status
[18:34:26.634] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:34:26.634] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:56:0) after 1m0s
[18:35:26.783] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:56:0)
[18:35:26.783] Timer tick, asking Buildbucket for the build status
[18:35:26.970] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:35:26.970] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:57:0) after 1m0s
[18:36:27.205] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:57:0)
[18:36:27.205] Timer tick, asking Buildbucket for the build status
[18:36:27.504] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:36:27.504] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:58:0) after 1m0s
[18:37:27.596] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:58:0)
[18:37:27.596] Timer tick, asking Buildbucket for the build status
[18:37:27.968] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:37:27.968] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:59:0) after 1m0s
[18:38:28.170] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:59:0)
[18:38:28.170] Timer tick, asking Buildbucket for the build status
[18:38:28.592] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:38:28.592] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:60:0) after 1m0s
[18:39:28.639] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:60:0)
[18:39:28.639] Timer tick, asking Buildbucket for the build status
[18:39:28.769] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:39:28.769] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:61:0) after 1m0s
[18:40:28.801] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:61:0)
[18:40:28.801] Timer tick, asking Buildbucket for the build status
[18:40:28.900] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:40:28.900] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:62:0) after 1m0s
[18:41:28.928] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:62:0)
[18:41:28.929] Timer tick, asking Buildbucket for the build status
[18:41:29.085] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:41:29.085] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:63:0) after 1m0s
[18:42:29.173] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:63:0)
[18:42:29.173] Timer tick, asking Buildbucket for the build status
[18:42:29.302] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:42:29.302] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:64:0) after 1m0s
[18:43:29.366] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:64:0)
[18:43:29.366] Timer tick, asking Buildbucket for the build status
[18:43:29.816] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:43:29.816] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:65:0) after 1m0s
[18:44:29.864] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:65:0)
[18:44:29.864] Timer tick, asking Buildbucket for the build status
[18:44:29.974] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:44:29.974] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:66:0) after 1m0s
[18:45:29.989] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:66:0)
[18:45:29.989] Timer tick, asking Buildbucket for the build status
[18:45:30.334] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:45:30.334] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:67:0) after 1m0s
[18:46:30.340] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:67:0)
[18:46:30.340] Timer tick, asking Buildbucket for the build status
[18:46:31.990] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:46:31.990] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:68:0) after 1m0s
[18:47:32.026] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:68:0)
[18:47:32.026] Timer tick, asking Buildbucket for the build status
[18:47:32.235] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:47:32.235] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:69:0) after 1m0s
[18:48:32.260] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:69:0)
[18:48:32.260] Timer tick, asking Buildbucket for the build status
[18:48:32.781] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:48:32.781] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:70:0) after 1m0s
[18:49:32.804] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:70:0)
[18:49:32.804] Timer tick, asking Buildbucket for the build status
[18:49:33.155] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:49:33.155] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:71:0) after 1m0s
[18:50:33.212] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:71:0)
[18:50:33.212] Timer tick, asking Buildbucket for the build status
[18:50:33.434] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:50:33.434] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:72:0) after 1m0s
[18:51:33.429] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:72:0)
[18:51:33.429] Timer tick, asking Buildbucket for the build status
[18:51:33.771] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:51:33.771] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:73:0) after 1m0s
[18:52:33.802] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:73:0)
[18:52:33.802] Timer tick, asking Buildbucket for the build status
[18:52:34.348] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:52:34.348] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:74:0) after 1m0s
[18:53:34.390] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:74:0)
[18:53:34.390] Timer tick, asking Buildbucket for the build status
[18:53:34.523] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:53:34.523] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:75:0) after 1m0s
[18:54:34.546] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:75:0)
[18:54:34.546] Timer tick, asking Buildbucket for the build status
[18:54:34.732] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:54:34.732] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:76:0) after 1m0s
[18:55:34.723] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:76:0)
[18:55:34.723] Timer tick, asking Buildbucket for the build status
[18:55:35.172] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:55:35.172] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:77:0) after 1m0s
[18:56:35.177] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:77:0)
[18:56:35.177] Timer tick, asking Buildbucket for the build status
[18:56:35.323] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:56:35.323] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:78:0) after 1m0s
[18:57:35.371] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:78:0)
[18:57:35.371] Timer tick, asking Buildbucket for the build status
[18:57:35.612] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:57:35.612] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:79:0) after 1m0s
[18:58:35.639] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:79:0)
[18:58:35.639] Timer tick, asking Buildbucket for the build status
[18:58:35.840] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:58:35.840] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:80:0) after 1m0s
[18:59:35.961] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:80:0)
[18:59:35.961] Timer tick, asking Buildbucket for the build status
[18:59:36.123] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[18:59:36.123] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:81:0) after 1m0s
[19:00:36.149] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:81:0)
[19:00:36.149] Timer tick, asking Buildbucket for the build status
[19:00:37.198] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:00:37.198] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:82:0) after 1m0s
[19:01:37.230] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:82:0)
[19:01:37.230] Timer tick, asking Buildbucket for the build status
[19:01:37.406] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:01:37.406] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:83:0) after 1m0s
[19:02:37.453] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:83:0)
[19:02:37.453] Timer tick, asking Buildbucket for the build status
[19:02:42.343] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:02:42.343] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:84:0) after 1m0s
[19:03:45.764] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:84:0)
[19:03:45.764] Timer tick, asking Buildbucket for the build status
[19:03:45.952] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:03:45.952] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:85:0) after 1m0s
[19:04:46.554] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:85:0)
[19:04:46.554] Timer tick, asking Buildbucket for the build status
[19:04:46.869] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:04:46.869] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:86:0) after 1m0s
[19:05:46.955] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:86:0)
[19:05:46.955] Timer tick, asking Buildbucket for the build status
[19:05:47.379] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:05:47.379] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:87:0) after 1m0s
[19:06:47.432] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:87:0)
[19:06:47.432] Timer tick, asking Buildbucket for the build status
[19:06:47.637] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:06:47.637] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:88:0) after 1m0s
[19:07:47.879] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:88:0)
[19:07:47.879] Timer tick, asking Buildbucket for the build status
[19:07:48.028] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:07:48.028] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:89:0) after 1m0s
[19:08:48.251] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:89:0)
[19:08:48.251] Timer tick, asking Buildbucket for the build status
[19:08:48.489] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:08:48.489] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:90:0) after 1m0s
[19:09:48.861] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:90:0)
[19:09:48.861] Timer tick, asking Buildbucket for the build status
[19:09:49.002] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:09:49.003] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:91:0) after 1m0s
[19:10:49.155] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:91:0)
[19:10:49.155] Timer tick, asking Buildbucket for the build status
[19:10:49.281] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:10:49.281] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:92:0) after 1m0s
[19:11:49.339] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:92:0)
[19:11:49.339] Timer tick, asking Buildbucket for the build status
[19:11:49.520] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:11:49.520] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:93:0) after 1m0s
[19:12:49.548] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:93:0)
[19:12:49.548] Timer tick, asking Buildbucket for the build status
[19:12:49.726] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:12:49.726] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:94:0) after 1m0s
[19:13:49.842] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:94:0)
[19:13:49.842] Timer tick, asking Buildbucket for the build status
[19:13:50.178] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:13:50.178] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:95:0) after 1m0s
[19:14:50.329] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:95:0)
[19:14:50.329] Timer tick, asking Buildbucket for the build status
[19:14:50.595] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:14:50.595] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:96:0) after 1m0s
[19:15:50.705] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:96:0)
[19:15:50.705] Timer tick, asking Buildbucket for the build status
[19:15:51.138] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:15:51.139] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:97:0) after 1m0s
[19:16:51.174] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:97:0)
[19:16:51.174] Timer tick, asking Buildbucket for the build status
[19:16:51.494] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:16:51.494] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:98:0) after 1m0s
[19:17:51.576] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:98:0)
[19:17:51.576] Timer tick, asking Buildbucket for the build status
[19:17:51.833] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:17:51.833] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:99:0) after 1m0s
[19:18:51.828] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:99:0)
[19:18:51.828] Timer tick, asking Buildbucket for the build status
[19:18:51.979] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:18:51.979] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:100:0) after 1m0s
[19:19:52.007] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:100:0)
[19:19:52.007] Timer tick, asking Buildbucket for the build status
[19:19:52.225] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:19:52.225] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:101:0) after 1m0s
[19:20:52.258] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:101:0)
[19:20:52.258] Timer tick, asking Buildbucket for the build status
[19:20:53.048] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:20:53.048] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:102:0) after 1m0s
[19:21:53.115] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:102:0)
[19:21:53.115] Timer tick, asking Buildbucket for the build status
[19:21:53.251] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:21:53.251] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:103:0) after 1m0s
[19:22:53.556] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:103:0)
[19:22:53.556] Timer tick, asking Buildbucket for the build status
[19:22:53.890] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:22:53.890] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:104:0) after 1m0s
[19:23:53.985] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:104:0)
[19:23:53.985] Timer tick, asking Buildbucket for the build status
[19:23:54.382] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:23:54.382] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:105:0) after 1m0s
[19:24:54.691] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:105:0)
[19:24:54.691] Timer tick, asking Buildbucket for the build status
[19:24:54.851] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:24:54.851] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:106:0) after 1m0s
[19:25:55.166] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:106:0)
[19:25:55.166] Timer tick, asking Buildbucket for the build status
[19:25:55.678] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:25:55.679] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:107:0) after 1m0s
[19:26:55.908] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:107:0)
[19:26:55.908] Timer tick, asking Buildbucket for the build status
[19:26:56.097] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:26:56.097] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:108:0) after 1m0s
[19:27:56.147] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:108:0)
[19:27:56.147] Timer tick, asking Buildbucket for the build status
[19:27:56.234] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:27:56.234] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:109:0) after 1m0s
[19:28:56.281] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:109:0)
[19:28:56.281] Timer tick, asking Buildbucket for the build status
[19:28:56.569] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:28:56.569] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:110:0) after 1m0s
[19:29:56.603] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:110:0)
[19:29:56.603] Timer tick, asking Buildbucket for the build status
[19:29:56.722] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:29:56.722] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:111:0) after 1m0s
[19:30:56.782] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:111:0)
[19:30:56.783] Timer tick, asking Buildbucket for the build status
[19:30:56.989] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:30:56.989] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:112:0) after 1m0s
[19:31:57.016] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:112:0)
[19:31:57.016] Timer tick, asking Buildbucket for the build status
[19:31:58.130] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:31:58.130] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:113:0) after 1m0s
[19:32:58.260] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:113:0)
[19:32:58.260] Timer tick, asking Buildbucket for the build status
[19:32:58.423] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:32:58.423] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:114:0) after 1m0s
[19:33:58.494] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:114:0)
[19:33:58.494] Timer tick, asking Buildbucket for the build status
[19:33:58.610] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:33:58.610] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:115:0) after 1m0s
[19:34:58.726] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:115:0)
[19:34:58.726] Timer tick, asking Buildbucket for the build status
[19:34:58.890] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:34:58.890] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:116:0) after 1m0s
[19:35:59.018] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:116:0)
[19:35:59.018] Timer tick, asking Buildbucket for the build status
[19:35:59.196] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:35:59.196] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:117:0) after 1m0s
[19:36:59.340] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:117:0)
[19:36:59.340] Timer tick, asking Buildbucket for the build status
[19:36:59.831] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:36:59.831] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:118:0) after 1m0s
[19:38:00.051] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:118:0)
[19:38:00.051] Timer tick, asking Buildbucket for the build status
[19:38:00.364] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:38:00.364] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:119:0) after 1m0s
[19:39:00.578] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:119:0)
[19:39:00.578] Timer tick, asking Buildbucket for the build status
[19:39:00.726] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:39:00.726] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:120:0) after 1m0s
[19:40:00.950] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:120:0)
[19:40:00.950] Timer tick, asking Buildbucket for the build status
[19:40:01.276] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:40:01.276] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:121:0) after 1m0s
[19:41:01.721] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:121:0)
[19:41:01.721] Timer tick, asking Buildbucket for the build status
[19:41:01.846] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:41:01.846] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:122:0) after 1m0s
[19:42:02.138] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:122:0)
[19:42:02.138] Timer tick, asking Buildbucket for the build status
[19:42:02.379] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:42:02.379] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:123:0) after 1m0s
[19:43:02.634] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:123:0)
[19:43:02.634] Timer tick, asking Buildbucket for the build status
[19:43:02.798] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:43:02.798] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:124:0) after 1m0s
[19:44:02.896] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:124:0)
[19:44:02.896] Timer tick, asking Buildbucket for the build status
[19:44:03.029] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:44:03.029] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:125:0) after 1m0s
[19:45:03.099] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:125:0)
[19:45:03.099] Timer tick, asking Buildbucket for the build status
[19:45:03.203] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:45:03.203] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:126:0) after 1m0s
[19:46:03.232] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:126:0)
[19:46:03.232] Timer tick, asking Buildbucket for the build status
[19:46:03.405] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:46:03.405] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:127:0) after 1m0s
[19:47:03.436] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:127:0)
[19:47:03.436] Timer tick, asking Buildbucket for the build status
[19:47:03.583] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:47:03.583] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:128:0) after 1m0s
[19:48:03.608] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:128:0)
[19:48:03.608] Timer tick, asking Buildbucket for the build status
[19:48:03.796] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:48:03.796] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:129:0) after 1m0s
[19:49:03.873] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:129:0)
[19:49:03.873] Timer tick, asking Buildbucket for the build status
[19:49:04.012] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:49:04.012] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:130:0) after 1m0s
[19:50:04.138] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:130:0)
[19:50:04.138] Timer tick, asking Buildbucket for the build status
[19:50:04.723] Build 8875231811590667856: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[19:50:04.723] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:131:0) after 1m0s
[19:50:23.612] Received PubSub notification, asking Buildbucket for the build status
[19:50:23.680] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:51:04.833] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:131:0)
[19:51:04.833] Timer tick, asking Buildbucket for the build status
[19:51:05.309] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:51:05.309] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:133:0) after 1m0s
[19:52:05.328] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:133:0)
[19:52:05.328] Timer tick, asking Buildbucket for the build status
[19:52:05.508] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:52:05.508] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:134:0) after 1m0s
[19:53:05.595] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:134:0)
[19:53:05.596] Timer tick, asking Buildbucket for the build status
[19:53:05.779] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:53:05.779] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:135:0) after 1m0s
[19:54:05.842] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:135:0)
[19:54:05.842] Timer tick, asking Buildbucket for the build status
[19:54:06.599] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:54:06.599] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:136:0) after 1m0s
[19:55:06.657] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:136:0)
[19:55:06.657] Timer tick, asking Buildbucket for the build status
[19:55:08.898] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:55:08.898] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:137:0) after 1m0s
[19:56:08.969] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:137:0)
[19:56:08.969] Timer tick, asking Buildbucket for the build status
[19:56:09.416] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:56:09.416] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:138:0) after 1m0s
[19:57:09.516] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:138:0)
[19:57:09.516] Timer tick, asking Buildbucket for the build status
[19:57:09.779] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:57:09.779] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:139:0) after 1m0s
[19:58:09.818] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:139:0)
[19:58:09.818] Timer tick, asking Buildbucket for the build status
[19:58:09.961] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:58:09.961] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:140:0) after 1m0s
[19:59:10.034] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:140:0)
[19:59:10.034] Timer tick, asking Buildbucket for the build status
[19:59:10.177] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:59:10.177] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:141:0) after 1m0s
[20:00:10.249] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:141:0)
[20:00:10.249] Timer tick, asking Buildbucket for the build status
[20:00:10.414] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:00:10.414] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:142:0) after 1m0s
[20:01:10.485] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:142:0)
[20:01:10.485] Timer tick, asking Buildbucket for the build status
[20:01:12.818] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:01:12.818] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:143:0) after 1m0s
[20:02:12.852] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:143:0)
[20:02:12.852] Timer tick, asking Buildbucket for the build status
[20:02:13.437] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:02:13.437] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:144:0) after 1m0s
[20:03:13.467] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:144:0)
[20:03:13.467] Timer tick, asking Buildbucket for the build status
[20:03:13.623] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:03:13.623] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:145:0) after 1m0s
[20:04:13.647] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:145:0)
[20:04:13.647] Timer tick, asking Buildbucket for the build status
[20:04:14.259] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:04:14.259] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:146:0) after 1m0s
[20:05:14.339] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:146:0)
[20:05:14.339] Timer tick, asking Buildbucket for the build status
[20:05:14.443] Build 8875231811590667856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:05:14.443] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9040661876423100960:147:0) after 1m0s
[20:06:14.229] Received PubSub notification, asking Buildbucket for the build status
[20:06:14.302] Build 8875231811590667856: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[20:06:14.302] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1594325172815990",
"created_by": "project:nacl",
"created_ts": "1594316391342798",
"id": "8875231811590667856",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_32-tests-mips\", \"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\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"title\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}}",
"project": "nacl",
"result": "SUCCESS",
"result_details_json": "{\"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\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"title\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030\"}]}, \"bot_id\": \"luci-nacl-toolchain-xenial-2-qshq\", \"branch\": \"refs/heads/master\", \"buildername\": \"linux-pnacl-x86_32-tests-mips\", \"buildnumber\": 5008, \"got_revision\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"mastername\": \"client.nacl.toolchain\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"f2b7d37238a5f49ba00fc1c152cbd5caa278d030\", \"slavetype\": \"BuilderTester\"}, \"swarming\": {\"bot_dimensions\": {\"caches\": [\"builder_5e264a2b33887b9708d9efa4d555f48b42be33439102d42d27d93f0b7d878c19_v2\", \"builder_bf14184df246ade0cf783e61825966ff5c624694bcccef3edd9032289b04d52b_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-2-qshq\"], \"image\": [\"chrome-xenial-20052400-59eb8623c93\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"n1-standard-16\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16.04\"], \"pool\": [\"luci.nacl.toolchain\"], \"python\": [\"2.7.12\"], \"server_version\": [\"5378-e275056\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-b\"]}}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1594324222586249",
"status": "COMPLETED",
"status_changed_ts": "1594325173334239",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_32-tests-mips/5008",
"builder:linux-pnacl-x86_32-tests-mips",
"buildset:commit/git/f2b7d37238a5f49ba00fc1c152cbd5caa278d030",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/f2b7d37238a5f49ba00fc1c152cbd5caa278d030",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9040661876423100960",
"scheduler_job_id:nacl/linux-pnacl-x86_32-tests-mips",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8875231811590667856/+/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:4d4d7b1c9da71410",
"user_agent:luci-scheduler"
],
"updated_ts": "1594325173351717",
"url": "https://ci.chromium.org/b/8875231811590667856",
"utcnow_ts": "1594325174294844"
}
}
[20:06:14.303] Invocation finished in 2h26m26.952079466s with status SUCCEEDED