[23:47:57.374] New invocation is queued and will start shortly
[23:47:59.653] Starting the invocation (attempt 1)
[23:47:59.708] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[23:47:59.708] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[23:47:59.708] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9073887800052708432",
"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\":\"058a26f57015051953a727add26e7e26348b9558\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@058a26f57015051953a727add26e7e26348b9558\",\"title\":\"058a26f57015051953a727add26e7e26348b9558\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/058a26f57015051953a727add26e7e26348b9558\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"058a26f57015051953a727add26e7e26348b9558\"}}",
"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:9073887800052708432",
"scheduler_job_id:nacl/linux-pnacl-x86_32-tests-mips",
"user_agent:luci-scheduler",
"buildset:commit/git/058a26f57015051953a727add26e7e26348b9558",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/058a26f57015051953a727add26e7e26348b9558",
"gitiles_ref:refs/heads/master"
]
}
[23:48:00.839] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1562629679825490",
"id": "8908457736805927952",
"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\": \"058a26f57015051953a727add26e7e26348b9558\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@058a26f57015051953a727add26e7e26348b9558\", \"title\": \"058a26f57015051953a727add26e7e26348b9558\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/058a26f57015051953a727add26e7e26348b9558\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"058a26f57015051953a727add26e7e26348b9558\"}}",
"project": "nacl",
"result_details_json": "{\"properties\": {}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1562629680466639",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_32-tests-mips/4971",
"builder:linux-pnacl-x86_32-tests-mips",
"buildset:commit/git/058a26f57015051953a727add26e7e26348b9558",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/058a26f57015051953a727add26e7e26348b9558",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9073887800052708432",
"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/8908457736805927952/+/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": "1562629680466746",
"url": "https://ci.chromium.org/b/8908457736805927952",
"utcnow_ts": "1562629680816780"
}
}
[23:48:00.839] Task URL: https://ci.chromium.org/b/8908457736805927952
[23:48:00.839] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:2:0) after 1m0s
[23:49:01.001] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:2:0)
[23:49:01.001] Timer tick, asking Buildbucket for the build status
[23:49:01.411] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:49:01.411] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:3:0) after 1m0s
[23:50:01.473] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:3:0)
[23:50:01.473] Timer tick, asking Buildbucket for the build status
[23:50:01.608] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:50:01.608] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:4:0) after 1m0s
[23:51:01.664] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:4:0)
[23:51:01.664] Timer tick, asking Buildbucket for the build status
[23:51:01.821] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:51:01.821] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:5:0) after 1m0s
[23:52:01.846] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:5:0)
[23:52:01.846] Timer tick, asking Buildbucket for the build status
[23:52:02.335] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:52:02.335] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:6:0) after 1m0s
[23:53:02.307] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:6:0)
[23:53:02.307] Timer tick, asking Buildbucket for the build status
[23:53:02.512] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:53:02.512] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:7:0) after 1m0s
[23:54:02.569] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:7:0)
[23:54:02.569] Timer tick, asking Buildbucket for the build status
[23:54:02.737] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:54:02.737] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:8:0) after 1m0s
[23:55:02.784] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:8:0)
[23:55:02.784] Timer tick, asking Buildbucket for the build status
[23:55:03.057] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:55:03.057] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:9:0) after 1m0s
[23:56:03.083] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:9:0)
[23:56:03.083] Timer tick, asking Buildbucket for the build status
[23:56:03.405] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:56:03.405] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:10:0) after 1m0s
[23:57:03.471] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:10:0)
[23:57:03.471] Timer tick, asking Buildbucket for the build status
[23:57:03.572] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:57:03.572] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:11:0) after 1m0s
[23:58:03.568] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:11:0)
[23:58:03.568] Timer tick, asking Buildbucket for the build status
[23:58:03.892] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:58:03.892] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:12:0) after 1m0s
[23:59:03.948] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:12:0)
[23:59:03.948] Timer tick, asking Buildbucket for the build status
[23:59:04.082] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[23:59:04.082] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:13:0) after 1m0s
[00:00:04.126] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:13:0)
[00:00:04.126] Timer tick, asking Buildbucket for the build status
[00:00:04.548] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:00:04.548] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:14:0) after 1m0s
[00:01:04.573] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:14:0)
[00:01:04.573] Timer tick, asking Buildbucket for the build status
[00:01:04.675] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:01:04.675] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:15:0) after 1m0s
[00:02:04.681] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:15:0)
[00:02:04.681] Timer tick, asking Buildbucket for the build status
[00:02:05.164] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:02:05.164] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:16:0) after 1m0s
[00:03:05.223] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:16:0)
[00:03:05.223] Timer tick, asking Buildbucket for the build status
[00:03:05.328] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:03:05.328] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:17:0) after 1m0s
[00:04:05.366] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:17:0)
[00:04:05.366] Timer tick, asking Buildbucket for the build status
[00:04:06.383] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:04:06.383] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:18:0) after 1m0s
[00:05:06.420] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:18:0)
[00:05:06.420] Timer tick, asking Buildbucket for the build status
[00:05:06.557] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:05:06.557] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:19:0) after 1m0s
[00:06:06.637] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:19:0)
[00:06:06.637] Timer tick, asking Buildbucket for the build status
[00:06:07.642] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:06:07.642] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:20:0) after 1m0s
[00:07:07.644] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:20:0)
[00:07:07.644] Timer tick, asking Buildbucket for the build status
[00:07:07.930] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:07:07.930] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:21:0) after 1m0s
[00:08:07.911] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:21:0)
[00:08:07.911] Timer tick, asking Buildbucket for the build status
[00:08:08.712] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:08:08.712] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:22:0) after 1m0s
[00:09:08.697] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:22:0)
[00:09:08.697] Timer tick, asking Buildbucket for the build status
[00:09:09.073] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:09:09.073] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:23:0) after 1m0s
[00:10:09.127] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:23:0)
[00:10:09.127] Timer tick, asking Buildbucket for the build status
[00:10:09.416] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:10:09.416] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:24:0) after 1m0s
[00:11:09.489] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:24:0)
[00:11:09.489] Timer tick, asking Buildbucket for the build status
[00:11:09.762] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:11:09.762] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:25:0) after 1m0s
[00:12:09.778] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:25:0)
[00:12:09.778] Timer tick, asking Buildbucket for the build status
[00:12:11.309] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:12:11.309] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:26:0) after 1m0s
[00:13:11.359] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:26:0)
[00:13:11.359] Timer tick, asking Buildbucket for the build status
[00:13:11.494] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:13:11.494] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:27:0) after 1m0s
[00:14:11.569] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:27:0)
[00:14:11.569] Timer tick, asking Buildbucket for the build status
[00:14:13.577] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:14:13.577] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:28:0) after 1m0s
[00:15:13.645] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:28:0)
[00:15:13.645] Timer tick, asking Buildbucket for the build status
[00:15:14.167] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:15:14.167] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:29:0) after 1m0s
[00:16:14.175] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:29:0)
[00:16:14.176] Timer tick, asking Buildbucket for the build status
[00:16:15.044] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:16:15.044] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:30:0) after 1m0s
[00:17:15.190] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:30:0)
[00:17:15.190] Timer tick, asking Buildbucket for the build status
[00:17:15.348] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:17:15.348] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:31:0) after 1m0s
[00:18:15.404] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:31:0)
[00:18:15.404] Timer tick, asking Buildbucket for the build status
[00:18:15.649] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:18:15.649] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:32:0) after 1m0s
[00:19:15.718] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:32:0)
[00:19:15.718] Timer tick, asking Buildbucket for the build status
[00:19:15.922] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:19:15.922] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:33:0) after 1m0s
[00:20:16.009] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:33:0)
[00:20:16.009] Timer tick, asking Buildbucket for the build status
[00:20:16.712] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:20:16.712] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:34:0) after 1m0s
[00:21:16.801] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:34:0)
[00:21:16.801] Timer tick, asking Buildbucket for the build status
[00:21:17.605] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:21:17.605] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:35:0) after 1m0s
[00:22:17.694] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:35:0)
[00:22:17.694] Timer tick, asking Buildbucket for the build status
[00:22:18.428] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:22:18.428] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:36:0) after 1m0s
[00:23:18.485] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:36:0)
[00:23:18.485] Timer tick, asking Buildbucket for the build status
[00:23:18.863] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:23:18.863] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:37:0) after 1m0s
[00:24:18.883] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:37:0)
[00:24:18.883] Timer tick, asking Buildbucket for the build status
[00:24:19.092] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:24:19.092] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:38:0) after 1m0s
[00:25:19.143] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:38:0)
[00:25:19.143] Timer tick, asking Buildbucket for the build status
[00:25:19.471] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:25:19.471] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:39:0) after 1m0s
[00:26:19.592] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:39:0)
[00:26:19.592] Timer tick, asking Buildbucket for the build status
[00:26:20.435] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:26:20.435] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:40:0) after 1m0s
[00:27:20.462] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:40:0)
[00:27:20.462] Timer tick, asking Buildbucket for the build status
[00:27:20.617] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:27:20.617] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:41:0) after 1m0s
[00:28:20.640] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:41:0)
[00:28:20.640] Timer tick, asking Buildbucket for the build status
[00:28:21.041] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:28:21.041] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:42:0) after 1m0s
[00:29:21.052] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:42:0)
[00:29:21.052] Timer tick, asking Buildbucket for the build status
[00:29:21.322] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:29:21.322] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:43:0) after 1m0s
[00:30:21.363] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:43:0)
[00:30:21.363] Timer tick, asking Buildbucket for the build status
[00:30:21.640] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:30:21.640] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:44:0) after 1m0s
[00:31:21.665] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:44:0)
[00:31:21.665] Timer tick, asking Buildbucket for the build status
[00:31:21.916] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:31:21.916] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:45:0) after 1m0s
[00:32:21.934] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:45:0)
[00:32:21.934] Timer tick, asking Buildbucket for the build status
[00:32:22.076] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:32:22.076] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:46:0) after 1m0s
[00:33:22.108] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:46:0)
[00:33:22.108] Timer tick, asking Buildbucket for the build status
[00:33:22.799] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:33:22.799] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:47:0) after 1m0s
[00:34:22.875] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:47:0)
[00:34:22.875] Timer tick, asking Buildbucket for the build status
[00:34:23.152] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:34:23.152] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:48:0) after 1m0s
[00:35:23.178] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:48:0)
[00:35:23.178] Timer tick, asking Buildbucket for the build status
[00:35:23.319] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:35:23.319] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:49:0) after 1m0s
[00:36:23.376] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:49:0)
[00:36:23.376] Timer tick, asking Buildbucket for the build status
[00:36:24.076] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:36:24.076] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:50:0) after 1m0s
[00:37:24.133] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:50:0)
[00:37:24.133] Timer tick, asking Buildbucket for the build status
[00:37:24.494] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:37:24.494] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:51:0) after 1m0s
[00:38:24.597] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:51:0)
[00:38:24.597] Timer tick, asking Buildbucket for the build status
[00:38:24.914] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:38:24.914] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:52:0) after 1m0s
[00:39:24.932] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:52:0)
[00:39:24.932] Timer tick, asking Buildbucket for the build status
[00:39:25.311] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:39:25.311] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:53:0) after 1m0s
[00:40:25.372] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:53:0)
[00:40:25.372] Timer tick, asking Buildbucket for the build status
[00:40:25.716] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:40:25.716] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:54:0) after 1m0s
[00:41:25.829] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:54:0)
[00:41:25.829] Timer tick, asking Buildbucket for the build status
[00:41:26.076] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:41:26.076] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:55:0) after 1m0s
[00:42:26.226] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:55:0)
[00:42:26.226] Timer tick, asking Buildbucket for the build status
[00:42:26.689] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:42:26.689] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:56:0) after 1m0s
[00:43:26.808] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:56:0)
[00:43:26.808] Timer tick, asking Buildbucket for the build status
[00:43:27.047] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:43:27.047] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:57:0) after 1m0s
[00:44:27.081] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:57:0)
[00:44:27.081] Timer tick, asking Buildbucket for the build status
[00:44:27.512] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:44:27.512] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:58:0) after 1m0s
[00:45:27.556] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:58:0)
[00:45:27.556] Timer tick, asking Buildbucket for the build status
[00:45:27.696] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:45:27.696] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:59:0) after 1m0s
[00:46:27.877] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:59:0)
[00:46:27.877] Timer tick, asking Buildbucket for the build status
[00:46:28.030] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:46:28.030] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:60:0) after 1m0s
[00:47:28.066] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:60:0)
[00:47:28.066] Timer tick, asking Buildbucket for the build status
[00:47:28.212] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:47:28.212] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:61:0) after 1m0s
[00:48:28.334] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:61:0)
[00:48:28.334] Timer tick, asking Buildbucket for the build status
[00:48:28.459] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:48:28.459] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:62:0) after 1m0s
[00:49:28.554] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:62:0)
[00:49:28.554] Timer tick, asking Buildbucket for the build status
[00:49:28.805] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:49:28.805] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:63:0) after 1m0s
[00:50:28.856] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:63:0)
[00:50:28.856] Timer tick, asking Buildbucket for the build status
[00:50:29.512] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:50:29.512] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:64:0) after 1m0s
[00:51:29.600] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:64:0)
[00:51:29.600] Timer tick, asking Buildbucket for the build status
[00:51:29.843] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:51:29.843] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:65:0) after 1m0s
[00:52:29.857] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:65:0)
[00:52:29.857] Timer tick, asking Buildbucket for the build status
[00:52:31.498] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:52:31.498] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:66:0) after 1m0s
[00:53:31.580] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:66:0)
[00:53:31.580] Timer tick, asking Buildbucket for the build status
[00:53:31.824] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:53:31.824] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:67:0) after 1m0s
[00:54:31.852] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:67:0)
[00:54:31.852] Timer tick, asking Buildbucket for the build status
[00:54:31.991] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:54:31.991] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:68:0) after 1m0s
[00:55:32.064] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:68:0)
[00:55:32.064] Timer tick, asking Buildbucket for the build status
[00:55:32.589] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:55:32.589] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:69:0) after 1m0s
[00:56:32.682] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:69:0)
[00:56:32.682] Timer tick, asking Buildbucket for the build status
[00:56:32.879] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:56:32.879] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:70:0) after 1m0s
[00:57:32.945] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:70:0)
[00:57:32.945] Timer tick, asking Buildbucket for the build status
[00:57:33.216] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:57:33.216] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:71:0) after 1m0s
[00:58:33.274] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:71:0)
[00:58:33.274] Timer tick, asking Buildbucket for the build status
[00:58:33.359] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:58:33.359] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:72:0) after 1m0s
[00:59:33.459] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:72:0)
[00:59:33.459] Timer tick, asking Buildbucket for the build status
[00:59:33.576] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:59:33.576] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:73:0) after 1m0s
[01:00:33.560] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:73:0)
[01:00:33.560] Timer tick, asking Buildbucket for the build status
[01:00:33.679] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:00:33.679] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:74:0) after 1m0s
[01:01:33.733] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:74:0)
[01:01:33.733] Timer tick, asking Buildbucket for the build status
[01:01:34.372] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:01:34.372] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:75:0) after 1m0s
[01:02:34.473] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:75:0)
[01:02:34.473] Timer tick, asking Buildbucket for the build status
[01:02:34.576] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:02:34.576] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:76:0) after 1m0s
[01:03:34.707] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:76:0)
[01:03:34.707] Timer tick, asking Buildbucket for the build status
[01:03:34.821] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:03:34.821] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:77:0) after 1m0s
[01:04:34.944] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:77:0)
[01:04:34.944] Timer tick, asking Buildbucket for the build status
[01:04:35.510] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:04:35.510] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:78:0) after 1m0s
[01:05:35.556] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:78:0)
[01:05:35.556] Timer tick, asking Buildbucket for the build status
[01:05:35.884] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:05:35.884] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:79:0) after 1m0s
[01:06:35.954] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:79:0)
[01:06:35.954] Timer tick, asking Buildbucket for the build status
[01:06:36.106] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:06:36.106] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:80:0) after 1m0s
[01:07:36.147] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:80:0)
[01:07:36.147] Timer tick, asking Buildbucket for the build status
[01:07:36.265] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:07:36.265] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:81:0) after 1m0s
[01:08:36.293] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:81:0)
[01:08:36.293] Timer tick, asking Buildbucket for the build status
[01:08:37.005] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:08:37.005] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:82:0) after 1m0s
[01:09:37.136] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:82:0)
[01:09:37.136] Timer tick, asking Buildbucket for the build status
[01:09:37.299] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:09:37.299] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:83:0) after 1m0s
[01:10:37.341] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:83:0)
[01:10:37.341] Timer tick, asking Buildbucket for the build status
[01:10:37.506] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:10:37.506] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:84:0) after 1m0s
[01:11:37.537] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:84:0)
[01:11:37.537] Timer tick, asking Buildbucket for the build status
[01:11:37.611] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:11:37.611] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:85:0) after 1m0s
[01:12:37.665] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:85:0)
[01:12:37.665] Timer tick, asking Buildbucket for the build status
[01:12:37.937] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:12:37.937] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:86:0) after 1m0s
[01:13:37.962] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:86:0)
[01:13:37.962] Timer tick, asking Buildbucket for the build status
[01:13:38.191] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:13:38.191] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:87:0) after 1m0s
[01:14:38.289] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:87:0)
[01:14:38.289] Timer tick, asking Buildbucket for the build status
[01:14:38.501] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:14:38.501] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:88:0) after 1m0s
[01:15:38.555] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:88:0)
[01:15:38.555] Timer tick, asking Buildbucket for the build status
[01:15:38.803] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:15:38.803] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:89:0) after 1m0s
[01:16:38.883] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:89:0)
[01:16:38.883] Timer tick, asking Buildbucket for the build status
[01:16:39.764] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:16:39.765] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:90:0) after 1m0s
[01:17:39.851] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:90:0)
[01:17:39.851] Timer tick, asking Buildbucket for the build status
[01:17:40.049] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:17:40.049] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:91:0) after 1m0s
[01:18:40.257] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:91:0)
[01:18:40.257] Timer tick, asking Buildbucket for the build status
[01:18:40.720] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:18:40.721] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:92:0) after 1m0s
[01:19:40.827] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:92:0)
[01:19:40.827] Timer tick, asking Buildbucket for the build status
[01:19:41.309] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:19:41.309] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:93:0) after 1m0s
[01:20:41.333] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:93:0)
[01:20:41.333] Timer tick, asking Buildbucket for the build status
[01:20:41.596] Build 8908457736805927952: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[01:20:41.596] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:94:0) after 1m0s
[01:21:22.800] Received PubSub notification, asking Buildbucket for the build status
[01:21:22.921] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:21:41.573] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:94:0)
[01:21:41.573] Timer tick, asking Buildbucket for the build status
[01:21:41.704] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:21:41.704] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:96:0) after 1m0s
[01:22:41.729] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:96:0)
[01:22:41.729] Timer tick, asking Buildbucket for the build status
[01:22:41.928] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:22:41.928] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:97:0) after 1m0s
[01:23:41.954] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:97:0)
[01:23:41.954] Timer tick, asking Buildbucket for the build status
[01:23:42.817] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:23:42.817] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:98:0) after 1m0s
[01:24:42.834] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:98:0)
[01:24:42.834] Timer tick, asking Buildbucket for the build status
[01:24:42.951] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:24:42.951] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:99:0) after 1m0s
[01:25:43.000] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:99:0)
[01:25:43.000] Timer tick, asking Buildbucket for the build status
[01:25:43.337] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:25:43.337] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:100:0) after 1m0s
[01:26:43.363] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:100:0)
[01:26:43.363] Timer tick, asking Buildbucket for the build status
[01:26:43.470] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:26:43.470] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:101:0) after 1m0s
[01:27:43.600] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:101:0)
[01:27:43.600] Timer tick, asking Buildbucket for the build status
[01:27:43.758] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:27:43.758] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:102:0) after 1m0s
[01:28:43.781] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:102:0)
[01:28:43.781] Timer tick, asking Buildbucket for the build status
[01:28:43.858] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:28:43.858] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:103:0) after 1m0s
[01:29:43.907] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:103:0)
[01:29:43.907] Timer tick, asking Buildbucket for the build status
[01:29:43.987] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:29:43.987] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:104:0) after 1m0s
[01:30:44.056] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:104:0)
[01:30:44.056] Timer tick, asking Buildbucket for the build status
[01:30:44.520] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:30:44.520] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:105:0) after 1m0s
[01:31:44.625] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:105:0)
[01:31:44.625] Timer tick, asking Buildbucket for the build status
[01:31:45.198] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:31:45.198] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:106:0) after 1m0s
[01:32:45.319] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:106:0)
[01:32:45.319] Timer tick, asking Buildbucket for the build status
[01:32:45.556] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:32:45.556] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:107:0) after 1m0s
[01:33:45.638] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:107:0)
[01:33:45.638] Timer tick, asking Buildbucket for the build status
[01:33:45.742] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:33:45.742] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:108:0) after 1m0s
[01:34:45.773] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:108:0)
[01:34:45.773] Timer tick, asking Buildbucket for the build status
[01:34:45.874] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:34:45.874] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:109:0) after 1m0s
[01:35:46.001] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:109:0)
[01:35:46.001] Timer tick, asking Buildbucket for the build status
[01:35:46.108] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:35:46.108] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:110:0) after 1m0s
[01:36:46.263] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:110:0)
[01:36:46.263] Timer tick, asking Buildbucket for the build status
[01:36:46.954] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:36:46.954] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:111:0) after 1m0s
[01:37:47.035] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:111:0)
[01:37:47.035] Timer tick, asking Buildbucket for the build status
[01:37:47.266] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:37:47.266] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:112:0) after 1m0s
[01:38:47.366] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:112:0)
[01:38:47.366] Timer tick, asking Buildbucket for the build status
[01:38:47.463] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:38:47.463] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:113:0) after 1m0s
[01:39:47.537] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:113:0)
[01:39:47.537] Timer tick, asking Buildbucket for the build status
[01:39:47.650] Build 8908457736805927952: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:39:47.650] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_32-tests-mips:9073887800052708432:114:0) after 1m0s
[01:40:36.907] Received PubSub notification, asking Buildbucket for the build status
[01:40:37.427] Build 8908457736805927952: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[01:40:37.428] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1562636434703999",
"created_by": "project:nacl",
"created_ts": "1562629679825490",
"id": "8908457736805927952",
"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\": \"058a26f57015051953a727add26e7e26348b9558\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@058a26f57015051953a727add26e7e26348b9558\", \"title\": \"058a26f57015051953a727add26e7e26348b9558\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/058a26f57015051953a727add26e7e26348b9558\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"058a26f57015051953a727add26e7e26348b9558\"}}",
"project": "nacl",
"result": "SUCCESS",
"result_details_json": "{\"properties\": {\"$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\": \"058a26f57015051953a727add26e7e26348b9558\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@058a26f57015051953a727add26e7e26348b9558\", \"title\": \"058a26f57015051953a727add26e7e26348b9558\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/058a26f57015051953a727add26e7e26348b9558\"}]}, \"bot_id\": \"luci-nacl-toolchain-trusty-0-t9o4\", \"branch\": \"refs/heads/master\", \"buildername\": \"linux-pnacl-x86_32-tests-mips\", \"buildnumber\": 4971, \"got_revision\": \"058a26f57015051953a727add26e7e26348b9558\", \"mastername\": \"client.nacl.toolchain\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"058a26f57015051953a727add26e7e26348b9558\", \"slavetype\": \"BuilderTester\"}, \"swarming\": {\"bot_dimensions\": {\"caches\": [\"git\", \"goma_v2\", \"vpython\"], \"cores\": [\"16\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gpu\": [\"none\"], \"id\": [\"luci-nacl-toolchain-trusty-0-t9o4\"], \"image\": [\"chrome-trusty-19041600-95c8804d634\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"machine_type\": [\"n1-standard-16\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-14.04\"], \"pool\": [\"luci.nacl.toolchain\"], \"python\": [\"2.7.6\"], \"server_version\": [\"4365-1559751\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-b\"]}}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1562635281260356",
"status": "COMPLETED",
"status_changed_ts": "1562636436177050",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_32-tests-mips/4971",
"builder:linux-pnacl-x86_32-tests-mips",
"buildset:commit/git/058a26f57015051953a727add26e7e26348b9558",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/058a26f57015051953a727add26e7e26348b9558",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9073887800052708432",
"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/8908457736805927952/+/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:45ecce385c408810",
"user_agent:luci-scheduler"
],
"updated_ts": "1562636436556039",
"url": "https://ci.chromium.org/b/8908457736805927952",
"utcnow_ts": "1562636437389332"
}
}
[01:40:37.428] Invocation finished in 1h52m40.082636544s with status SUCCEEDED