Status: FAILED
Triggered by: -
Duration: 2 hours
Actions:

Definition (rev 1c82d86159c2071b02a7ddf08ffd2ae0bff92186)

buildbucket: <
  server: "cr-buildbucket.appspot.com"
  bucket: "luci.nacl.toolchain"
  builder: "linux-pnacl-x86_64-tests-x86_32"
>

Incoming triggers

Incoming properties

{
  "branch": "refs/heads/master",
  "repository": "https://chromium.googlesource.com/native_client/src/native_client.git",
  "revision": "87b7f311d3a006f29e28a3631cc19f9f30577ac3"
}

Incoming tags

  • buildset:commit/git/87b7f311d3a006f29e28a3631cc19f9f30577ac3
  • buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3
  • gitiles_ref:refs/heads/master

Debug log (UTC)

[15:57:38.777] New invocation is queued and will start shortly
[15:57:40.564] Starting the invocation (attempt 1)
[15:57:40.667] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:57:40.667] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:57:40.667] Buildbucket request:
{
  "bucket": "luci.nacl.toolchain",
  "client_operation_id": "9052083520481665136",
  "parameters_json": "{\"builder_name\":\"linux-pnacl-x86_64-tests-x86_32\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"gitiles\":{\"ref\":\"refs/heads/master\",\"repo\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"},\"id\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@87b7f311d3a006f29e28a3631cc19f9f30577ac3\",\"title\":\"87b7f311d3a006f29e28a3631cc19f9f30577ac3\",\"url\":\"https://chromium.googlesource.com/native_client/src/native_client.git/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/native_client/src/native_client.git\",\"revision\":\"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}}",
  "pubsub_callback": {
    "auth_token": "...",
    "topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  },
  "tags": [
    "builder:linux-pnacl-x86_64-tests-x86_32",
    "scheduler_invocation_id:9052083520481665136",
    "scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
    "user_agent:luci-scheduler",
    "buildset:commit/git/87b7f311d3a006f29e28a3631cc19f9f30577ac3",
    "buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3",
    "gitiles_ref:refs/heads/master"
  ]
}
[15:57:41.635] Buildbucket response:
{
  "build": {
    "bucket": "luci.nacl.toolchain",
    "canary_preference": "PROD",
    "created_by": "project:nacl",
    "created_ts": "1583423860894955",
    "id": "8886653457597749088",
    "parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_32\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"title\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}}",
    "project": "nacl",
    "result_details_json": "{\"properties\": {}}",
    "service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
    "status": "SCHEDULED",
    "status_changed_ts": "1583423861440417",
    "tags": [
      "build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_32/5142",
      "builder:linux-pnacl-x86_64-tests-x86_32",
      "buildset:commit/git/87b7f311d3a006f29e28a3631cc19f9f30577ac3",
      "buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3",
      "gitiles_ref:refs/heads/master",
      "scheduler_invocation_id:9052083520481665136",
      "scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
      "swarming_hostname:chromium-swarm.appspot.com",
      "swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8886653457597749088/+/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": "1583423861440547",
    "url": "https://ci.chromium.org/b/8886653457597749088",
    "utcnow_ts": "1583423861622133"
  }
}
[15:57:41.635] Task URL: https://ci.chromium.org/b/8886653457597749088
[15:57:41.635] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:2:0) after 1m0s
[15:57:53.668] Received PubSub notification, asking Buildbucket for the build status
[15:57:53.737] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:58:41.661] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:2:0)
[15:58:41.661] Timer tick, asking Buildbucket for the build status
[15:58:42.026] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:58:42.026] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:4:0) after 1m0s
[15:59:42.082] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:4:0)
[15:59:42.082] Timer tick, asking Buildbucket for the build status
[15:59:42.199] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:59:42.199] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:5:0) after 1m0s
[16:00:42.323] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:5:0)
[16:00:42.323] Timer tick, asking Buildbucket for the build status
[16:00:42.474] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:00:42.474] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:6:0) after 1m0s
[16:01:42.501] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:6:0)
[16:01:42.501] Timer tick, asking Buildbucket for the build status
[16:01:42.596] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:01:42.596] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:7:0) after 1m0s
[16:02:42.640] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:7:0)
[16:02:42.640] Timer tick, asking Buildbucket for the build status
[16:02:42.897] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:02:42.897] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:8:0) after 1m0s
[16:03:43.062] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:8:0)
[16:03:43.062] Timer tick, asking Buildbucket for the build status
[16:03:43.159] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:03:43.159] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:9:0) after 1m0s
[16:04:43.261] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:9:0)
[16:04:43.261] Timer tick, asking Buildbucket for the build status
[16:04:43.502] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:04:43.502] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:10:0) after 1m0s
[16:05:43.523] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:10:0)
[16:05:43.523] Timer tick, asking Buildbucket for the build status
[16:05:43.731] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:05:43.731] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:11:0) after 1m0s
[16:06:43.949] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:11:0)
[16:06:43.949] Timer tick, asking Buildbucket for the build status
[16:06:44.185] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:06:44.185] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:12:0) after 1m0s
[16:07:44.316] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:12:0)
[16:07:44.316] Timer tick, asking Buildbucket for the build status
[16:07:44.469] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:07:44.469] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:13:0) after 1m0s
[16:08:44.724] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:13:0)
[16:08:44.724] Timer tick, asking Buildbucket for the build status
[16:08:44.943] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:08:44.943] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:14:0) after 1m0s
[16:09:45.006] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:14:0)
[16:09:45.006] Timer tick, asking Buildbucket for the build status
[16:09:45.164] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:09:45.165] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:15:0) after 1m0s
[16:10:45.185] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:15:0)
[16:10:45.185] Timer tick, asking Buildbucket for the build status
[16:10:45.389] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:10:45.389] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:16:0) after 1m0s
[16:11:45.502] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:16:0)
[16:11:45.502] Timer tick, asking Buildbucket for the build status
[16:11:45.684] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:11:45.684] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:17:0) after 1m0s
[16:12:45.742] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:17:0)
[16:12:45.742] Timer tick, asking Buildbucket for the build status
[16:12:45.839] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:12:45.839] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:18:0) after 1m0s
[16:13:45.823] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:18:0)
[16:13:45.823] Timer tick, asking Buildbucket for the build status
[16:13:45.982] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:13:45.982] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:19:0) after 1m0s
[16:14:45.984] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:19:0)
[16:14:45.984] Timer tick, asking Buildbucket for the build status
[16:14:46.210] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:14:46.210] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:20:0) after 1m0s
[16:15:46.250] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:20:0)
[16:15:46.250] Timer tick, asking Buildbucket for the build status
[16:15:46.451] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:15:46.451] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:21:0) after 1m0s
[16:16:46.509] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:21:0)
[16:16:46.509] Timer tick, asking Buildbucket for the build status
[16:16:46.858] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:16:46.858] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:22:0) after 1m0s
[16:17:46.896] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:22:0)
[16:17:46.896] Timer tick, asking Buildbucket for the build status
[16:17:47.042] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:17:47.042] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:23:0) after 1m0s
[16:18:47.129] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:23:0)
[16:18:47.129] Timer tick, asking Buildbucket for the build status
[16:18:47.258] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:18:47.258] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:24:0) after 1m0s
[16:19:47.391] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:24:0)
[16:19:47.391] Timer tick, asking Buildbucket for the build status
[16:19:47.483] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:19:47.483] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:25:0) after 1m0s
[16:20:47.629] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:25:0)
[16:20:47.629] Timer tick, asking Buildbucket for the build status
[16:20:48.264] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:20:48.264] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:26:0) after 1m0s
[16:21:48.388] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:26:0)
[16:21:48.388] Timer tick, asking Buildbucket for the build status
[16:21:48.689] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:21:48.689] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:27:0) after 1m0s
[16:22:48.908] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:27:0)
[16:22:48.908] Timer tick, asking Buildbucket for the build status
[16:22:49.182] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:22:49.182] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:28:0) after 1m0s
[16:23:49.402] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:28:0)
[16:23:49.402] Timer tick, asking Buildbucket for the build status
[16:23:49.587] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:23:49.587] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:29:0) after 1m0s
[16:24:49.711] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:29:0)
[16:24:49.711] Timer tick, asking Buildbucket for the build status
[16:24:49.804] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:24:49.804] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:30:0) after 1m0s
[16:25:49.963] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:30:0)
[16:25:49.963] Timer tick, asking Buildbucket for the build status
[16:25:50.205] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:25:50.206] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:31:0) after 1m0s
[16:26:50.183] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:31:0)
[16:26:50.183] Timer tick, asking Buildbucket for the build status
[16:26:50.353] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:26:50.353] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:32:0) after 1m0s
[16:27:50.399] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:32:0)
[16:27:50.399] Timer tick, asking Buildbucket for the build status
[16:27:50.791] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:27:50.791] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:33:0) after 1m0s
[16:28:50.849] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:33:0)
[16:28:50.849] Timer tick, asking Buildbucket for the build status
[16:28:50.998] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:28:50.998] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:34:0) after 1m0s
[16:29:51.149] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:34:0)
[16:29:51.149] Timer tick, asking Buildbucket for the build status
[16:29:51.687] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:29:51.687] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:35:0) after 1m0s
[16:30:51.722] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:35:0)
[16:30:51.722] Timer tick, asking Buildbucket for the build status
[16:30:51.916] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:30:51.916] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:36:0) after 1m0s
[16:31:51.990] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:36:0)
[16:31:51.990] Timer tick, asking Buildbucket for the build status
[16:31:52.098] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:31:52.098] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:37:0) after 1m0s
[16:32:52.211] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:37:0)
[16:32:52.211] Timer tick, asking Buildbucket for the build status
[16:32:52.357] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:32:52.357] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:38:0) after 1m0s
[16:33:52.456] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:38:0)
[16:33:52.456] Timer tick, asking Buildbucket for the build status
[16:33:52.624] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:33:52.624] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:39:0) after 1m0s
[16:34:52.674] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:39:0)
[16:34:52.674] Timer tick, asking Buildbucket for the build status
[16:34:52.769] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:34:52.769] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:40:0) after 1m0s
[16:35:53.006] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:40:0)
[16:35:53.006] Timer tick, asking Buildbucket for the build status
[16:35:53.116] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:35:53.117] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:41:0) after 1m0s
[16:36:53.197] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:41:0)
[16:36:53.197] Timer tick, asking Buildbucket for the build status
[16:36:53.321] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:36:53.321] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:42:0) after 1m0s
[16:37:53.371] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:42:0)
[16:37:53.371] Timer tick, asking Buildbucket for the build status
[16:37:53.516] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:37:53.516] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:43:0) after 1m0s
[16:38:53.588] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:43:0)
[16:38:53.588] Timer tick, asking Buildbucket for the build status
[16:38:53.737] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:38:53.737] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:44:0) after 1m0s
[16:39:54.038] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:44:0)
[16:39:54.038] Timer tick, asking Buildbucket for the build status
[16:39:54.181] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:39:54.181] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:45:0) after 1m0s
[16:40:54.319] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:45:0)
[16:40:54.319] Timer tick, asking Buildbucket for the build status
[16:40:54.540] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:40:54.540] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:46:0) after 1m0s
[16:41:54.753] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:46:0)
[16:41:54.753] Timer tick, asking Buildbucket for the build status
[16:41:54.859] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:41:54.859] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:47:0) after 1m0s
[16:42:54.906] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:47:0)
[16:42:54.906] Timer tick, asking Buildbucket for the build status
[16:42:55.008] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:42:55.009] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:48:0) after 1m0s
[16:43:55.149] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:48:0)
[16:43:55.149] Timer tick, asking Buildbucket for the build status
[16:43:55.239] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:43:55.240] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:49:0) after 1m0s
[16:44:55.444] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:49:0)
[16:44:55.444] Timer tick, asking Buildbucket for the build status
[16:44:55.695] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:44:55.695] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:50:0) after 1m0s
[16:45:55.822] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:50:0)
[16:45:55.822] Timer tick, asking Buildbucket for the build status
[16:45:55.952] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:45:55.952] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:51:0) after 1m0s
[16:46:55.970] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:51:0)
[16:46:55.970] Timer tick, asking Buildbucket for the build status
[16:46:56.067] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:46:56.067] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:52:0) after 1m0s
[16:47:56.131] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:52:0)
[16:47:56.131] Timer tick, asking Buildbucket for the build status
[16:47:56.265] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:47:56.265] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:53:0) after 1m0s
[16:48:56.392] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:53:0)
[16:48:56.392] Timer tick, asking Buildbucket for the build status
[16:48:56.763] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:48:56.763] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:54:0) after 1m0s
[16:49:56.965] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:54:0)
[16:49:56.965] Timer tick, asking Buildbucket for the build status
[16:49:57.145] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:49:57.145] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:55:0) after 1m0s
[16:50:57.193] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:55:0)
[16:50:57.193] Timer tick, asking Buildbucket for the build status
[16:50:57.277] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:50:57.277] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:56:0) after 1m0s
[16:51:57.334] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:56:0)
[16:51:57.334] Timer tick, asking Buildbucket for the build status
[16:51:57.889] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:51:57.889] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:57:0) after 1m0s
[16:52:57.944] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:57:0)
[16:52:57.944] Timer tick, asking Buildbucket for the build status
[16:52:58.045] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:52:58.045] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:58:0) after 1m0s
[16:53:58.102] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:58:0)
[16:53:58.102] Timer tick, asking Buildbucket for the build status
[16:53:58.187] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:53:58.187] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:59:0) after 1m0s
[16:54:58.427] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:59:0)
[16:54:58.427] Timer tick, asking Buildbucket for the build status
[16:55:00.249] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:55:00.249] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:60:0) after 1m0s
[16:56:00.303] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:60:0)
[16:56:00.303] Timer tick, asking Buildbucket for the build status
[16:56:00.593] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:56:00.596] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:61:0) after 1m0s
[16:57:00.674] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:61:0)
[16:57:00.674] Timer tick, asking Buildbucket for the build status
[16:57:01.062] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:57:01.062] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:62:0) after 1m0s
[16:58:01.102] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:62:0)
[16:58:01.102] Timer tick, asking Buildbucket for the build status
[16:58:01.456] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:58:01.456] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:63:0) after 1m0s
[16:59:01.465] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:63:0)
[16:59:01.465] Timer tick, asking Buildbucket for the build status
[16:59:01.724] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:59:01.724] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:64:0) after 1m0s
[17:00:01.762] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:64:0)
[17:00:01.762] Timer tick, asking Buildbucket for the build status
[17:00:01.847] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:00:01.847] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:65:0) after 1m0s
[17:01:01.856] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:65:0)
[17:01:01.856] Timer tick, asking Buildbucket for the build status
[17:01:01.954] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:01:01.954] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:66:0) after 1m0s
[17:02:02.006] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:66:0)
[17:02:02.006] Timer tick, asking Buildbucket for the build status
[17:02:02.385] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:02:02.385] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:67:0) after 1m0s
[17:03:02.439] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:67:0)
[17:03:02.439] Timer tick, asking Buildbucket for the build status
[17:03:02.793] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:03:02.793] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:68:0) after 1m0s
[17:04:02.859] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:68:0)
[17:04:02.859] Timer tick, asking Buildbucket for the build status
[17:04:02.956] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:04:02.956] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:69:0) after 1m0s
[17:05:03.015] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:69:0)
[17:05:03.015] Timer tick, asking Buildbucket for the build status
[17:05:03.116] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:05:03.116] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:70:0) after 1m0s
[17:06:03.089] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:70:0)
[17:06:03.089] Timer tick, asking Buildbucket for the build status
[17:06:03.324] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:06:03.324] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:71:0) after 1m0s
[17:07:03.539] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:71:0)
[17:07:03.539] Timer tick, asking Buildbucket for the build status
[17:07:03.649] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:07:03.649] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:72:0) after 1m0s
[17:08:03.996] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:72:0)
[17:08:03.996] Timer tick, asking Buildbucket for the build status
[17:08:04.517] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:08:04.517] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:73:0) after 1m0s
[17:09:04.700] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:73:0)
[17:09:04.700] Timer tick, asking Buildbucket for the build status
[17:09:04.896] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:09:04.896] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:74:0) after 1m0s
[17:10:04.924] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:74:0)
[17:10:04.924] Timer tick, asking Buildbucket for the build status
[17:10:05.108] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:10:05.108] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:75:0) after 1m0s
[17:11:05.249] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:75:0)
[17:11:05.249] Timer tick, asking Buildbucket for the build status
[17:11:05.424] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:11:05.424] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:76:0) after 1m0s
[17:12:05.553] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:76:0)
[17:12:05.553] Timer tick, asking Buildbucket for the build status
[17:12:05.669] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:12:05.669] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:77:0) after 1m0s
[17:13:05.725] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:77:0)
[17:13:05.725] Timer tick, asking Buildbucket for the build status
[17:13:05.959] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:13:05.959] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:78:0) after 1m0s
[17:14:05.987] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:78:0)
[17:14:05.987] Timer tick, asking Buildbucket for the build status
[17:14:06.366] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:14:06.366] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:79:0) after 1m0s
[17:15:06.544] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:79:0)
[17:15:06.544] Timer tick, asking Buildbucket for the build status
[17:15:06.936] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:15:06.936] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:80:0) after 1m0s
[17:16:07.097] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:80:0)
[17:16:07.097] Timer tick, asking Buildbucket for the build status
[17:16:07.195] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:16:07.195] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:81:0) after 1m0s
[17:17:07.402] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:81:0)
[17:17:07.402] Timer tick, asking Buildbucket for the build status
[17:17:07.576] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:17:07.576] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:82:0) after 1m0s
[17:18:07.688] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:82:0)
[17:18:07.688] Timer tick, asking Buildbucket for the build status
[17:18:07.811] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:18:07.811] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:83:0) after 1m0s
[17:19:07.938] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:83:0)
[17:19:07.938] Timer tick, asking Buildbucket for the build status
[17:19:08.068] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:19:08.068] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:84:0) after 1m0s
[17:20:08.140] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:84:0)
[17:20:08.140] Timer tick, asking Buildbucket for the build status
[17:20:08.253] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:20:08.253] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:85:0) after 1m0s
[17:21:08.319] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:85:0)
[17:21:08.319] Timer tick, asking Buildbucket for the build status
[17:21:08.444] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:21:08.444] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:86:0) after 1m0s
[17:22:08.626] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:86:0)
[17:22:08.626] Timer tick, asking Buildbucket for the build status
[17:22:08.711] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:22:08.711] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:87:0) after 1m0s
[17:23:08.867] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:87:0)
[17:23:08.867] Timer tick, asking Buildbucket for the build status
[17:23:08.992] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:23:08.992] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:88:0) after 1m0s
[17:24:09.201] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:88:0)
[17:24:09.201] Timer tick, asking Buildbucket for the build status
[17:24:09.563] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:24:09.563] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:89:0) after 1m0s
[17:25:09.653] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:89:0)
[17:25:09.653] Timer tick, asking Buildbucket for the build status
[17:25:09.770] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:25:09.770] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:90:0) after 1m0s
[17:26:09.809] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:90:0)
[17:26:09.809] Timer tick, asking Buildbucket for the build status
[17:26:10.255] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:26:10.255] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:91:0) after 1m0s
[17:27:10.359] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:91:0)
[17:27:10.359] Timer tick, asking Buildbucket for the build status
[17:27:10.548] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:27:10.548] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:92:0) after 1m0s
[17:28:10.716] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:92:0)
[17:28:10.716] Timer tick, asking Buildbucket for the build status
[17:28:10.843] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:28:10.843] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:93:0) after 1m0s
[17:29:10.898] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:93:0)
[17:29:10.898] Timer tick, asking Buildbucket for the build status
[17:29:11.243] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:29:11.243] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:94:0) after 1m0s
[17:30:11.313] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:94:0)
[17:30:11.313] Timer tick, asking Buildbucket for the build status
[17:30:11.436] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:30:11.436] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:95:0) after 1m0s
[17:31:11.517] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:95:0)
[17:31:11.518] Timer tick, asking Buildbucket for the build status
[17:31:11.629] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:31:11.629] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:96:0) after 1m0s
[17:32:11.713] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:96:0)
[17:32:11.713] Timer tick, asking Buildbucket for the build status
[17:32:11.897] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:32:11.897] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:97:0) after 1m0s
[17:33:11.965] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:97:0)
[17:33:11.965] Timer tick, asking Buildbucket for the build status
[17:33:12.463] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:33:12.463] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:98:0) after 1m0s
[17:34:12.591] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:98:0)
[17:34:12.591] Timer tick, asking Buildbucket for the build status
[17:34:12.933] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:34:12.933] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:99:0) after 1m0s
[17:35:13.028] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:99:0)
[17:35:13.028] Timer tick, asking Buildbucket for the build status
[17:35:13.202] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:35:13.202] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:100:0) after 1m0s
[17:36:13.224] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:100:0)
[17:36:13.225] Timer tick, asking Buildbucket for the build status
[17:36:13.335] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:36:13.335] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:101:0) after 1m0s
[17:37:13.574] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:101:0)
[17:37:13.574] Timer tick, asking Buildbucket for the build status
[17:37:13.679] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:37:13.679] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:102:0) after 1m0s
[17:38:13.817] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:102:0)
[17:38:13.817] Timer tick, asking Buildbucket for the build status
[17:38:13.930] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:38:13.930] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:103:0) after 1m0s
[17:39:14.143] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:103:0)
[17:39:14.143] Timer tick, asking Buildbucket for the build status
[17:39:14.219] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:39:14.219] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:104:0) after 1m0s
[17:40:14.330] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:104:0)
[17:40:14.330] Timer tick, asking Buildbucket for the build status
[17:40:14.418] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:40:14.418] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:105:0) after 1m0s
[17:41:14.509] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:105:0)
[17:41:14.509] Timer tick, asking Buildbucket for the build status
[17:41:14.713] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:41:14.713] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:106:0) after 1m0s
[17:42:14.869] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:106:0)
[17:42:14.869] Timer tick, asking Buildbucket for the build status
[17:42:14.969] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:42:14.969] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:107:0) after 1m0s
[17:43:14.994] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:107:0)
[17:43:14.994] Timer tick, asking Buildbucket for the build status
[17:43:15.145] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:43:15.145] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:108:0) after 1m0s
[17:44:15.211] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:108:0)
[17:44:15.211] Timer tick, asking Buildbucket for the build status
[17:44:15.372] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:44:15.372] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:109:0) after 1m0s
[17:45:15.434] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:109:0)
[17:45:15.434] Timer tick, asking Buildbucket for the build status
[17:45:15.545] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:45:15.545] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:110:0) after 1m0s
[17:46:15.618] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:110:0)
[17:46:15.618] Timer tick, asking Buildbucket for the build status
[17:46:15.743] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:46:15.743] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:111:0) after 1m0s
[17:47:15.856] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:111:0)
[17:47:15.856] Timer tick, asking Buildbucket for the build status
[17:47:15.966] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:47:15.966] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:112:0) after 1m0s
[17:48:16.142] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:112:0)
[17:48:16.142] Timer tick, asking Buildbucket for the build status
[17:48:16.468] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:48:16.468] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:113:0) after 1m0s
[17:49:16.509] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:113:0)
[17:49:16.509] Timer tick, asking Buildbucket for the build status
[17:49:16.655] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:49:16.655] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:114:0) after 1m0s
[17:50:16.712] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:114:0)
[17:50:16.712] Timer tick, asking Buildbucket for the build status
[17:50:16.816] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:50:16.816] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:115:0) after 1m0s
[17:51:16.908] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:115:0)
[17:51:16.908] Timer tick, asking Buildbucket for the build status
[17:51:16.991] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:51:16.991] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:116:0) after 1m0s
[17:52:16.994] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:116:0)
[17:52:16.994] Timer tick, asking Buildbucket for the build status
[17:52:17.223] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:52:17.223] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:117:0) after 1m0s
[17:53:17.352] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:117:0)
[17:53:17.352] Timer tick, asking Buildbucket for the build status
[17:53:17.507] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:53:17.507] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:118:0) after 1m0s
[17:54:17.603] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:118:0)
[17:54:17.603] Timer tick, asking Buildbucket for the build status
[17:54:17.776] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:54:17.776] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:119:0) after 1m0s
[17:55:17.887] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:119:0)
[17:55:17.889] Timer tick, asking Buildbucket for the build status
[17:55:18.040] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:55:18.040] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:120:0) after 1m0s
[17:56:18.062] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:120:0)
[17:56:18.062] Timer tick, asking Buildbucket for the build status
[17:56:18.166] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:56:18.166] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:121:0) after 1m0s
[17:57:18.209] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:121:0)
[17:57:18.210] Timer tick, asking Buildbucket for the build status
[17:57:18.552] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:57:18.552] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:122:0) after 1m0s
[17:58:18.655] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:122:0)
[17:58:18.655] Timer tick, asking Buildbucket for the build status
[17:58:18.777] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:58:18.777] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:123:0) after 1m0s
[17:59:18.947] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:123:0)
[17:59:18.948] Timer tick, asking Buildbucket for the build status
[17:59:19.262] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:59:19.262] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:124:0) after 1m0s
[18:00:19.324] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:124:0)
[18:00:19.324] Timer tick, asking Buildbucket for the build status
[18:00:19.527] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:00:19.527] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:125:0) after 1m0s
[18:01:19.683] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:125:0)
[18:01:19.683] Timer tick, asking Buildbucket for the build status
[18:01:19.844] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:01:19.844] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:126:0) after 1m0s
[18:02:19.920] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:126:0)
[18:02:19.920] Timer tick, asking Buildbucket for the build status
[18:02:20.194] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:02:20.194] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:127:0) after 1m0s
[18:03:20.340] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:127:0)
[18:03:20.340] Timer tick, asking Buildbucket for the build status
[18:03:20.541] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:03:20.541] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:128:0) after 1m0s
[18:04:20.616] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:128:0)
[18:04:20.617] Timer tick, asking Buildbucket for the build status
[18:04:20.717] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:04:20.717] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:129:0) after 1m0s
[18:05:20.842] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:129:0)
[18:05:20.842] Timer tick, asking Buildbucket for the build status
[18:05:20.995] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:05:20.995] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:130:0) after 1m0s
[18:06:21.399] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:130:0)
[18:06:21.399] Timer tick, asking Buildbucket for the build status
[18:06:21.511] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:06:21.511] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:131:0) after 1m0s
[18:07:21.614] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:131:0)
[18:07:21.614] Timer tick, asking Buildbucket for the build status
[18:07:21.709] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:07:21.709] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:132:0) after 1m0s
[18:08:21.740] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:132:0)
[18:08:21.740] Timer tick, asking Buildbucket for the build status
[18:08:22.138] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:08:22.138] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:133:0) after 1m0s
[18:09:22.189] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:133:0)
[18:09:22.189] Timer tick, asking Buildbucket for the build status
[18:09:22.331] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:09:22.331] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:134:0) after 1m0s
[18:10:22.513] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:134:0)
[18:10:22.513] Timer tick, asking Buildbucket for the build status
[18:10:22.900] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:10:22.900] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:135:0) after 1m0s
[18:11:23.084] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:135:0)
[18:11:23.084] Timer tick, asking Buildbucket for the build status
[18:11:23.238] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:11:23.238] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:136:0) after 1m0s
[18:12:23.294] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:136:0)
[18:12:23.294] Timer tick, asking Buildbucket for the build status
[18:12:23.425] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:12:23.425] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:137:0) after 1m0s
[18:13:23.506] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:137:0)
[18:13:23.506] Timer tick, asking Buildbucket for the build status
[18:13:23.978] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:13:23.978] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:138:0) after 1m0s
[18:14:23.978] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:138:0)
[18:14:23.978] Timer tick, asking Buildbucket for the build status
[18:14:24.115] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:14:24.115] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:139:0) after 1m0s
[18:15:24.153] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:139:0)
[18:15:24.153] Timer tick, asking Buildbucket for the build status
[18:15:24.351] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:15:24.351] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:140:0) after 1m0s
[18:16:24.520] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:140:0)
[18:16:24.520] Timer tick, asking Buildbucket for the build status
[18:16:24.837] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:16:24.837] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:141:0) after 1m0s
[18:17:24.920] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:141:0)
[18:17:24.920] Timer tick, asking Buildbucket for the build status
[18:17:25.022] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:17:25.022] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:142:0) after 1m0s
[18:18:25.121] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:142:0)
[18:18:25.121] Timer tick, asking Buildbucket for the build status
[18:18:25.319] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:18:25.319] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:143:0) after 1m0s
[18:19:25.522] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:143:0)
[18:19:25.522] Timer tick, asking Buildbucket for the build status
[18:19:25.707] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:19:25.707] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:144:0) after 1m0s
[18:20:25.726] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:144:0)
[18:20:25.726] Timer tick, asking Buildbucket for the build status
[18:20:25.836] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:20:25.836] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:145:0) after 1m0s
[18:21:25.911] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:145:0)
[18:21:25.911] Timer tick, asking Buildbucket for the build status
[18:21:26.123] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:21:26.123] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:146:0) after 1m0s
[18:22:26.220] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:146:0)
[18:22:26.220] Timer tick, asking Buildbucket for the build status
[18:22:26.310] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:22:26.310] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:147:0) after 1m0s
[18:23:26.484] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:147:0)
[18:23:26.484] Timer tick, asking Buildbucket for the build status
[18:23:26.588] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:23:26.588] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:148:0) after 1m0s
[18:24:26.668] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:148:0)
[18:24:26.668] Timer tick, asking Buildbucket for the build status
[18:24:27.211] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:24:27.211] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:149:0) after 1m0s
[18:25:27.311] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:149:0)
[18:25:27.311] Timer tick, asking Buildbucket for the build status
[18:25:27.431] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:25:27.431] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:150:0) after 1m0s
[18:26:27.616] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:150:0)
[18:26:27.616] Timer tick, asking Buildbucket for the build status
[18:26:27.762] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:26:27.762] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:151:0) after 1m0s
[18:27:27.790] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:151:0)
[18:27:27.790] Timer tick, asking Buildbucket for the build status
[18:27:27.914] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:27:27.914] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:152:0) after 1m0s
[18:28:28.009] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:152:0)
[18:28:28.009] Timer tick, asking Buildbucket for the build status
[18:28:28.267] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:28:28.267] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:153:0) after 1m0s
[18:29:28.417] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:153:0)
[18:29:28.417] Timer tick, asking Buildbucket for the build status
[18:29:28.596] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:29:28.596] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:154:0) after 1m0s
[18:30:28.695] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:154:0)
[18:30:28.695] Timer tick, asking Buildbucket for the build status
[18:30:28.830] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:30:28.830] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:155:0) after 1m0s
[18:31:29.127] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:155:0)
[18:31:29.127] Timer tick, asking Buildbucket for the build status
[18:31:29.271] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:31:29.271] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:156:0) after 1m0s
[18:32:29.428] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:156:0)
[18:32:29.428] Timer tick, asking Buildbucket for the build status
[18:32:29.520] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:32:29.520] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:157:0) after 1m0s
[18:33:30.177] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:157:0)
[18:33:30.177] Timer tick, asking Buildbucket for the build status
[18:33:30.285] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:33:30.285] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:158:0) after 1m0s
[18:34:30.380] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:158:0)
[18:34:30.380] Timer tick, asking Buildbucket for the build status
[18:34:30.466] Build 8886653457597749088: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:34:30.467] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64-tests-x86_32:9052083520481665136:159:0) after 1m0s
[18:34:32.578] Received PubSub notification, asking Buildbucket for the build status
[18:34:32.709] Build 8886653457597749088: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[18:34:32.709] Buildbucket build:
{
  "build": {
    "bucket": "luci.nacl.toolchain",
    "canary_preference": "PROD",
    "completed_ts": "1583433272186310",
    "created_by": "project:nacl",
    "created_ts": "1583423860894955",
    "failure_reason": "BUILD_FAILURE",
    "id": "8886653457597749088",
    "parameters_json": "{\"builder_name\": \"linux-pnacl-x86_64-tests-x86_32\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"title\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}}",
    "project": "nacl",
    "result": "FAILURE",
    "result_details_json": "{\"error\": {\"message\": \"Step('annotated steps') (retcode: 1)\"}, \"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\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}, \"id\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/refs/heads/master@87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"title\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"url\": \"https://chromium.googlesource.com/native_client/src/native_client.git/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3\"}]}, \"bot_id\": \"luci-nacl-toolchain-xenial-1-p0cw\", \"branch\": \"refs/heads/master\", \"buildername\": \"linux-pnacl-x86_64-tests-x86_32\", \"buildnumber\": 5142, \"got_revision\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"mastername\": \"client.nacl.toolchain\", \"path_config\": \"generic\", \"recipe\": \"nacl\", \"repository\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"87b7f311d3a006f29e28a3631cc19f9f30577ac3\", \"slavetype\": \"BuilderTester\"}, \"swarming\": {\"bot_dimensions\": {\"cores\": [\"16\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gcp\": [\"google.com:chromecompute\"], \"gpu\": [\"none\"], \"id\": [\"luci-nacl-toolchain-xenial-1-p0cw\"], \"image\": [\"chrome-xenial-20030100-2bddf837f90\"], \"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\": [\"4851-268d16b\"], \"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": "1583423872627086",
    "status": "COMPLETED",
    "status_changed_ts": "1583423873149588",
    "tags": [
      "build_address:luci.nacl.toolchain/linux-pnacl-x86_64-tests-x86_32/5142",
      "builder:linux-pnacl-x86_64-tests-x86_32",
      "buildset:commit/git/87b7f311d3a006f29e28a3631cc19f9f30577ac3",
      "buildset:commit/gitiles/chromium.googlesource.com/native_client/src/native_client/+/87b7f311d3a006f29e28a3631cc19f9f30577ac3",
      "gitiles_ref:refs/heads/master",
      "scheduler_invocation_id:9052083520481665136",
      "scheduler_job_id:nacl/linux-pnacl-x86_64-tests-x86_32",
      "swarming_hostname:chromium-swarm.appspot.com",
      "swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8886653457597749088/+/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:4ac43c3e2a8f8610",
      "user_agent:luci-scheduler"
    ],
    "updated_ts": "1583433272249529",
    "url": "https://ci.chromium.org/b/8886653457597749088",
    "utcnow_ts": "1583433272697005"
  }
}
[18:34:32.709] Invocation finished in 2h36m53.949166434s with status FAILED