[11:32:08.264] New invocation is queued and will start shortly
[11:32:12.311] Starting the invocation (attempt 1)
[11:32:12.354] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[11:32:12.355] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[11:32:12.355] Buildbucket request:
{
"bucket": "luci.nacl.toolchain",
"client_operation_id": "9040685007069867264",
"parameters_json": "{\"builder_name\":\"linux-pnacl-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",
"scheduler_invocation_id:9040685007069867264",
"scheduler_job_id:nacl/linux-pnacl-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:13.819] Buildbucket response:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"created_by": "project:nacl",
"created_ts": "1594294332480776",
"id": "8875254941984067856",
"parameters_json": "{\"builder_name\": \"linux-pnacl-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": "1594294333520794",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64/7073",
"builder:linux-pnacl-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:9040685007069867264",
"scheduler_job_id:nacl/linux-pnacl-x86_64",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8875254941984067856/+/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": "1594294333521821",
"url": "https://ci.chromium.org/b/8875254941984067856",
"utcnow_ts": "1594294333804020"
}
}
[11:32:13.819] Task URL: https://ci.chromium.org/b/8875254941984067856
[11:32:13.819] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:2:0) after 1m0s
[11:32:31.457] Received PubSub notification, asking Buildbucket for the build status
[11:32:31.573] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:33:13.922] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:2:0)
[11:33:13.922] Timer tick, asking Buildbucket for the build status
[11:33:14.019] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:33:14.019] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:4:0) after 1m0s
[11:34:14.043] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:4:0)
[11:34:14.043] Timer tick, asking Buildbucket for the build status
[11:34:14.224] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:34:14.224] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:5:0) after 1m0s
[11:35:14.285] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:5:0)
[11:35:14.285] Timer tick, asking Buildbucket for the build status
[11:35:14.463] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:35:14.463] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:6:0) after 1m0s
[11:36:14.484] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:6:0)
[11:36:14.484] Timer tick, asking Buildbucket for the build status
[11:36:14.958] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:36:14.958] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:7:0) after 1m0s
[11:37:14.992] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:7:0)
[11:37:14.992] Timer tick, asking Buildbucket for the build status
[11:37:15.129] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:37:15.129] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:8:0) after 1m0s
[11:38:15.125] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:8:0)
[11:38:15.125] Timer tick, asking Buildbucket for the build status
[11:38:16.268] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:38:16.268] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:9:0) after 1m0s
[11:39:16.264] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:9:0)
[11:39:16.264] Timer tick, asking Buildbucket for the build status
[11:39:16.983] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:39:16.983] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:10:0) after 1m0s
[11:40:17.388] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:10:0)
[11:40:17.388] Timer tick, asking Buildbucket for the build status
[11:40:18.320] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:40:18.320] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:11:0) after 1m0s
[11:41:18.516] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:11:0)
[11:41:18.516] Timer tick, asking Buildbucket for the build status
[11:41:18.622] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:41:18.622] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:12:0) after 1m0s
[11:42:18.706] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:12:0)
[11:42:18.706] Timer tick, asking Buildbucket for the build status
[11:42:18.854] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:42:18.854] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:13:0) after 1m0s
[11:43:18.925] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:13:0)
[11:43:18.925] Timer tick, asking Buildbucket for the build status
[11:43:19.076] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:43:19.076] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:14:0) after 1m0s
[11:44:19.256] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:14:0)
[11:44:19.256] Timer tick, asking Buildbucket for the build status
[11:44:19.608] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:44:19.608] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:15:0) after 1m0s
[11:45:20.109] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:15:0)
[11:45:20.109] Timer tick, asking Buildbucket for the build status
[11:45:20.271] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:45:20.271] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:16:0) after 1m0s
[11:46:20.375] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:16:0)
[11:46:20.375] Timer tick, asking Buildbucket for the build status
[11:46:20.537] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:46:20.537] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:17:0) after 1m0s
[11:47:20.684] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:17:0)
[11:47:20.684] Timer tick, asking Buildbucket for the build status
[11:47:20.913] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:47:20.913] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:18:0) after 1m0s
[11:48:20.923] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:18:0)
[11:48:20.923] Timer tick, asking Buildbucket for the build status
[11:48:21.097] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:48:21.097] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:19:0) after 1m0s
[11:49:21.211] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:19:0)
[11:49:21.211] Timer tick, asking Buildbucket for the build status
[11:49:21.453] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:49:21.453] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:20:0) after 1m0s
[11:50:21.867] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:20:0)
[11:50:21.867] Timer tick, asking Buildbucket for the build status
[11:50:21.989] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:50:21.989] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:21:0) after 1m0s
[11:51:22.150] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:21:0)
[11:51:22.150] Timer tick, asking Buildbucket for the build status
[11:51:22.304] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:51:22.304] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:22:0) after 1m0s
[11:52:22.418] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:22:0)
[11:52:22.418] Timer tick, asking Buildbucket for the build status
[11:52:22.551] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:52:22.551] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:23:0) after 1m0s
[11:53:22.636] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:23:0)
[11:53:22.636] Timer tick, asking Buildbucket for the build status
[11:53:22.804] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:53:22.804] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:24:0) after 1m0s
[11:54:22.906] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:24:0)
[11:54:22.906] Timer tick, asking Buildbucket for the build status
[11:54:23.235] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:54:23.235] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:25:0) after 1m0s
[11:55:23.277] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:25:0)
[11:55:23.277] Timer tick, asking Buildbucket for the build status
[11:55:23.399] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:55:23.399] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:26:0) after 1m0s
[11:56:23.520] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:26:0)
[11:56:23.520] Timer tick, asking Buildbucket for the build status
[11:56:23.606] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:56:23.606] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:27:0) after 1m0s
[11:57:23.624] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:27:0)
[11:57:23.624] Timer tick, asking Buildbucket for the build status
[11:57:24.068] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:57:24.068] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:28:0) after 1m0s
[11:58:24.267] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:28:0)
[11:58:24.267] Timer tick, asking Buildbucket for the build status
[11:58:24.424] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:58:24.424] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:29:0) after 1m0s
[11:59:24.468] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:29:0)
[11:59:24.468] Timer tick, asking Buildbucket for the build status
[11:59:24.601] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[11:59:24.601] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:30:0) after 1m0s
[12:00:24.784] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:30:0)
[12:00:24.784] Timer tick, asking Buildbucket for the build status
[12:00:25.093] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:00:25.093] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:31:0) after 1m0s
[12:01:25.219] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:31:0)
[12:01:25.219] Timer tick, asking Buildbucket for the build status
[12:01:25.700] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:01:25.700] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:32:0) after 1m0s
[12:02:25.772] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:32:0)
[12:02:25.772] Timer tick, asking Buildbucket for the build status
[12:02:26.194] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:02:26.194] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:33:0) after 1m0s
[12:03:26.312] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:33:0)
[12:03:26.312] Timer tick, asking Buildbucket for the build status
[12:03:26.422] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:03:26.422] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:34:0) after 1m0s
[12:04:26.496] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:34:0)
[12:04:26.496] Timer tick, asking Buildbucket for the build status
[12:04:26.688] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:04:26.688] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:35:0) after 1m0s
[12:05:26.704] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:35:0)
[12:05:26.704] Timer tick, asking Buildbucket for the build status
[12:05:26.859] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:05:26.859] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:36:0) after 1m0s
[12:06:26.890] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:36:0)
[12:06:26.890] Timer tick, asking Buildbucket for the build status
[12:06:27.166] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:06:27.166] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:37:0) after 1m0s
[12:07:27.215] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:37:0)
[12:07:27.215] Timer tick, asking Buildbucket for the build status
[12:07:27.655] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:07:27.655] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:38:0) after 1m0s
[12:08:27.706] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:38:0)
[12:08:27.706] Timer tick, asking Buildbucket for the build status
[12:08:27.831] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:08:27.831] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:39:0) after 1m0s
[12:09:27.919] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:39:0)
[12:09:27.919] Timer tick, asking Buildbucket for the build status
[12:09:28.329] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:09:28.329] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:40:0) after 1m0s
[12:10:28.541] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:40:0)
[12:10:28.541] Timer tick, asking Buildbucket for the build status
[12:10:28.748] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:10:28.748] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:41:0) after 1m0s
[12:11:28.889] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:41:0)
[12:11:28.889] Timer tick, asking Buildbucket for the build status
[12:11:29.063] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:11:29.063] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:42:0) after 1m0s
[12:12:29.153] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:42:0)
[12:12:29.153] Timer tick, asking Buildbucket for the build status
[12:12:31.052] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:12:31.052] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:43:0) after 1m0s
[12:13:31.300] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:43:0)
[12:13:31.300] Timer tick, asking Buildbucket for the build status
[12:13:31.492] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:13:31.492] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:44:0) after 1m0s
[12:14:31.706] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:44:0)
[12:14:31.706] Timer tick, asking Buildbucket for the build status
[12:14:31.832] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:14:31.832] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:45:0) after 1m0s
[12:15:31.950] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:45:0)
[12:15:31.950] Timer tick, asking Buildbucket for the build status
[12:15:32.127] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:15:32.127] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:46:0) after 1m0s
[12:16:32.199] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:46:0)
[12:16:32.200] Timer tick, asking Buildbucket for the build status
[12:16:32.379] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:16:32.379] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:47:0) after 1m0s
[12:17:32.547] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:47:0)
[12:17:32.547] Timer tick, asking Buildbucket for the build status
[12:17:32.914] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:17:32.914] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:48:0) after 1m0s
[12:18:32.944] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:48:0)
[12:18:32.944] Timer tick, asking Buildbucket for the build status
[12:18:33.246] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:18:33.246] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:49:0) after 1m0s
[12:19:33.320] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:49:0)
[12:19:33.320] Timer tick, asking Buildbucket for the build status
[12:19:33.978] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:19:33.978] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:50:0) after 1m0s
[12:20:34.080] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:50:0)
[12:20:34.080] Timer tick, asking Buildbucket for the build status
[12:20:34.224] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:20:34.224] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:51:0) after 1m0s
[12:21:34.266] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:51:0)
[12:21:34.266] Timer tick, asking Buildbucket for the build status
[12:21:34.383] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:21:34.383] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:52:0) after 1m0s
[12:22:34.481] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:52:0)
[12:22:34.481] Timer tick, asking Buildbucket for the build status
[12:22:35.712] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:22:35.712] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:53:0) after 1m0s
[12:23:35.748] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:53:0)
[12:23:35.748] Timer tick, asking Buildbucket for the build status
[12:23:35.923] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:23:35.923] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:54:0) after 1m0s
[12:24:37.156] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:54:0)
[12:24:37.157] Timer tick, asking Buildbucket for the build status
[12:24:37.813] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:24:37.813] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:55:0) after 1m0s
[12:25:38.062] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:55:0)
[12:25:38.062] Timer tick, asking Buildbucket for the build status
[12:25:38.359] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:25:38.359] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:56:0) after 1m0s
[12:26:40.646] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:56:0)
[12:26:40.646] Timer tick, asking Buildbucket for the build status
[12:26:41.061] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:26:41.061] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:57:0) after 1m0s
[12:27:41.214] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:57:0)
[12:27:41.215] Timer tick, asking Buildbucket for the build status
[12:27:41.345] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:27:41.345] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:58:0) after 1m0s
[12:28:41.643] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:58:0)
[12:28:41.643] Timer tick, asking Buildbucket for the build status
[12:28:41.925] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:28:41.925] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:59:0) after 1m0s
[12:29:42.150] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:59:0)
[12:29:42.150] Timer tick, asking Buildbucket for the build status
[12:29:42.306] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:29:42.306] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:60:0) after 1m0s
[12:30:42.825] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:60:0)
[12:30:42.825] Timer tick, asking Buildbucket for the build status
[12:30:43.068] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:30:43.068] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:61:0) after 1m0s
[12:31:43.227] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:61:0)
[12:31:43.227] Timer tick, asking Buildbucket for the build status
[12:31:43.365] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:31:43.365] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:62:0) after 1m0s
[12:32:43.417] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:62:0)
[12:32:43.417] Timer tick, asking Buildbucket for the build status
[12:32:43.654] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:32:43.654] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:63:0) after 1m0s
[12:33:43.642] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:63:0)
[12:33:43.642] Timer tick, asking Buildbucket for the build status
[12:33:43.776] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:33:43.776] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:64:0) after 1m0s
[12:34:43.911] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:64:0)
[12:34:43.911] Timer tick, asking Buildbucket for the build status
[12:34:44.082] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:34:44.082] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:65:0) after 1m0s
[12:35:44.208] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:65:0)
[12:35:44.208] Timer tick, asking Buildbucket for the build status
[12:35:44.421] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:35:44.422] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:66:0) after 1m0s
[12:36:45.180] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:66:0)
[12:36:45.180] Timer tick, asking Buildbucket for the build status
[12:36:45.365] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:36:45.365] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:67:0) after 1m0s
[12:37:45.496] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:67:0)
[12:37:45.496] Timer tick, asking Buildbucket for the build status
[12:37:50.400] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:37:50.400] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:68:0) after 1m0s
[12:38:51.035] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:68:0)
[12:38:51.035] Timer tick, asking Buildbucket for the build status
[12:38:51.234] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:38:51.234] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:69:0) after 1m0s
[12:39:51.261] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:69:0)
[12:39:51.261] Timer tick, asking Buildbucket for the build status
[12:39:51.588] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:39:51.588] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:70:0) after 1m0s
[12:40:51.653] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:70:0)
[12:40:51.653] Timer tick, asking Buildbucket for the build status
[12:40:51.944] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:40:51.944] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:71:0) after 1m0s
[12:41:51.943] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:71:0)
[12:41:51.943] Timer tick, asking Buildbucket for the build status
[12:41:52.337] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:41:52.337] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:72:0) after 1m0s
[12:42:52.396] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:72:0)
[12:42:52.396] Timer tick, asking Buildbucket for the build status
[12:42:55.853] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:42:55.853] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:73:0) after 1m0s
[12:43:55.923] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:73:0)
[12:43:55.923] Timer tick, asking Buildbucket for the build status
[12:43:56.098] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:43:56.098] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:74:0) after 1m0s
[12:44:56.123] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:74:0)
[12:44:56.123] Timer tick, asking Buildbucket for the build status
[12:44:56.372] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:44:56.372] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:75:0) after 1m0s
[12:45:56.367] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:75:0)
[12:45:56.367] Timer tick, asking Buildbucket for the build status
[12:45:56.500] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:45:56.500] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:76:0) after 1m0s
[12:46:56.976] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:76:0)
[12:46:56.976] Timer tick, asking Buildbucket for the build status
[12:46:57.111] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:46:57.111] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:77:0) after 1m0s
[12:47:57.211] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:77:0)
[12:47:57.211] Timer tick, asking Buildbucket for the build status
[12:47:57.425] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:47:57.425] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:78:0) after 1m0s
[12:48:57.516] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:78:0)
[12:48:57.516] Timer tick, asking Buildbucket for the build status
[12:48:57.758] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:48:57.758] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:79:0) after 1m0s
[12:49:58.003] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:79:0)
[12:49:58.003] Timer tick, asking Buildbucket for the build status
[12:49:58.234] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:49:58.234] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:80:0) after 1m0s
[12:50:58.260] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:80:0)
[12:50:58.260] Timer tick, asking Buildbucket for the build status
[12:50:58.415] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:50:58.415] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:81:0) after 1m0s
[12:51:58.639] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:81:0)
[12:51:58.639] Timer tick, asking Buildbucket for the build status
[12:51:58.800] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:51:58.800] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:82:0) after 1m0s
[12:52:58.913] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:82:0)
[12:52:58.913] Timer tick, asking Buildbucket for the build status
[12:52:59.049] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:52:59.049] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:83:0) after 1m0s
[12:53:59.081] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:83:0)
[12:53:59.081] Timer tick, asking Buildbucket for the build status
[12:53:59.256] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:53:59.256] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:84:0) after 1m0s
[12:54:59.348] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:84:0)
[12:54:59.348] Timer tick, asking Buildbucket for the build status
[12:55:05.158] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:55:05.158] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:85:0) after 1m0s
[12:56:05.167] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:85:0)
[12:56:05.167] Timer tick, asking Buildbucket for the build status
[12:56:05.325] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:56:05.325] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:86:0) after 1m0s
[12:57:05.708] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:86:0)
[12:57:05.708] Timer tick, asking Buildbucket for the build status
[12:57:05.845] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:57:05.845] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:87:0) after 1m0s
[12:58:06.343] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:87:0)
[12:58:06.343] Timer tick, asking Buildbucket for the build status
[12:58:06.507] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:58:06.507] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:88:0) after 1m0s
[12:59:06.673] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:88:0)
[12:59:06.673] Timer tick, asking Buildbucket for the build status
[12:59:06.846] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[12:59:06.846] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:89:0) after 1m0s
[13:00:06.973] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:89:0)
[13:00:06.973] Timer tick, asking Buildbucket for the build status
[13:00:07.189] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:00:07.189] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:90:0) after 1m0s
[13:01:07.362] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:90:0)
[13:01:07.362] Timer tick, asking Buildbucket for the build status
[13:01:07.778] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:01:07.778] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:91:0) after 1m0s
[13:02:07.907] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:91:0)
[13:02:07.907] Timer tick, asking Buildbucket for the build status
[13:02:08.204] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:02:08.205] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:92:0) after 1m0s
[13:03:08.260] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:92:0)
[13:03:08.260] Timer tick, asking Buildbucket for the build status
[13:03:08.431] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:03:08.431] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:93:0) after 1m0s
[13:04:08.458] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:93:0)
[13:04:08.458] Timer tick, asking Buildbucket for the build status
[13:04:08.648] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:04:08.648] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:94:0) after 1m0s
[13:05:08.699] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:94:0)
[13:05:08.699] Timer tick, asking Buildbucket for the build status
[13:05:08.851] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:05:08.851] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:95:0) after 1m0s
[13:06:08.874] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:95:0)
[13:06:08.874] Timer tick, asking Buildbucket for the build status
[13:06:09.318] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:06:09.318] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:96:0) after 1m0s
[13:07:10.901] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:96:0)
[13:07:10.901] Timer tick, asking Buildbucket for the build status
[13:07:12.116] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:07:12.116] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:97:0) after 1m0s
[13:08:12.275] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:97:0)
[13:08:12.275] Timer tick, asking Buildbucket for the build status
[13:08:12.509] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:08:12.509] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:98:0) after 1m0s
[13:09:12.621] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:98:0)
[13:09:12.621] Timer tick, asking Buildbucket for the build status
[13:09:12.765] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:09:12.765] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:99:0) after 1m0s
[13:10:12.998] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:99:0)
[13:10:12.998] Timer tick, asking Buildbucket for the build status
[13:10:13.306] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:10:13.306] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:100:0) after 1m0s
[13:11:13.348] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:100:0)
[13:11:13.348] Timer tick, asking Buildbucket for the build status
[13:11:13.494] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:11:13.494] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:101:0) after 1m0s
[13:12:13.548] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:101:0)
[13:12:13.548] Timer tick, asking Buildbucket for the build status
[13:12:13.697] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:12:13.697] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:102:0) after 1m0s
[13:13:13.826] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:102:0)
[13:13:13.826] Timer tick, asking Buildbucket for the build status
[13:13:13.960] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:13:13.960] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:103:0) after 1m0s
[13:14:14.076] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:103:0)
[13:14:14.076] Timer tick, asking Buildbucket for the build status
[13:14:14.283] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:14:14.283] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:104:0) after 1m0s
[13:15:14.373] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:104:0)
[13:15:14.373] Timer tick, asking Buildbucket for the build status
[13:15:15.039] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:15:15.039] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:105:0) after 1m0s
[13:16:15.077] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:105:0)
[13:16:15.077] Timer tick, asking Buildbucket for the build status
[13:16:15.224] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:16:15.224] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:106:0) after 1m0s
[13:17:15.273] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:106:0)
[13:17:15.273] Timer tick, asking Buildbucket for the build status
[13:17:15.622] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:17:15.622] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:107:0) after 1m0s
[13:18:15.716] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:107:0)
[13:18:15.716] Timer tick, asking Buildbucket for the build status
[13:18:15.837] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:18:15.837] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:108:0) after 1m0s
[13:19:15.997] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:108:0)
[13:19:15.997] Timer tick, asking Buildbucket for the build status
[13:19:16.291] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:19:16.291] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:109:0) after 1m0s
[13:20:16.305] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:109:0)
[13:20:16.305] Timer tick, asking Buildbucket for the build status
[13:20:17.450] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:20:17.450] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:110:0) after 1m0s
[13:21:17.480] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:110:0)
[13:21:17.480] Timer tick, asking Buildbucket for the build status
[13:21:17.877] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:21:17.877] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:111:0) after 1m0s
[13:22:17.853] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:111:0)
[13:22:17.853] Timer tick, asking Buildbucket for the build status
[13:22:18.104] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:22:18.104] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:112:0) after 1m0s
[13:23:18.162] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:112:0)
[13:23:18.162] Timer tick, asking Buildbucket for the build status
[13:23:18.338] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:23:18.338] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:113:0) after 1m0s
[13:24:18.374] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:113:0)
[13:24:18.374] Timer tick, asking Buildbucket for the build status
[13:24:18.609] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:24:18.609] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:114:0) after 1m0s
[13:25:18.596] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:114:0)
[13:25:18.596] Timer tick, asking Buildbucket for the build status
[13:25:18.830] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:25:18.830] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:115:0) after 1m0s
[13:26:18.873] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:115:0)
[13:26:18.873] Timer tick, asking Buildbucket for the build status
[13:26:20.594] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:26:20.594] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:116:0) after 1m0s
[13:27:20.648] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:116:0)
[13:27:20.648] Timer tick, asking Buildbucket for the build status
[13:27:20.883] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:27:20.883] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:117:0) after 1m0s
[13:28:20.948] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:117:0)
[13:28:20.948] Timer tick, asking Buildbucket for the build status
[13:28:21.098] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:28:21.098] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:118:0) after 1m0s
[13:29:21.243] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:118:0)
[13:29:21.243] Timer tick, asking Buildbucket for the build status
[13:29:22.221] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:29:22.221] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:119:0) after 1m0s
[13:30:22.274] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:119:0)
[13:30:22.274] Timer tick, asking Buildbucket for the build status
[13:30:22.429] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:30:22.429] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:120:0) after 1m0s
[13:31:22.461] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:120:0)
[13:31:22.461] Timer tick, asking Buildbucket for the build status
[13:31:22.722] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:31:22.722] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:121:0) after 1m0s
[13:32:22.819] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:121:0)
[13:32:22.819] Timer tick, asking Buildbucket for the build status
[13:32:23.756] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:32:23.756] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:122:0) after 1m0s
[13:33:23.778] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:122:0)
[13:33:23.778] Timer tick, asking Buildbucket for the build status
[13:33:24.078] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:33:24.078] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:123:0) after 1m0s
[13:34:24.111] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:123:0)
[13:34:24.111] Timer tick, asking Buildbucket for the build status
[13:34:24.250] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:34:24.250] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:124:0) after 1m0s
[13:35:24.287] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:124:0)
[13:35:24.287] Timer tick, asking Buildbucket for the build status
[13:35:24.467] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:35:24.468] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:125:0) after 1m0s
[13:36:24.509] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:125:0)
[13:36:24.509] Timer tick, asking Buildbucket for the build status
[13:36:24.813] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:36:24.813] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:126:0) after 1m0s
[13:37:24.863] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:126:0)
[13:37:24.863] Timer tick, asking Buildbucket for the build status
[13:37:24.981] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:37:24.981] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:127:0) after 1m0s
[13:38:24.976] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:127:0)
[13:38:24.976] Timer tick, asking Buildbucket for the build status
[13:38:26.900] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:38:26.900] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:128:0) after 1m0s
[13:39:26.968] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:128:0)
[13:39:26.968] Timer tick, asking Buildbucket for the build status
[13:39:27.077] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:39:27.077] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:129:0) after 1m0s
[13:40:27.110] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:129:0)
[13:40:27.110] Timer tick, asking Buildbucket for the build status
[13:40:27.262] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:40:27.262] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:130:0) after 1m0s
[13:41:27.273] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:130:0)
[13:41:27.273] Timer tick, asking Buildbucket for the build status
[13:41:27.487] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:41:27.487] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:131:0) after 1m0s
[13:42:27.538] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:131:0)
[13:42:27.538] Timer tick, asking Buildbucket for the build status
[13:42:27.764] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:42:27.764] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:132:0) after 1m0s
[13:43:27.790] Handling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:132:0)
[13:43:27.790] Timer tick, asking Buildbucket for the build status
[13:43:28.101] Build 8875254941984067856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[13:43:28.101] Scheduling timer "check-buildbucket-build-status" (nacl/linux-pnacl-x86_64:9040685007069867264:133:0) after 1m0s
[13:43:38.737] Received PubSub notification, asking Buildbucket for the build status
[13:43:38.826] Build 8875254941984067856: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[13:43:38.826] Buildbucket build:
{
"build": {
"bucket": "luci.nacl.toolchain",
"canary_preference": "PROD",
"completed_ts": "1594302217918721",
"created_by": "project:nacl",
"created_ts": "1594294332480776",
"id": "8875254941984067856",
"parameters_json": "{\"builder_name\": \"linux-pnacl-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": "SUCCESS",
"result_details_json": "{\"properties\": {\"$build/goma\": {\"enable_ats\": true, \"rpc_extra_params\": \"?prod\", \"server_host\": \"goma.chromium.org\"}, \"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/native_client/src/native_client.git\", \"revision\": \"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-1-kswx\", \"branch\": \"refs/heads/master\", \"buildername\": \"linux-pnacl-x86_64\", \"buildnumber\": 7073, \"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\": {\"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-kswx\"], \"image\": [\"chrome-xenial-20052400-59eb8623c93\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"n1-standard-16\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16.04\"], \"pool\": [\"luci.nacl.toolchain\"], \"python\": [\"2.7.12\"], \"server_version\": [\"5378-e275056\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-east\", \"us-east1\", \"us-east1-b\"]}}}",
"service_account": "nacl-toolchain-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1594294350022298",
"status": "COMPLETED",
"status_changed_ts": "1594302218372174",
"tags": [
"build_address:luci.nacl.toolchain/linux-pnacl-x86_64/7073",
"builder:linux-pnacl-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:9040685007069867264",
"scheduler_job_id:nacl/linux-pnacl-x86_64",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/nacl/buildbucket/cr-buildbucket.appspot.com/8875254941984067856/+/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:4d4c2a7cc4c17e10",
"user_agent:luci-scheduler"
],
"updated_ts": "1594302218399138",
"url": "https://ci.chromium.org/b/8875254941984067856",
"utcnow_ts": "1594302218808269"
}
}
[13:43:38.826] Invocation finished in 2h11m30.58045664s with status SUCCEEDED