[11:32:11.832] New invocation is queued and will start shortly
[11:32:16.607] Starting the invocation (attempt 1)
[11:32:16.664] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[11:32:16.664] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[11:32:16.664] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9040685003328090192",
"parameters_json": "{\"builder_name\":\"linux-pnacl-x86_64-tests-x86_64\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"gitiles\":{\"ref\":\"refs/heads/master\",\"repo\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\",\"title\":\"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux-pnacl-x86_64-tests-x86_64",
"scheduler_invocation_id:9040685003328090192",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_64",
"user_agent:luci-scheduler",
"buildset:commit/git/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972",
"gitiles_ref:refs/heads/master"
]
}
[11:32:17.807] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1594294336783711",
"id": "8875254937471378096",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_64\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"title\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}}",
"project": "nacl",
"result_details_json": "{\"properties\": {}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1594294337641168",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_64/5111",
"builder:linux-pnacl-x86_64-tests-x86_64",
"buildset:commit/git/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9040685003328090192",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_64",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8875254937471378096/+/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": "1594294337641397",
"url": "https://ci.chromium.org/b/8875254937471378096",
"utcnow_ts": "1594294337797663"
}
}
[11:32:17.807] Task URL: https://ci.chromium.org/b/8875254937471378096
[11:32:17.807] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:2:0) after 1m0s
[11:33:17.954] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:2:0)
[11:33:17.954] Timer tick, asking Buildbucket for the build status
[11:33:18.166] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:33:18.166] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:3:0) after 1m0s
[11:34:18.328] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:3:0)
[11:34:18.328] Timer tick, asking Buildbucket for the build status
[11:34:18.487] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:34:18.487] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:4:0) after 1m0s
[11:35:18.712] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:4:0)
[11:35:18.712] Timer tick, asking Buildbucket for the build status
[11:35:18.888] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:35:18.888] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:5:0) after 1m0s
[11:36:18.993] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:5:0)
[11:36:18.994] Timer tick, asking Buildbucket for the build status
[11:36:19.434] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:36:19.434] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:6:0) after 1m0s
[11:37:19.566] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:6:0)
[11:37:19.566] Timer tick, asking Buildbucket for the build status
[11:37:19.952] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:37:19.952] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:7:0) after 1m0s
[11:38:20.534] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:7:0)
[11:38:20.534] Timer tick, asking Buildbucket for the build status
[11:38:21.445] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:38:21.445] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:8:0) after 1m0s
[11:39:21.627] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:8:0)
[11:39:21.628] Timer tick, asking Buildbucket for the build status
[11:39:21.744] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:39:21.744] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:9:0) after 1m0s
[11:40:22.028] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:9:0)
[11:40:22.028] Timer tick, asking Buildbucket for the build status
[11:40:22.287] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:40:22.287] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:10:0) after 1m0s
[11:41:22.297] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:10:0)
[11:41:22.297] Timer tick, asking Buildbucket for the build status
[11:41:22.483] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:41:22.483] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:11:0) after 1m0s
[11:42:22.732] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:11:0)
[11:42:22.732] Timer tick, asking Buildbucket for the build status
[11:42:22.870] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:42:22.870] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:12:0) after 1m0s
[11:43:23.170] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:12:0)
[11:43:23.170] Timer tick, asking Buildbucket for the build status
[11:43:23.447] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:43:23.447] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:13:0) after 1m0s
[11:44:23.506] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:13:0)
[11:44:23.506] Timer tick, asking Buildbucket for the build status
[11:44:23.951] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:44:23.951] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:14:0) after 1m0s
[11:45:24.576] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:14:0)
[11:45:24.576] Timer tick, asking Buildbucket for the build status
[11:45:24.711] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:45:24.711] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:15:0) after 1m0s
[11:46:24.767] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:15:0)
[11:46:24.767] Timer tick, asking Buildbucket for the build status
[11:46:24.900] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:46:24.900] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:16:0) after 1m0s
[11:47:25.102] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:16:0)
[11:47:25.102] Timer tick, asking Buildbucket for the build status
[11:47:25.347] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:47:25.347] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:17:0) after 1m0s
[11:48:25.429] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:17:0)
[11:48:25.429] Timer tick, asking Buildbucket for the build status
[11:48:25.769] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:48:25.769] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:18:0) after 1m0s
[11:49:26.077] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:18:0)
[11:49:26.077] Timer tick, asking Buildbucket for the build status
[11:49:26.365] Build 8875254937471378096: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[11:49:26.365] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:19:0) after 1m0s
[11:49:50.767] Received PubSub notification, asking Buildbucket for the build status
[11:49:50.895] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:50:26.522] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:19:0)
[11:50:26.522] Timer tick, asking Buildbucket for the build status
[11:50:26.663] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:50:26.663] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:21:0) after 1m0s
[11:51:26.708] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:21:0)
[11:51:26.708] Timer tick, asking Buildbucket for the build status
[11:51:27.005] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:51:27.005] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:22:0) after 1m0s
[11:52:27.011] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:22:0)
[11:52:27.011] Timer tick, asking Buildbucket for the build status
[11:52:27.311] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:52:27.311] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:23:0) after 1m0s
[11:53:27.365] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:23:0)
[11:53:27.365] Timer tick, asking Buildbucket for the build status
[11:53:27.600] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:53:27.600] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:24:0) after 1m0s
[11:54:27.644] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:24:0)
[11:54:27.644] Timer tick, asking Buildbucket for the build status
[11:54:28.208] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:54:28.208] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:25:0) after 1m0s
[11:55:28.298] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:25:0)
[11:55:28.298] Timer tick, asking Buildbucket for the build status
[11:55:28.555] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:55:28.555] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:26:0) after 1m0s
[11:56:28.572] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:26:0)
[11:56:28.572] Timer tick, asking Buildbucket for the build status
[11:56:28.934] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:56:28.934] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:27:0) after 1m0s
[11:57:28.919] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:27:0)
[11:57:28.919] Timer tick, asking Buildbucket for the build status
[11:57:29.063] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:57:29.063] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:28:0) after 1m0s
[11:58:29.188] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:28:0)
[11:58:29.188] Timer tick, asking Buildbucket for the build status
[11:58:29.527] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:58:29.527] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:29:0) after 1m0s
[11:59:29.563] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:29:0)
[11:59:29.563] Timer tick, asking Buildbucket for the build status
[11:59:29.802] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:59:29.802] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:30:0) after 1m0s
[12:00:29.865] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:30:0)
[12:00:29.865] Timer tick, asking Buildbucket for the build status
[12:00:30.161] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:00:30.161] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:31:0) after 1m0s
[12:01:30.247] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:31:0)
[12:01:30.247] Timer tick, asking Buildbucket for the build status
[12:01:31.304] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:01:31.304] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:32:0) after 1m0s
[12:02:31.379] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:32:0)
[12:02:31.379] Timer tick, asking Buildbucket for the build status
[12:02:31.554] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:02:31.554] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:33:0) after 1m0s
[12:03:31.604] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:33:0)
[12:03:31.604] Timer tick, asking Buildbucket for the build status
[12:03:31.775] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:03:31.775] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:34:0) after 1m0s
[12:04:31.810] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:34:0)
[12:04:31.810] Timer tick, asking Buildbucket for the build status
[12:04:31.917] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:04:31.917] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:35:0) after 1m0s
[12:05:31.940] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:35:0)
[12:05:31.940] Timer tick, asking Buildbucket for the build status
[12:05:32.079] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:05:32.079] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:36:0) after 1m0s
[12:06:32.122] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:36:0)
[12:06:32.122] Timer tick, asking Buildbucket for the build status
[12:06:32.261] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:06:32.261] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:37:0) after 1m0s
[12:07:32.306] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:37:0)
[12:07:32.306] Timer tick, asking Buildbucket for the build status
[12:07:32.638] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:07:32.638] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:38:0) after 1m0s
[12:08:32.737] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:38:0)
[12:08:32.737] Timer tick, asking Buildbucket for the build status
[12:08:32.892] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:08:32.892] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:39:0) after 1m0s
[12:09:33.045] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:39:0)
[12:09:33.045] Timer tick, asking Buildbucket for the build status
[12:09:33.211] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:09:33.211] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:40:0) after 1m0s
[12:10:33.285] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:40:0)
[12:10:33.285] Timer tick, asking Buildbucket for the build status
[12:10:33.412] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:10:33.412] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:41:0) after 1m0s
[12:11:33.560] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:41:0)
[12:11:33.560] Timer tick, asking Buildbucket for the build status
[12:11:33.761] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:11:33.761] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:42:0) after 1m0s
[12:12:33.989] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:42:0)
[12:12:33.989] Timer tick, asking Buildbucket for the build status
[12:12:39.063] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:12:39.063] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:43:0) after 1m0s
[12:13:39.092] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:43:0)
[12:13:39.092] Timer tick, asking Buildbucket for the build status
[12:13:39.314] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:13:39.314] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:44:0) after 1m0s
[12:14:39.337] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:44:0)
[12:14:39.337] Timer tick, asking Buildbucket for the build status
[12:14:39.491] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:14:39.491] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:45:0) after 1m0s
[12:15:39.514] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:45:0)
[12:15:39.514] Timer tick, asking Buildbucket for the build status
[12:15:39.625] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:15:39.625] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:46:0) after 1m0s
[12:16:39.646] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:46:0)
[12:16:39.646] Timer tick, asking Buildbucket for the build status
[12:16:39.772] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:16:39.772] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:47:0) after 1m0s
[12:17:39.804] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:47:0)
[12:17:39.804] Timer tick, asking Buildbucket for the build status
[12:17:40.118] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:17:40.118] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:48:0) after 1m0s
[12:18:40.141] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:48:0)
[12:18:40.141] Timer tick, asking Buildbucket for the build status
[12:18:40.522] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:18:40.523] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:49:0) after 1m0s
[12:19:40.545] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:49:0)
[12:19:40.545] Timer tick, asking Buildbucket for the build status
[12:19:40.716] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:19:40.716] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:50:0) after 1m0s
[12:20:40.804] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:50:0)
[12:20:40.804] Timer tick, asking Buildbucket for the build status
[12:20:41.005] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:20:41.005] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:51:0) after 1m0s
[12:21:41.092] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:51:0)
[12:21:41.092] Timer tick, asking Buildbucket for the build status
[12:21:41.208] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:21:41.208] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:52:0) after 1m0s
[12:22:41.285] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:52:0)
[12:22:41.285] Timer tick, asking Buildbucket for the build status
[12:22:41.529] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:22:41.529] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:53:0) after 1m0s
[12:23:41.599] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:53:0)
[12:23:41.599] Timer tick, asking Buildbucket for the build status
[12:23:41.992] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:23:41.992] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:54:0) after 1m0s
[12:24:44.786] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:54:0)
[12:24:44.786] Timer tick, asking Buildbucket for the build status
[12:24:44.967] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:24:44.967] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:55:0) after 1m0s
[12:25:45.439] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:55:0)
[12:25:45.439] Timer tick, asking Buildbucket for the build status
[12:25:45.688] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:25:45.688] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:56:0) after 1m0s
[12:26:47.888] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:56:0)
[12:26:47.888] Timer tick, asking Buildbucket for the build status
[12:26:48.305] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:26:48.305] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:57:0) after 1m0s
[12:27:48.488] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:57:0)
[12:27:48.488] Timer tick, asking Buildbucket for the build status
[12:27:48.707] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:27:48.707] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:58:0) after 1m0s
[12:28:48.883] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:58:0)
[12:28:48.883] Timer tick, asking Buildbucket for the build status
[12:28:49.338] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:28:49.338] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:59:0) after 1m0s
[12:29:49.573] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:59:0)
[12:29:49.573] Timer tick, asking Buildbucket for the build status
[12:29:50.125] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:29:50.125] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:60:0) after 1m0s
[12:30:50.414] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:60:0)
[12:30:50.414] Timer tick, asking Buildbucket for the build status
[12:30:50.770] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:30:50.770] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:61:0) after 1m0s
[12:31:50.831] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:61:0)
[12:31:50.831] Timer tick, asking Buildbucket for the build status
[12:31:51.197] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:31:51.197] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:62:0) after 1m0s
[12:32:51.414] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:62:0)
[12:32:51.414] Timer tick, asking Buildbucket for the build status
[12:32:51.542] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:32:51.542] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:63:0) after 1m0s
[12:33:51.580] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:63:0)
[12:33:51.580] Timer tick, asking Buildbucket for the build status
[12:33:51.781] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:33:51.781] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:64:0) after 1m0s
[12:34:51.861] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:64:0)
[12:34:51.861] Timer tick, asking Buildbucket for the build status
[12:34:52.035] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:34:52.035] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:65:0) after 1m0s
[12:35:52.072] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:65:0)
[12:35:52.072] Timer tick, asking Buildbucket for the build status
[12:35:52.244] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:35:52.244] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:66:0) after 1m0s
[12:36:54.029] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:66:0)
[12:36:54.029] Timer tick, asking Buildbucket for the build status
[12:36:54.185] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:36:54.185] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:67:0) after 1m0s
[12:37:54.590] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:67:0)
[12:37:54.590] Timer tick, asking Buildbucket for the build status
[12:37:54.801] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:37:54.801] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:68:0) after 1m0s
[12:38:56.310] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:68:0)
[12:38:56.310] Timer tick, asking Buildbucket for the build status
[12:38:56.914] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:38:56.914] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:69:0) after 1m0s
[12:39:56.912] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:69:0)
[12:39:56.912] Timer tick, asking Buildbucket for the build status
[12:39:57.428] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:39:57.428] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:70:0) after 1m0s
[12:40:57.454] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:70:0)
[12:40:57.454] Timer tick, asking Buildbucket for the build status
[12:40:57.836] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:40:57.836] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:71:0) after 1m0s
[12:41:57.912] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:71:0)
[12:41:57.912] Timer tick, asking Buildbucket for the build status
[12:41:58.480] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:41:58.480] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:72:0) after 1m0s
[12:42:58.513] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:72:0)
[12:42:58.513] Timer tick, asking Buildbucket for the build status
[12:42:59.105] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:42:59.105] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:73:0) after 1m0s
[12:43:59.134] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:73:0)
[12:43:59.134] Timer tick, asking Buildbucket for the build status
[12:43:59.291] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:43:59.291] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:74:0) after 1m0s
[12:44:59.399] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:74:0)
[12:44:59.399] Timer tick, asking Buildbucket for the build status
[12:44:59.573] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:44:59.573] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:75:0) after 1m0s
[12:45:59.624] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:75:0)
[12:45:59.624] Timer tick, asking Buildbucket for the build status
[12:45:59.805] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:45:59.805] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:76:0) after 1m0s
[12:47:00.050] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:76:0)
[12:47:00.050] Timer tick, asking Buildbucket for the build status
[12:47:00.407] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:47:00.407] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:77:0) after 1m0s
[12:48:00.472] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:77:0)
[12:48:00.472] Timer tick, asking Buildbucket for the build status
[12:48:00.655] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:48:00.655] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:78:0) after 1m0s
[12:49:00.725] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:78:0)
[12:49:00.725] Timer tick, asking Buildbucket for the build status
[12:49:00.856] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:49:00.856] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:79:0) after 1m0s
[12:50:00.993] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:79:0)
[12:50:00.993] Timer tick, asking Buildbucket for the build status
[12:50:01.290] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:50:01.290] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:80:0) after 1m0s
[12:51:01.393] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:80:0)
[12:51:01.393] Timer tick, asking Buildbucket for the build status
[12:51:01.497] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:51:01.497] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:81:0) after 1m0s
[12:52:01.816] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:81:0)
[12:52:01.816] Timer tick, asking Buildbucket for the build status
[12:52:01.947] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:52:01.947] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:82:0) after 1m0s
[12:53:02.186] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:82:0)
[12:53:02.186] Timer tick, asking Buildbucket for the build status
[12:53:02.492] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:53:02.492] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:83:0) after 1m0s
[12:54:02.536] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:83:0)
[12:54:02.536] Timer tick, asking Buildbucket for the build status
[12:54:02.824] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:54:02.824] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:84:0) after 1m0s
[12:55:02.892] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:84:0)
[12:55:02.892] Timer tick, asking Buildbucket for the build status
[12:55:15.446] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:55:15.446] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:85:0) after 1m0s
[12:56:15.521] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:85:0)
[12:56:15.521] Timer tick, asking Buildbucket for the build status
[12:56:15.671] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:56:15.671] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:86:0) after 1m0s
[12:57:15.668] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:86:0)
[12:57:15.669] Timer tick, asking Buildbucket for the build status
[12:57:15.813] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:57:15.813] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:87:0) after 1m0s
[12:58:15.840] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:87:0)
[12:58:15.840] Timer tick, asking Buildbucket for the build status
[12:58:16.146] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:58:16.146] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:88:0) after 1m0s
[12:59:16.147] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:88:0)
[12:59:16.147] Timer tick, asking Buildbucket for the build status
[12:59:17.125] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:59:17.125] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:89:0) after 1m0s
[13:00:17.212] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:89:0)
[13:00:17.212] Timer tick, asking Buildbucket for the build status
[13:00:17.411] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:00:17.411] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:90:0) after 1m0s
[13:01:17.572] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:90:0)
[13:01:17.572] Timer tick, asking Buildbucket for the build status
[13:01:22.258] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:01:22.258] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:91:0) after 1m0s
[13:02:22.384] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:91:0)
[13:02:22.384] Timer tick, asking Buildbucket for the build status
[13:02:22.509] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:02:22.509] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:92:0) after 1m0s
[13:03:22.680] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:92:0)
[13:03:22.680] Timer tick, asking Buildbucket for the build status
[13:03:22.812] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:03:22.812] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:93:0) after 1m0s
[13:04:22.953] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:93:0)
[13:04:22.953] Timer tick, asking Buildbucket for the build status
[13:04:23.459] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:04:23.459] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:94:0) after 1m0s
[13:05:23.468] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:94:0)
[13:05:23.468] Timer tick, asking Buildbucket for the build status
[13:05:23.917] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:05:23.917] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:95:0) after 1m0s
[13:06:24.002] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:95:0)
[13:06:24.002] Timer tick, asking Buildbucket for the build status
[13:06:24.136] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:06:24.136] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:96:0) after 1m0s
[13:07:24.150] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:96:0)
[13:07:24.150] Timer tick, asking Buildbucket for the build status
[13:07:28.753] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:07:28.753] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:97:0) after 1m0s
[13:08:28.761] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:97:0)
[13:08:28.761] Timer tick, asking Buildbucket for the build status
[13:08:28.903] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:08:28.903] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:98:0) after 1m0s
[13:09:29.068] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:98:0)
[13:09:29.068] Timer tick, asking Buildbucket for the build status
[13:09:29.213] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:09:29.213] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:99:0) after 1m0s
[13:10:29.246] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:99:0)
[13:10:29.246] Timer tick, asking Buildbucket for the build status
[13:10:29.712] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:10:29.712] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:100:0) after 1m0s
[13:11:29.740] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:100:0)
[13:11:29.740] Timer tick, asking Buildbucket for the build status
[13:11:30.183] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:11:30.183] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:101:0) after 1m0s
[13:12:30.187] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:101:0)
[13:12:30.187] Timer tick, asking Buildbucket for the build status
[13:12:30.320] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:12:30.320] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:102:0) after 1m0s
[13:13:30.322] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:102:0)
[13:13:30.322] Timer tick, asking Buildbucket for the build status
[13:13:31.147] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:13:31.147] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:103:0) after 1m0s
[13:14:31.172] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:103:0)
[13:14:31.173] Timer tick, asking Buildbucket for the build status
[13:14:31.417] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:14:31.418] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:104:0) after 1m0s
[13:15:31.443] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:104:0)
[13:15:31.444] Timer tick, asking Buildbucket for the build status
[13:15:31.897] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:15:31.897] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:105:0) after 1m0s
[13:16:31.921] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:105:0)
[13:16:31.921] Timer tick, asking Buildbucket for the build status
[13:16:32.071] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:16:32.071] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:106:0) after 1m0s
[13:17:32.099] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:106:0)
[13:17:32.099] Timer tick, asking Buildbucket for the build status
[13:17:32.231] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:17:32.231] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:107:0) after 1m0s
[13:18:32.336] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:107:0)
[13:18:32.336] Timer tick, asking Buildbucket for the build status
[13:18:32.706] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:18:32.706] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:108:0) after 1m0s
[13:19:32.747] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:108:0)
[13:19:32.747] Timer tick, asking Buildbucket for the build status
[13:19:34.211] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:19:34.211] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:109:0) after 1m0s
[13:20:34.288] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:109:0)
[13:20:34.288] Timer tick, asking Buildbucket for the build status
[13:20:35.486] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:20:35.486] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:110:0) after 1m0s
[13:21:35.464] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:110:0)
[13:21:35.464] Timer tick, asking Buildbucket for the build status
[13:21:35.741] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:21:35.741] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:111:0) after 1m0s
[13:22:35.828] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:111:0)
[13:22:35.828] Timer tick, asking Buildbucket for the build status
[13:22:36.008] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:22:36.008] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:112:0) after 1m0s
[13:23:36.051] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:112:0)
[13:23:36.051] Timer tick, asking Buildbucket for the build status
[13:23:36.190] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:23:36.190] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:113:0) after 1m0s
[13:24:36.247] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:113:0)
[13:24:36.247] Timer tick, asking Buildbucket for the build status
[13:24:36.375] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:24:36.375] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:114:0) after 1m0s
[13:25:36.484] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:114:0)
[13:25:36.484] Timer tick, asking Buildbucket for the build status
[13:25:36.639] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:25:36.639] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:115:0) after 1m0s
[13:26:36.716] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:115:0)
[13:26:36.716] Timer tick, asking Buildbucket for the build status
[13:26:37.095] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:26:37.095] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:116:0) after 1m0s
[13:27:37.136] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:116:0)
[13:27:37.136] Timer tick, asking Buildbucket for the build status
[13:27:37.334] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:27:37.334] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:117:0) after 1m0s
[13:28:37.507] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:117:0)
[13:28:37.507] Timer tick, asking Buildbucket for the build status
[13:28:37.640] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:28:37.640] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:118:0) after 1m0s
[13:29:37.754] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:118:0)
[13:29:37.754] Timer tick, asking Buildbucket for the build status
[13:29:37.918] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:29:37.918] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:119:0) after 1m0s
[13:30:38.021] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:119:0)
[13:30:38.021] Timer tick, asking Buildbucket for the build status
[13:30:38.211] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:30:38.211] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:120:0) after 1m0s
[13:31:38.532] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:120:0)
[13:31:38.532] Timer tick, asking Buildbucket for the build status
[13:31:39.045] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:31:39.045] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:121:0) after 1m0s
[13:32:39.232] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:121:0)
[13:32:39.232] Timer tick, asking Buildbucket for the build status
[13:32:39.505] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:32:39.505] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:122:0) after 1m0s
[13:33:39.628] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:122:0)
[13:33:39.628] Timer tick, asking Buildbucket for the build status
[13:33:40.105] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:33:40.105] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:123:0) after 1m0s
[13:34:40.121] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:123:0)
[13:34:40.121] Timer tick, asking Buildbucket for the build status
[13:34:40.317] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:34:40.317] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:124:0) after 1m0s
[13:35:40.356] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:124:0)
[13:35:40.356] Timer tick, asking Buildbucket for the build status
[13:35:40.520] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:35:40.520] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:125:0) after 1m0s
[13:36:40.578] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:125:0)
[13:36:40.578] Timer tick, asking Buildbucket for the build status
[13:36:40.797] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:36:40.797] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:126:0) after 1m0s
[13:37:40.929] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:126:0)
[13:37:40.929] Timer tick, asking Buildbucket for the build status
[13:37:41.123] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:37:41.123] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:127:0) after 1m0s
[13:38:41.153] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:127:0)
[13:38:41.153] Timer tick, asking Buildbucket for the build status
[13:38:41.946] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:38:41.946] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:128:0) after 1m0s
[13:39:41.988] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:128:0)
[13:39:41.988] Timer tick, asking Buildbucket for the build status
[13:39:42.198] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:39:42.198] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:129:0) after 1m0s
[13:40:42.257] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:129:0)
[13:40:42.258] Timer tick, asking Buildbucket for the build status
[13:40:42.613] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:40:42.613] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:130:0) after 1m0s
[13:41:42.667] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:130:0)
[13:41:42.667] Timer tick, asking Buildbucket for the build status
[13:41:42.788] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:41:42.788] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:131:0) after 1m0s
[13:42:42.876] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:131:0)
[13:42:42.876] Timer tick, asking Buildbucket for the build status
[13:42:43.014] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:42:43.015] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:132:0) after 1m0s
[13:43:43.219] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:132:0)
[13:43:43.219] Timer tick, asking Buildbucket for the build status
[13:43:43.351] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:43:43.351] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:133:0) after 1m0s
[13:44:43.379] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:133:0)
[13:44:43.379] Timer tick, asking Buildbucket for the build status
[13:44:43.699] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:44:43.699] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:134:0) after 1m0s
[13:45:43.793] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:134:0)
[13:45:43.793] Timer tick, asking Buildbucket for the build status
[13:45:46.332] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:45:46.332] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:135:0) after 1m0s
[13:46:46.400] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:135:0)
[13:46:46.400] Timer tick, asking Buildbucket for the build status
[13:46:46.558] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:46:46.558] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:136:0) after 1m0s
[13:47:46.638] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:136:0)
[13:47:46.638] Timer tick, asking Buildbucket for the build status
[13:47:46.746] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:47:46.746] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:137:0) after 1m0s
[13:48:47.007] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:137:0)
[13:48:47.007] Timer tick, asking Buildbucket for the build status
[13:48:47.166] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:48:47.166] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:138:0) after 1m0s
[13:49:47.211] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:138:0)
[13:49:47.211] Timer tick, asking Buildbucket for the build status
[13:49:47.332] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:49:47.332] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:139:0) after 1m0s
[13:50:47.392] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:139:0)
[13:50:47.392] Timer tick, asking Buildbucket for the build status
[13:50:47.543] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:50:47.543] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:140:0) after 1m0s
[13:51:47.575] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:140:0)
[13:51:47.575] Timer tick, asking Buildbucket for the build status
[13:51:48.017] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:51:48.017] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:141:0) after 1m0s
[13:52:48.173] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:141:0)
[13:52:48.173] Timer tick, asking Buildbucket for the build status
[13:52:48.386] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:52:48.386] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:142:0) after 1m0s
[13:53:48.571] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:142:0)
[13:53:48.571] Timer tick, asking Buildbucket for the build status
[13:53:48.702] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:53:48.702] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:143:0) after 1m0s
[13:54:48.732] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:143:0)
[13:54:48.732] Timer tick, asking Buildbucket for the build status
[13:54:49.056] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:54:49.056] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:144:0) after 1m0s
[13:55:49.090] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:144:0)
[13:55:49.090] Timer tick, asking Buildbucket for the build status
[13:55:49.320] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:55:49.320] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:145:0) after 1m0s
[13:56:49.366] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:145:0)
[13:56:49.366] Timer tick, asking Buildbucket for the build status
[13:56:49.894] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:56:49.895] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:146:0) after 1m0s
[13:57:50.013] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:146:0)
[13:57:50.013] Timer tick, asking Buildbucket for the build status
[13:57:50.772] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:57:50.772] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:147:0) after 1m0s
[13:58:50.935] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:147:0)
[13:58:50.935] Timer tick, asking Buildbucket for the build status
[13:58:51.092] Build 8875254937471378096: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:58:51.092] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_64:9040685003328090192:148:0) after 1m0s
[13:59:36.916] Received PubSub notification, asking Buildbucket for the build status
[13:59:37.074] Build 8875254937471378096: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[13:59:37.074] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1594303176432806",
"created_by": "project:nacl",
"created_ts": "1594294336783711",
"failure_reason": "BUILD_FAILURE",
"id": "8875254937471378096",
"parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_64\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"title\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}}",
"project": "nacl",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step('annotated steps') (retcode: 1)\"}, \"properties\": {\"$build/goma\": {\"enable_ats\": true, \"rpc_extra_params\": \"?prod\", \"server_host\": \"goma.chromium.org\"}, \"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"title\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\"}]}, \"bot_id\": \"luci-nacl-toolchain-xenial-2-qshq\", \"branch\": \"refs/heads/master\", \"buildername\": \"linux-pnacl-x86_64-tests-x86_64\", \"buildnumber\": 5111, \"got_revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"mastername\": \"client.nacl.toolchain\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"6725bbc5ec5a64f7becb0a6eeba8395aa2a72972\", \"slavetype\": \"BuilderTester\"}, \"swarming\": {\"bot_dimensions\": {\"caches\": [\"builder_5e264a2b33887b9708d9efa4d555f48b42be33439102d42d27d93f0b7d878c19_v2\", \"git\", \"goma_v2\", \"vpython\"], \"cores\": [\"16\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gcp\": [\"google.com:chromecompute\"], \"gpu\": [\"none\"], \"id\": [\"luci-nacl-toolchain-xenial-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\"]}}, \"ui\": {\"info\": \"Step('annotated steps') (retcode: 1)\"}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1594295389438383",
"status": "COMPLETED",
"status_changed_ts": "1594295390256237",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_64/5111",
"builder:linux-pnacl-x86_64-tests-x86_64",
"buildset:commit/git/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972",
"buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/6725bbc5ec5a64f7becb0a6eeba8395aa2a72972",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9040685003328090192",
"scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_64",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8875254937471378096/+/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:4d4c2a8ebf199210",
"user_agent:luci-scheduler"
],
"updated_ts": "1594303176575561",
"url": "https://ci.chromium.org/b/8875254937471378096",
"utcnow_ts": "1594303177044857"
}
}
[13:59:37.074] Invocation finished in 2h27m25.260132418s with status FAILED