[03:36:26.143] New invocation is queued and will start shortly
[03:36:27.296] Starting the invocation (attempt 1)
[03:36:27.353] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[03:36:27.353] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[03:36:27.353] Buildbucket request:
{
"bucket": "luci.fuchsia.prod",
"client_operation_id": "9079581034238065216",
"parameters_json": "{\"builder_name\":\"clang\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://fuchsia.googlesource.com/third_party/llvm-project\",\"revision\":\"c72aaf62d3f92c0c6d33b4df2253505f6eb22996\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:clang",
"scheduler_invocation_id:9079581034238065216",
"scheduler_job_id:fuchsia/prod-clang",
"user_agent:luci-scheduler",
"buildset:commit/git/c72aaf62d3f92c0c6d33b4df2253505f6eb22996",
"buildset:commit/gitiles/fuchsia.googlesource.com/third_party/llvm-project/+/c72aaf62d3f92c0c6d33b4df2253505f6eb22996",
"gitiles_ref:refs/heads/master"
]
}
[03:36:28.725] Buildbucket response:
{
"build": {
"bucket": "luci.fuchsia.prod",
"canary_preference": "AUTO",
"created_by": "project:fuchsia",
"created_ts": "1557200187495361",
"id": "8914150972155486576",
"parameters_json": "{\"builder_name\": \"clang\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://fuchsia.googlesource.com/third_party/llvm-project\", \"revision\": \"c72aaf62d3f92c0c6d33b4df2253505f6eb22996\"}}",
"project": "fuchsia",
"result_details_json": "{\"properties\": {}}",
"service_account": "fuchsia-prod-builder@fuchsia-infra.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1557200187976532",
"tags": [
"builder:clang",
"buildset:commit/git/c72aaf62d3f92c0c6d33b4df2253505f6eb22996",
"buildset:commit/gitiles/fuchsia.googlesource.com/third_party/llvm-project/+/c72aaf62d3f92c0c6d33b4df2253505f6eb22996",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9079581034238065216",
"scheduler_job_id:fuchsia/prod-clang",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/fuchsia/buildbucket/cr-buildbucket.appspot.com/8914150972155486576/+/annotations",
"swarming_tag:luci_project:fuchsia",
"swarming_tag:recipe_name:buildbucket_trigger",
"swarming_tag:recipe_package:fuchsia/infra/recipe_bundles/fuchsia.googlesource.com/infra/recipes",
"swarming_task_id:",
"user_agent:luci-scheduler"
],
"updated_ts": "1557200187976619",
"url": "https://ci.chromium.org/b/8914150972155486576",
"utcnow_ts": "1557200188703970"
}
}
[03:36:28.725] Task URL: https://ci.chromium.org/b/8914150972155486576
[03:36:28.725] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:2:0) after 1m0s
[03:36:33.424] Received PubSub notification, asking Buildbucket for the build status
[03:36:33.488] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:37:28.760] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:2:0)
[03:37:28.760] Timer tick, asking Buildbucket for the build status
[03:37:28.982] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:37:28.982] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:4:0) after 1m0s
[03:38:29.158] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:4:0)
[03:38:29.158] Timer tick, asking Buildbucket for the build status
[03:38:29.295] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:38:29.295] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:5:0) after 1m0s
[03:39:29.315] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:5:0)
[03:39:29.315] Timer tick, asking Buildbucket for the build status
[03:39:29.553] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:39:29.553] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:6:0) after 1m0s
[03:40:29.573] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:6:0)
[03:40:29.573] Timer tick, asking Buildbucket for the build status
[03:40:29.636] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:40:29.636] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:7:0) after 1m0s
[03:41:29.696] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:7:0)
[03:41:29.696] Timer tick, asking Buildbucket for the build status
[03:41:29.802] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:41:29.802] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:8:0) after 1m0s
[03:42:29.843] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:8:0)
[03:42:29.843] Timer tick, asking Buildbucket for the build status
[03:42:29.896] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:42:29.896] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:9:0) after 1m0s
[03:43:29.897] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:9:0)
[03:43:29.897] Timer tick, asking Buildbucket for the build status
[03:43:29.959] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:43:29.959] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:10:0) after 1m0s
[03:44:29.942] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:10:0)
[03:44:29.942] Timer tick, asking Buildbucket for the build status
[03:44:29.998] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:44:29.998] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:11:0) after 1m0s
[03:45:30.023] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:11:0)
[03:45:30.023] Timer tick, asking Buildbucket for the build status
[03:45:30.104] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:45:30.104] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:12:0) after 1m0s
[03:46:30.110] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:12:0)
[03:46:30.110] Timer tick, asking Buildbucket for the build status
[03:46:30.158] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:46:30.158] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:13:0) after 1m0s
[03:47:30.177] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:13:0)
[03:47:30.177] Timer tick, asking Buildbucket for the build status
[03:47:30.218] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:47:30.218] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:14:0) after 1m0s
[03:48:30.237] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:14:0)
[03:48:30.237] Timer tick, asking Buildbucket for the build status
[03:48:30.308] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:48:30.308] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:15:0) after 1m0s
[03:49:30.325] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:15:0)
[03:49:30.325] Timer tick, asking Buildbucket for the build status
[03:49:30.367] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:49:30.367] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:16:0) after 1m0s
[03:50:30.338] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:16:0)
[03:50:30.338] Timer tick, asking Buildbucket for the build status
[03:50:30.405] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:50:30.405] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:17:0) after 1m0s
[03:51:30.423] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:17:0)
[03:51:30.423] Timer tick, asking Buildbucket for the build status
[03:51:30.572] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:51:30.572] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:18:0) after 1m0s
[03:52:30.607] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:18:0)
[03:52:30.607] Timer tick, asking Buildbucket for the build status
[03:52:30.774] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:52:30.774] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:19:0) after 1m0s
[03:53:30.792] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:19:0)
[03:53:30.792] Timer tick, asking Buildbucket for the build status
[03:53:30.868] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:53:30.868] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:20:0) after 1m0s
[03:54:30.884] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:20:0)
[03:54:30.884] Timer tick, asking Buildbucket for the build status
[03:54:31.170] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:54:31.170] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:21:0) after 1m0s
[03:55:31.196] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:21:0)
[03:55:31.196] Timer tick, asking Buildbucket for the build status
[03:55:31.303] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:55:31.303] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:22:0) after 1m0s
[03:56:31.285] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:22:0)
[03:56:31.285] Timer tick, asking Buildbucket for the build status
[03:56:31.649] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:56:31.649] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:23:0) after 1m0s
[03:57:31.685] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:23:0)
[03:57:31.685] Timer tick, asking Buildbucket for the build status
[03:57:31.907] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:57:31.907] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:24:0) after 1m0s
[03:58:31.927] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:24:0)
[03:58:31.927] Timer tick, asking Buildbucket for the build status
[03:58:32.008] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:58:32.008] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:25:0) after 1m0s
[03:59:32.026] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:25:0)
[03:59:32.026] Timer tick, asking Buildbucket for the build status
[03:59:32.151] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:59:32.151] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:26:0) after 1m0s
[04:00:32.136] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:26:0)
[04:00:32.136] Timer tick, asking Buildbucket for the build status
[04:00:32.193] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:00:32.193] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:27:0) after 1m0s
[04:01:32.195] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:27:0)
[04:01:32.195] Timer tick, asking Buildbucket for the build status
[04:01:32.254] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:01:32.254] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:28:0) after 1m0s
[04:02:32.277] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:28:0)
[04:02:32.277] Timer tick, asking Buildbucket for the build status
[04:02:32.343] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:02:32.343] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:29:0) after 1m0s
[04:03:32.365] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:29:0)
[04:03:32.365] Timer tick, asking Buildbucket for the build status
[04:03:32.477] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:03:32.477] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:30:0) after 1m0s
[04:04:32.521] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:30:0)
[04:04:32.521] Timer tick, asking Buildbucket for the build status
[04:04:32.584] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:04:32.584] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:31:0) after 1m0s
[04:05:32.603] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:31:0)
[04:05:32.603] Timer tick, asking Buildbucket for the build status
[04:05:32.759] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:05:32.759] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:32:0) after 1m0s
[04:06:32.768] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:32:0)
[04:06:32.768] Timer tick, asking Buildbucket for the build status
[04:06:32.878] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:06:32.878] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:33:0) after 1m0s
[04:07:32.899] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:33:0)
[04:07:32.899] Timer tick, asking Buildbucket for the build status
[04:07:33.010] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:07:33.010] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:34:0) after 1m0s
[04:08:33.043] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:34:0)
[04:08:33.043] Timer tick, asking Buildbucket for the build status
[04:08:33.157] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:08:33.157] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:35:0) after 1m0s
[04:09:33.176] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:35:0)
[04:09:33.176] Timer tick, asking Buildbucket for the build status
[04:09:33.423] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:09:33.423] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:36:0) after 1m0s
[04:10:33.485] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:36:0)
[04:10:33.485] Timer tick, asking Buildbucket for the build status
[04:10:33.567] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:10:33.567] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:37:0) after 1m0s
[04:11:33.591] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:37:0)
[04:11:33.591] Timer tick, asking Buildbucket for the build status
[04:11:33.645] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:11:33.645] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:38:0) after 1m0s
[04:12:33.669] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:38:0)
[04:12:33.669] Timer tick, asking Buildbucket for the build status
[04:12:33.796] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:12:33.796] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:39:0) after 1m0s
[04:13:33.816] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:39:0)
[04:13:33.816] Timer tick, asking Buildbucket for the build status
[04:13:33.981] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:13:33.981] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:40:0) after 1m0s
[04:14:34.001] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:40:0)
[04:14:34.001] Timer tick, asking Buildbucket for the build status
[04:14:34.075] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:14:34.075] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:41:0) after 1m0s
[04:15:34.099] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:41:0)
[04:15:34.099] Timer tick, asking Buildbucket for the build status
[04:15:34.227] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:15:34.227] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:42:0) after 1m0s
[04:16:34.259] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:42:0)
[04:16:34.259] Timer tick, asking Buildbucket for the build status
[04:16:34.329] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:16:34.329] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:43:0) after 1m0s
[04:17:34.401] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:43:0)
[04:17:34.401] Timer tick, asking Buildbucket for the build status
[04:17:34.476] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:17:34.476] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:44:0) after 1m0s
[04:18:34.495] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:44:0)
[04:18:34.495] Timer tick, asking Buildbucket for the build status
[04:18:34.574] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:18:34.575] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:45:0) after 1m0s
[04:19:34.594] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:45:0)
[04:19:34.594] Timer tick, asking Buildbucket for the build status
[04:19:34.664] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:19:34.664] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:46:0) after 1m0s
[04:20:34.719] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:46:0)
[04:20:34.719] Timer tick, asking Buildbucket for the build status
[04:20:34.796] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:20:34.796] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:47:0) after 1m0s
[04:21:34.815] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:47:0)
[04:21:34.815] Timer tick, asking Buildbucket for the build status
[04:21:34.883] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:21:34.883] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:48:0) after 1m0s
[04:22:34.863] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:48:0)
[04:22:34.863] Timer tick, asking Buildbucket for the build status
[04:22:34.971] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:22:34.971] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:49:0) after 1m0s
[04:23:34.991] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:49:0)
[04:23:34.991] Timer tick, asking Buildbucket for the build status
[04:23:35.051] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:23:35.051] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:50:0) after 1m0s
[04:24:35.072] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:50:0)
[04:24:35.072] Timer tick, asking Buildbucket for the build status
[04:24:35.138] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:24:35.138] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:51:0) after 1m0s
[04:25:35.161] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:51:0)
[04:25:35.161] Timer tick, asking Buildbucket for the build status
[04:25:35.221] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:25:35.221] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:52:0) after 1m0s
[04:26:35.246] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:52:0)
[04:26:35.246] Timer tick, asking Buildbucket for the build status
[04:26:35.306] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:26:35.306] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:53:0) after 1m0s
[04:27:35.333] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:53:0)
[04:27:35.333] Timer tick, asking Buildbucket for the build status
[04:27:35.389] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:27:35.389] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:54:0) after 1m0s
[04:28:35.370] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:54:0)
[04:28:35.370] Timer tick, asking Buildbucket for the build status
[04:28:35.527] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:28:35.527] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:55:0) after 1m0s
[04:29:35.529] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:55:0)
[04:29:35.529] Timer tick, asking Buildbucket for the build status
[04:29:35.577] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:29:35.577] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:56:0) after 1m0s
[04:30:35.568] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:56:0)
[04:30:35.568] Timer tick, asking Buildbucket for the build status
[04:30:35.682] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:30:35.682] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:57:0) after 1m0s
[04:31:35.682] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:57:0)
[04:31:35.682] Timer tick, asking Buildbucket for the build status
[04:31:35.863] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:31:35.863] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:58:0) after 1m0s
[04:32:35.897] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:58:0)
[04:32:35.898] Timer tick, asking Buildbucket for the build status
[04:32:36.038] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:32:36.038] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:59:0) after 1m0s
[04:33:36.069] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:59:0)
[04:33:36.069] Timer tick, asking Buildbucket for the build status
[04:33:36.122] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:33:36.122] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:60:0) after 1m0s
[04:34:36.148] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:60:0)
[04:34:36.148] Timer tick, asking Buildbucket for the build status
[04:34:36.221] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:34:36.222] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:61:0) after 1m0s
[04:35:36.244] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:61:0)
[04:35:36.244] Timer tick, asking Buildbucket for the build status
[04:35:36.413] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:35:36.413] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:62:0) after 1m0s
[04:36:36.421] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:62:0)
[04:36:36.421] Timer tick, asking Buildbucket for the build status
[04:36:36.544] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:36:36.544] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:63:0) after 1m0s
[04:37:36.539] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:63:0)
[04:37:36.539] Timer tick, asking Buildbucket for the build status
[04:37:36.690] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:37:36.690] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:64:0) after 1m0s
[04:38:36.711] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:64:0)
[04:38:36.711] Timer tick, asking Buildbucket for the build status
[04:38:36.932] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:38:36.932] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:65:0) after 1m0s
[04:39:36.958] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:65:0)
[04:39:36.958] Timer tick, asking Buildbucket for the build status
[04:39:37.037] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:39:37.037] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:66:0) after 1m0s
[04:40:37.058] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:66:0)
[04:40:37.058] Timer tick, asking Buildbucket for the build status
[04:40:37.102] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:40:37.102] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:67:0) after 1m0s
[04:41:37.120] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:67:0)
[04:41:37.121] Timer tick, asking Buildbucket for the build status
[04:41:37.293] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:41:37.293] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:68:0) after 1m0s
[04:42:37.291] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:68:0)
[04:42:37.291] Timer tick, asking Buildbucket for the build status
[04:42:37.373] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:42:37.373] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:69:0) after 1m0s
[04:43:37.376] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:69:0)
[04:43:37.376] Timer tick, asking Buildbucket for the build status
[04:43:37.530] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:43:37.530] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:70:0) after 1m0s
[04:44:37.559] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:70:0)
[04:44:37.559] Timer tick, asking Buildbucket for the build status
[04:44:37.601] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:44:37.601] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:71:0) after 1m0s
[04:45:37.593] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:71:0)
[04:45:37.593] Timer tick, asking Buildbucket for the build status
[04:45:37.664] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:45:37.664] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:72:0) after 1m0s
[04:46:37.685] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:72:0)
[04:46:37.685] Timer tick, asking Buildbucket for the build status
[04:46:37.797] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:46:37.797] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:73:0) after 1m0s
[04:47:37.788] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:73:0)
[04:47:37.788] Timer tick, asking Buildbucket for the build status
[04:47:37.892] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:47:37.892] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:74:0) after 1m0s
[04:48:37.915] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:74:0)
[04:48:37.915] Timer tick, asking Buildbucket for the build status
[04:48:38.042] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:48:38.042] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:75:0) after 1m0s
[04:49:38.078] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:75:0)
[04:49:38.078] Timer tick, asking Buildbucket for the build status
[04:49:38.215] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:49:38.215] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:76:0) after 1m0s
[04:50:38.211] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:76:0)
[04:50:38.211] Timer tick, asking Buildbucket for the build status
[04:50:38.256] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:50:38.256] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:77:0) after 1m0s
[04:51:38.272] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:77:0)
[04:51:38.272] Timer tick, asking Buildbucket for the build status
[04:51:38.471] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:51:38.471] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:78:0) after 1m0s
[04:52:38.493] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:78:0)
[04:52:38.493] Timer tick, asking Buildbucket for the build status
[04:52:38.539] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:52:38.540] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:79:0) after 1m0s
[04:53:38.545] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:79:0)
[04:53:38.545] Timer tick, asking Buildbucket for the build status
[04:53:38.625] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:53:38.625] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:80:0) after 1m0s
[04:54:38.647] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:80:0)
[04:54:38.647] Timer tick, asking Buildbucket for the build status
[04:54:38.727] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:54:38.727] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:81:0) after 1m0s
[04:55:38.758] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:81:0)
[04:55:38.758] Timer tick, asking Buildbucket for the build status
[04:55:38.811] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:55:38.811] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:82:0) after 1m0s
[04:56:38.788] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:82:0)
[04:56:38.788] Timer tick, asking Buildbucket for the build status
[04:56:38.839] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:56:38.839] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:83:0) after 1m0s
[04:57:38.839] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:83:0)
[04:57:38.839] Timer tick, asking Buildbucket for the build status
[04:57:38.905] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:57:38.905] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:84:0) after 1m0s
[04:58:38.931] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:84:0)
[04:58:38.931] Timer tick, asking Buildbucket for the build status
[04:58:39.023] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:58:39.023] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:85:0) after 1m0s
[04:59:39.054] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:85:0)
[04:59:39.054] Timer tick, asking Buildbucket for the build status
[04:59:39.106] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:59:39.106] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:86:0) after 1m0s
[05:00:39.125] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:86:0)
[05:00:39.125] Timer tick, asking Buildbucket for the build status
[05:00:39.229] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:00:39.229] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:87:0) after 1m0s
[05:01:39.255] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:87:0)
[05:01:39.255] Timer tick, asking Buildbucket for the build status
[05:01:39.322] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:01:39.322] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:88:0) after 1m0s
[05:02:39.345] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:88:0)
[05:02:39.345] Timer tick, asking Buildbucket for the build status
[05:02:39.404] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:02:39.404] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:89:0) after 1m0s
[05:03:39.427] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:89:0)
[05:03:39.427] Timer tick, asking Buildbucket for the build status
[05:03:39.713] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:03:39.713] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:90:0) after 1m0s
[05:04:39.735] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:90:0)
[05:04:39.735] Timer tick, asking Buildbucket for the build status
[05:04:39.831] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:04:39.831] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:91:0) after 1m0s
[05:05:39.856] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:91:0)
[05:05:39.857] Timer tick, asking Buildbucket for the build status
[05:05:39.894] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:05:39.894] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:92:0) after 1m0s
[05:06:39.923] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:92:0)
[05:06:39.923] Timer tick, asking Buildbucket for the build status
[05:06:40.174] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:06:40.174] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:93:0) after 1m0s
[05:07:40.255] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:93:0)
[05:07:40.255] Timer tick, asking Buildbucket for the build status
[05:07:40.312] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:07:40.312] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:94:0) after 1m0s
[05:08:40.337] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:94:0)
[05:08:40.337] Timer tick, asking Buildbucket for the build status
[05:08:40.568] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:08:40.568] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:95:0) after 1m0s
[05:09:40.596] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:95:0)
[05:09:40.596] Timer tick, asking Buildbucket for the build status
[05:09:40.660] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:09:40.660] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:96:0) after 1m0s
[05:10:40.677] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:96:0)
[05:10:40.677] Timer tick, asking Buildbucket for the build status
[05:10:40.812] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:10:40.812] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:97:0) after 1m0s
[05:11:40.837] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:97:0)
[05:11:40.837] Timer tick, asking Buildbucket for the build status
[05:11:41.009] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:11:41.009] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:98:0) after 1m0s
[05:12:41.032] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:98:0)
[05:12:41.032] Timer tick, asking Buildbucket for the build status
[05:12:41.147] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:12:41.147] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:99:0) after 1m0s
[05:13:41.169] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:99:0)
[05:13:41.169] Timer tick, asking Buildbucket for the build status
[05:13:41.358] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:13:41.358] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:100:0) after 1m0s
[05:14:41.390] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:100:0)
[05:14:41.390] Timer tick, asking Buildbucket for the build status
[05:14:41.473] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:14:41.473] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:101:0) after 1m0s
[05:15:41.499] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:101:0)
[05:15:41.499] Timer tick, asking Buildbucket for the build status
[05:15:41.586] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:15:41.586] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:102:0) after 1m0s
[05:16:41.620] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:102:0)
[05:16:41.620] Timer tick, asking Buildbucket for the build status
[05:16:41.775] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:16:41.775] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:103:0) after 1m0s
[05:17:41.796] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:103:0)
[05:17:41.796] Timer tick, asking Buildbucket for the build status
[05:17:41.856] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:17:41.856] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:104:0) after 1m0s
[05:18:41.842] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:104:0)
[05:18:41.842] Timer tick, asking Buildbucket for the build status
[05:18:41.883] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:18:41.883] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:105:0) after 1m0s
[05:19:41.918] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:105:0)
[05:19:41.918] Timer tick, asking Buildbucket for the build status
[05:19:42.015] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:19:42.015] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:106:0) after 1m0s
[05:20:42.040] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:106:0)
[05:20:42.040] Timer tick, asking Buildbucket for the build status
[05:20:42.089] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:20:42.089] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:107:0) after 1m0s
[05:21:42.092] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:107:0)
[05:21:42.092] Timer tick, asking Buildbucket for the build status
[05:21:42.237] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:21:42.237] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:108:0) after 1m0s
[05:22:42.259] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:108:0)
[05:22:42.259] Timer tick, asking Buildbucket for the build status
[05:22:42.346] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:22:42.346] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:109:0) after 1m0s
[05:23:42.838] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:109:0)
[05:23:42.838] Timer tick, asking Buildbucket for the build status
[05:23:42.974] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:23:42.974] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:110:0) after 1m0s
[05:24:42.957] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:110:0)
[05:24:42.957] Timer tick, asking Buildbucket for the build status
[05:24:43.383] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:24:43.383] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:111:0) after 1m0s
[05:25:43.435] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:111:0)
[05:25:43.435] Timer tick, asking Buildbucket for the build status
[05:25:43.725] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:25:43.725] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:112:0) after 1m0s
[05:26:43.754] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:112:0)
[05:26:43.754] Timer tick, asking Buildbucket for the build status
[05:26:43.812] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:26:43.812] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:113:0) after 1m0s
[05:27:43.836] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:113:0)
[05:27:43.836] Timer tick, asking Buildbucket for the build status
[05:27:43.882] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:27:43.882] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:114:0) after 1m0s
[05:28:43.903] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:114:0)
[05:28:43.903] Timer tick, asking Buildbucket for the build status
[05:28:43.993] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:28:43.993] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:115:0) after 1m0s
[05:29:44.022] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:115:0)
[05:29:44.022] Timer tick, asking Buildbucket for the build status
[05:29:44.175] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:29:44.175] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:116:0) after 1m0s
[05:30:44.191] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:116:0)
[05:30:44.191] Timer tick, asking Buildbucket for the build status
[05:30:44.269] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:30:44.269] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:117:0) after 1m0s
[05:31:44.309] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:117:0)
[05:31:44.309] Timer tick, asking Buildbucket for the build status
[05:31:44.407] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:31:44.408] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:118:0) after 1m0s
[05:32:44.401] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:118:0)
[05:32:44.401] Timer tick, asking Buildbucket for the build status
[05:32:48.359] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:32:48.359] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:119:0) after 1m0s
[05:33:48.378] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:119:0)
[05:33:48.379] Timer tick, asking Buildbucket for the build status
[05:33:48.469] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:33:48.469] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:120:0) after 1m0s
[05:34:48.448] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:120:0)
[05:34:48.448] Timer tick, asking Buildbucket for the build status
[05:34:48.825] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:34:48.825] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:121:0) after 1m0s
[05:35:48.819] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:121:0)
[05:35:48.819] Timer tick, asking Buildbucket for the build status
[05:35:49.020] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:35:49.020] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:122:0) after 1m0s
[05:36:49.047] Handling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:122:0)
[05:36:49.047] Timer tick, asking Buildbucket for the build status
[05:36:49.207] Build 8914150972155486576: status "STARTED", result "", failure_reason "", cancelation_reason ""
[05:36:49.207] Scheduling timer "check-buildbucket-build-status" (fuchsia/prod-clang:9079581034238065216:123:0) after 1m0s
[05:37:11.570] Received PubSub notification, asking Buildbucket for the build status
[05:37:11.814] Build 8914150972155486576: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[05:37:11.814] Buildbucket build:
{
"build": {
"bucket": "luci.fuchsia.prod",
"canary_preference": "AUTO",
"completed_ts": "1557207431283162",
"created_by": "project:fuchsia",
"created_ts": "1557200187495361",
"failure_reason": "BUILD_FAILURE",
"id": "8914150972155486576",
"parameters_json": "{\"builder_name\": \"clang\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://fuchsia.googlesource.com/third_party/llvm-project\", \"revision\": \"c72aaf62d3f92c0c6d33b4df2253505f6eb22996\"}}",
"project": "fuchsia",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step Timeout: Step('buildbucket.run.collect') timed out after 7200\"}, \"properties\": {\"$recipe_engine/isolated\": {\"server\": \"https://isolateserver.appspot.com\"}, \"$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/swarming\": {\"server\": \"https://chromium-swarm.appspot.com\"}, \"bot_id\": \"fuchsia-debian-1-003729e9-us-central1-c-x31d\", \"branch\": \"refs/heads/master\", \"buildername\": \"clang\", \"builders\": [\"clang-linux-arm64\", \"clang-linux-x64\", \"clang-mac-x64\"], \"path_config\": \"generic\", \"recipe\": \"buildbucket_trigger\", \"repository\": \"https://fuchsia.googlesource.com/third_party/llvm-project\", \"revision\": \"c72aaf62d3f92c0c6d33b4df2253505f6eb22996\", \"timeout\": 7200.0}, \"swarming\": {\"bot_dimensions\": {\"cores\": [\"1\"], \"cpu\": [\"x64\", \"x86\", \"x86-64-Haswell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gpu\": [\"none\"], \"id\": [\"fuchsia-debian-1-003729e9-us-central1-c-x31d\"], \"image\": [\"fuchsia-debian-9-drawfork-v20190426-c90e1d5-prod\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"n1-standard-1\"], \"os\": [\"Debian\", \"Debian-9.5\", \"Linux\"], \"pool\": [\"luci.fuchsia.prod\"], \"python\": [\"2.7.13\"], \"server_version\": [\"4289-d945138\"], \"zone\": [\"us\", \"us-central\", \"us-central1\", \"us-central1-c\"]}}, \"ui\": {\"info\": \"Step Timeout: Step('buildbucket.run.collect') timed out after 7200\"}}",
"service_account": "fuchsia-prod-builder@fuchsia-infra.iam.gserviceaccount.com",
"started_ts": "1557200192373501",
"status": "COMPLETED",
"status_changed_ts": "1557200193019613",
"tags": [
"builder:clang",
"buildset:commit/git/c72aaf62d3f92c0c6d33b4df2253505f6eb22996",
"buildset:commit/gitiles/fuchsia.googlesource.com/third_party/llvm-project/+/c72aaf62d3f92c0c6d33b4df2253505f6eb22996",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9079581034238065216",
"scheduler_job_id:fuchsia/prod-clang",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/fuchsia/buildbucket/cr-buildbucket.appspot.com/8914150972155486576/+/annotations",
"swarming_tag:luci_project:fuchsia",
"swarming_tag:os:Debian",
"swarming_tag:recipe_name:buildbucket_trigger",
"swarming_tag:recipe_package:fuchsia/infra/recipe_bundles/fuchsia.googlesource.com/infra/recipes",
"swarming_task_id:44a92ebe27ab1f10",
"user_agent:luci-scheduler"
],
"updated_ts": "1557207431323419",
"url": "https://ci.chromium.org/b/8914150972155486576",
"utcnow_ts": "1557207431797303"
}
}
[05:37:11.814] Invocation finished in 2h0m45.68887851s with status FAILED