[02:21:11.077] New invocation is queued and will start shortly
[02:21:12.519] Starting the invocation (attempt 1)
[02:21:12.592] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[02:21:12.592] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[02:21:12.592] Buildbucket request:
{
"bucket": "luci.celab.ci",
"client_operation_id": "9062372345014351248",
"parameters_json": "{\"builder_name\":\"Linux\",\"properties\":{\"$recipe_engine/scheduler\":{\"hostname\":\"luci-scheduler.appspot.com\",\"triggers\":[{\"gitiles\":{\"ref\":\"refs/heads/master\",\"repo\":\"https://chromium.googlesource.com/enterprise/cel.git\",\"revision\":\"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"},\"id\":\"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@7832acfdc6c5b9794c04e7dba61cb040223a96fc\",\"title\":\"7832acfdc6c5b9794c04e7dba61cb040223a96fc\",\"url\":\"https://chromium.googlesource.com/enterprise/cel.git/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/enterprise/cel.git\",\"revision\":\"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Linux",
"scheduler_invocation_id:9062372345014351248",
"scheduler_job_id:celab/Linux",
"user_agent:luci-scheduler",
"buildset:commit/git/7832acfdc6c5b9794c04e7dba61cb040223a96fc",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc",
"gitiles_ref:refs/heads/master"
]
}
[02:21:13.503] Buildbucket response:
{
"build": {
"bucket": "luci.celab.ci",
"canary_preference": "PROD",
"created_by": "project:celab",
"created_ts": "1573611672797393",
"id": "8896942282543331168",
"parameters_json": "{\"builder_name\": \"Linux\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}, \"id\": \"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"title\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"url\": \"https://chromium.googlesource.com/enterprise/cel.git/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}}",
"project": "celab",
"result_details_json": "{\"properties\": {}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1573611673222701",
"tags": [
"builder:Linux",
"buildset:commit/git/7832acfdc6c5b9794c04e7dba61cb040223a96fc",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9062372345014351248",
"scheduler_job_id:celab/Linux",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/celab/buildbucket/cr-buildbucket.appspot.com/8896942282543331168/+/annotations",
"swarming_tag:luci_project:celab",
"swarming_tag:recipe_name:celab",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:",
"user_agent:luci-scheduler"
],
"updated_ts": "1573611673222843",
"url": "https://ci.chromium.org/b/8896942282543331168",
"utcnow_ts": "1573611673478970"
}
}
[02:21:13.503] Task URL: https://ci.chromium.org/b/8896942282543331168
[02:21:13.503] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:2:0) after 1m0s
[02:21:35.676] Received PubSub notification, asking Buildbucket for the build status
[02:21:35.829] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:22:13.517] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:2:0)
[02:22:13.517] Timer tick, asking Buildbucket for the build status
[02:22:13.721] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:22:13.721] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:4:0) after 1m0s
[02:23:13.786] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:4:0)
[02:23:13.786] Timer tick, asking Buildbucket for the build status
[02:23:14.136] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:23:14.136] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:5:0) after 1m0s
[02:24:14.155] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:5:0)
[02:24:14.156] Timer tick, asking Buildbucket for the build status
[02:24:14.716] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:24:14.716] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:6:0) after 1m0s
[02:25:14.904] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:6:0)
[02:25:14.904] Timer tick, asking Buildbucket for the build status
[02:25:15.167] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:25:15.168] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:7:0) after 1m0s
[02:26:15.347] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:7:0)
[02:26:15.347] Timer tick, asking Buildbucket for the build status
[02:26:17.057] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:26:17.057] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:8:0) after 1m0s
[02:27:17.069] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:8:0)
[02:27:17.069] Timer tick, asking Buildbucket for the build status
[02:27:17.187] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:27:17.187] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:9:0) after 1m0s
[02:28:17.296] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:9:0)
[02:28:17.296] Timer tick, asking Buildbucket for the build status
[02:28:17.544] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:28:17.544] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:10:0) after 1m0s
[02:29:17.754] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:10:0)
[02:29:17.754] Timer tick, asking Buildbucket for the build status
[02:29:17.888] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:29:17.888] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:11:0) after 1m0s
[02:30:17.988] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:11:0)
[02:30:17.988] Timer tick, asking Buildbucket for the build status
[02:30:18.278] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:30:18.278] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:12:0) after 1m0s
[02:31:18.537] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:12:0)
[02:31:18.538] Timer tick, asking Buildbucket for the build status
[02:31:18.663] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:31:18.663] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:13:0) after 1m0s
[02:32:18.716] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:13:0)
[02:32:18.716] Timer tick, asking Buildbucket for the build status
[02:32:19.239] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:32:19.239] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:14:0) after 1m0s
[02:33:19.295] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:14:0)
[02:33:19.295] Timer tick, asking Buildbucket for the build status
[02:33:19.501] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:33:19.501] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:15:0) after 1m0s
[02:34:19.528] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:15:0)
[02:34:19.528] Timer tick, asking Buildbucket for the build status
[02:34:20.004] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:34:20.004] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:16:0) after 1m0s
[02:35:20.031] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:16:0)
[02:35:20.031] Timer tick, asking Buildbucket for the build status
[02:35:20.278] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:35:20.278] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:17:0) after 1m0s
[02:36:20.349] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:17:0)
[02:36:20.349] Timer tick, asking Buildbucket for the build status
[02:36:21.377] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:36:21.377] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:18:0) after 1m0s
[02:37:21.400] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:18:0)
[02:37:21.400] Timer tick, asking Buildbucket for the build status
[02:37:21.761] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:37:21.761] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:19:0) after 1m0s
[02:38:21.797] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:19:0)
[02:38:21.797] Timer tick, asking Buildbucket for the build status
[02:38:21.960] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:38:21.960] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:20:0) after 1m0s
[02:39:22.005] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:20:0)
[02:39:22.005] Timer tick, asking Buildbucket for the build status
[02:39:24.202] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:39:24.202] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:21:0) after 1m0s
[02:40:24.235] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:21:0)
[02:40:24.235] Timer tick, asking Buildbucket for the build status
[02:40:25.116] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:40:25.116] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:22:0) after 1m0s
[02:41:25.175] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:22:0)
[02:41:25.175] Timer tick, asking Buildbucket for the build status
[02:41:26.707] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:41:26.707] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:23:0) after 1m0s
[02:42:26.801] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:23:0)
[02:42:26.801] Timer tick, asking Buildbucket for the build status
[02:42:27.109] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:42:27.109] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:24:0) after 1m0s
[02:43:27.134] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:24:0)
[02:43:27.134] Timer tick, asking Buildbucket for the build status
[02:43:27.498] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:43:27.498] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:25:0) after 1m0s
[02:44:27.519] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:25:0)
[02:44:27.519] Timer tick, asking Buildbucket for the build status
[02:44:28.971] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:44:28.971] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:26:0) after 1m0s
[02:45:29.130] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:26:0)
[02:45:29.131] Timer tick, asking Buildbucket for the build status
[02:45:29.544] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:45:29.544] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:27:0) after 1m0s
[02:46:29.697] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:27:0)
[02:46:29.697] Timer tick, asking Buildbucket for the build status
[02:46:31.282] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:46:31.282] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:28:0) after 1m0s
[02:47:31.338] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:28:0)
[02:47:31.338] Timer tick, asking Buildbucket for the build status
[02:47:32.581] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:47:32.581] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:29:0) after 1m0s
[02:48:32.615] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:29:0)
[02:48:32.615] Timer tick, asking Buildbucket for the build status
[02:48:33.810] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:48:33.810] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:30:0) after 1m0s
[02:49:33.835] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:30:0)
[02:49:33.835] Timer tick, asking Buildbucket for the build status
[02:49:34.988] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:49:34.988] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:31:0) after 1m0s
[02:50:35.073] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:31:0)
[02:50:35.073] Timer tick, asking Buildbucket for the build status
[02:50:35.997] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:50:35.997] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:32:0) after 1m0s
[02:51:36.056] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:32:0)
[02:51:36.056] Timer tick, asking Buildbucket for the build status
[02:51:36.264] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:51:36.264] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:33:0) after 1m0s
[02:52:36.294] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:33:0)
[02:52:36.294] Timer tick, asking Buildbucket for the build status
[02:52:36.510] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:52:36.510] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:34:0) after 1m0s
[02:53:36.536] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:34:0)
[02:53:36.536] Timer tick, asking Buildbucket for the build status
[02:53:36.866] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:53:36.866] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:35:0) after 1m0s
[02:54:36.954] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:35:0)
[02:54:36.954] Timer tick, asking Buildbucket for the build status
[02:54:37.358] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:54:37.358] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:36:0) after 1m0s
[02:55:37.475] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:36:0)
[02:55:37.475] Timer tick, asking Buildbucket for the build status
[02:55:37.668] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:55:37.668] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:37:0) after 1m0s
[02:56:37.724] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:37:0)
[02:56:37.724] Timer tick, asking Buildbucket for the build status
[02:56:41.384] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:56:41.384] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:38:0) after 1m0s
[02:57:41.460] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:38:0)
[02:57:41.460] Timer tick, asking Buildbucket for the build status
[02:57:42.743] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:57:42.743] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:39:0) after 1m0s
[02:58:42.785] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:39:0)
[02:58:42.785] Timer tick, asking Buildbucket for the build status
[02:58:43.013] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:58:43.013] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:40:0) after 1m0s
[02:59:43.063] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:40:0)
[02:59:43.063] Timer tick, asking Buildbucket for the build status
[02:59:43.155] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:59:43.155] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:41:0) after 1m0s
[03:00:43.219] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:41:0)
[03:00:43.219] Timer tick, asking Buildbucket for the build status
[03:00:44.134] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:00:44.134] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:42:0) after 1m0s
[03:01:44.263] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:42:0)
[03:01:44.263] Timer tick, asking Buildbucket for the build status
[03:01:44.509] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:01:44.509] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:43:0) after 1m0s
[03:02:44.553] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:43:0)
[03:02:44.553] Timer tick, asking Buildbucket for the build status
[03:02:44.911] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:02:44.911] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:44:0) after 1m0s
[03:03:44.899] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:44:0)
[03:03:44.899] Timer tick, asking Buildbucket for the build status
[03:03:46.451] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:03:46.451] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:45:0) after 1m0s
[03:04:46.618] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:45:0)
[03:04:46.618] Timer tick, asking Buildbucket for the build status
[03:04:46.802] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:04:46.802] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:46:0) after 1m0s
[03:05:46.828] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:46:0)
[03:05:46.828] Timer tick, asking Buildbucket for the build status
[03:05:47.106] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:05:47.106] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:47:0) after 1m0s
[03:06:47.349] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:47:0)
[03:06:47.349] Timer tick, asking Buildbucket for the build status
[03:06:47.443] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:06:47.443] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:48:0) after 1m0s
[03:07:47.520] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:48:0)
[03:07:47.520] Timer tick, asking Buildbucket for the build status
[03:07:48.486] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:07:48.486] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:49:0) after 1m0s
[03:08:48.612] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:49:0)
[03:08:48.612] Timer tick, asking Buildbucket for the build status
[03:08:48.819] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:08:48.819] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:50:0) after 1m0s
[03:09:48.943] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:50:0)
[03:09:48.943] Timer tick, asking Buildbucket for the build status
[03:09:50.098] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:09:50.098] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:51:0) after 1m0s
[03:10:50.169] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:51:0)
[03:10:50.169] Timer tick, asking Buildbucket for the build status
[03:10:50.409] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:10:50.409] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:52:0) after 1m0s
[03:11:50.513] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:52:0)
[03:11:50.513] Timer tick, asking Buildbucket for the build status
[03:11:52.331] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:11:52.331] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:53:0) after 1m0s
[03:12:52.357] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:53:0)
[03:12:52.357] Timer tick, asking Buildbucket for the build status
[03:12:52.510] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:12:52.510] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:54:0) after 1m0s
[03:13:52.584] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:54:0)
[03:13:52.585] Timer tick, asking Buildbucket for the build status
[03:13:52.836] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:13:52.836] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:55:0) after 1m0s
[03:14:52.872] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:55:0)
[03:14:52.872] Timer tick, asking Buildbucket for the build status
[03:14:54.205] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:14:54.205] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:56:0) after 1m0s
[03:15:54.328] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:56:0)
[03:15:54.328] Timer tick, asking Buildbucket for the build status
[03:15:57.394] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:15:57.394] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:57:0) after 1m0s
[03:16:57.774] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:57:0)
[03:16:57.774] Timer tick, asking Buildbucket for the build status
[03:16:57.891] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:16:57.891] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:58:0) after 1m0s
[03:17:58.065] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:58:0)
[03:17:58.065] Timer tick, asking Buildbucket for the build status
[03:17:58.322] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:17:58.323] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:59:0) after 1m0s
[03:18:58.496] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:59:0)
[03:18:58.496] Timer tick, asking Buildbucket for the build status
[03:18:58.679] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:18:58.679] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:60:0) after 1m0s
[03:19:58.851] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:60:0)
[03:19:58.851] Timer tick, asking Buildbucket for the build status
[03:19:59.088] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:19:59.088] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:61:0) after 1m0s
[03:20:59.295] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:61:0)
[03:20:59.295] Timer tick, asking Buildbucket for the build status
[03:20:59.964] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:20:59.964] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:62:0) after 1m0s
[03:22:00.193] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:62:0)
[03:22:00.193] Timer tick, asking Buildbucket for the build status
[03:22:01.436] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:22:01.436] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:63:0) after 1m0s
[03:23:01.463] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:63:0)
[03:23:01.463] Timer tick, asking Buildbucket for the build status
[03:23:01.941] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:23:01.941] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:64:0) after 1m0s
[03:24:02.031] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:64:0)
[03:24:02.031] Timer tick, asking Buildbucket for the build status
[03:24:03.540] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:24:03.540] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:65:0) after 1m0s
[03:25:03.663] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:65:0)
[03:25:03.663] Timer tick, asking Buildbucket for the build status
[03:25:03.860] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:25:03.860] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:66:0) after 1m0s
[03:26:03.894] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:66:0)
[03:26:03.894] Timer tick, asking Buildbucket for the build status
[03:26:04.555] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:26:04.555] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:67:0) after 1m0s
[03:27:04.583] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:67:0)
[03:27:04.583] Timer tick, asking Buildbucket for the build status
[03:27:05.901] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:27:05.901] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:68:0) after 1m0s
[03:28:05.918] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:68:0)
[03:28:05.918] Timer tick, asking Buildbucket for the build status
[03:28:06.619] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:28:06.619] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:69:0) after 1m0s
[03:29:06.696] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:69:0)
[03:29:06.696] Timer tick, asking Buildbucket for the build status
[03:29:08.366] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:29:08.366] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:70:0) after 1m0s
[03:30:08.420] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:70:0)
[03:30:08.420] Timer tick, asking Buildbucket for the build status
[03:30:08.649] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:30:08.649] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:71:0) after 1m0s
[03:31:08.721] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:71:0)
[03:31:08.721] Timer tick, asking Buildbucket for the build status
[03:31:09.994] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:31:09.994] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:72:0) after 1m0s
[03:32:10.110] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:72:0)
[03:32:10.110] Timer tick, asking Buildbucket for the build status
[03:32:10.325] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:32:10.325] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:73:0) after 1m0s
[03:33:10.430] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:73:0)
[03:33:10.430] Timer tick, asking Buildbucket for the build status
[03:33:10.572] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:33:10.572] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:74:0) after 1m0s
[03:34:10.551] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:74:0)
[03:34:10.551] Timer tick, asking Buildbucket for the build status
[03:34:10.811] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:34:10.811] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:75:0) after 1m0s
[03:35:10.910] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:75:0)
[03:35:10.911] Timer tick, asking Buildbucket for the build status
[03:35:11.334] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:35:11.334] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:76:0) after 1m0s
[03:36:11.443] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:76:0)
[03:36:11.443] Timer tick, asking Buildbucket for the build status
[03:36:14.725] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:36:14.725] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:77:0) after 1m0s
[03:37:14.737] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:77:0)
[03:37:14.737] Timer tick, asking Buildbucket for the build status
[03:37:15.398] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:37:15.399] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:78:0) after 1m0s
[03:38:15.468] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:78:0)
[03:38:15.468] Timer tick, asking Buildbucket for the build status
[03:38:15.845] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:38:15.845] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:79:0) after 1m0s
[03:39:15.881] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:79:0)
[03:39:15.881] Timer tick, asking Buildbucket for the build status
[03:39:16.593] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:39:16.593] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:80:0) after 1m0s
[03:40:16.636] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:80:0)
[03:40:16.636] Timer tick, asking Buildbucket for the build status
[03:40:17.185] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:40:17.185] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:81:0) after 1m0s
[03:41:17.222] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:81:0)
[03:41:17.222] Timer tick, asking Buildbucket for the build status
[03:41:17.642] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:41:17.642] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:82:0) after 1m0s
[03:42:17.676] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:82:0)
[03:42:17.676] Timer tick, asking Buildbucket for the build status
[03:42:18.398] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:42:18.398] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:83:0) after 1m0s
[03:43:18.435] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:83:0)
[03:43:18.435] Timer tick, asking Buildbucket for the build status
[03:43:19.896] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:43:19.896] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:84:0) after 1m0s
[03:44:20.012] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:84:0)
[03:44:20.012] Timer tick, asking Buildbucket for the build status
[03:44:20.592] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:44:20.592] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:85:0) after 1m0s
[03:45:20.618] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:85:0)
[03:45:20.618] Timer tick, asking Buildbucket for the build status
[03:45:21.455] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:45:21.455] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:86:0) after 1m0s
[03:46:21.480] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:86:0)
[03:46:21.480] Timer tick, asking Buildbucket for the build status
[03:46:21.752] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:46:21.752] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:87:0) after 1m0s
[03:47:21.735] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:87:0)
[03:47:21.735] Timer tick, asking Buildbucket for the build status
[03:47:21.850] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:47:21.850] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:88:0) after 1m0s
[03:48:21.881] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:88:0)
[03:48:21.881] Timer tick, asking Buildbucket for the build status
[03:48:22.057] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:48:22.057] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:89:0) after 1m0s
[03:49:22.104] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:89:0)
[03:49:22.104] Timer tick, asking Buildbucket for the build status
[03:49:22.465] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:49:22.465] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:90:0) after 1m0s
[03:50:22.511] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:90:0)
[03:50:22.511] Timer tick, asking Buildbucket for the build status
[03:50:22.776] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:50:22.776] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:91:0) after 1m0s
[03:51:22.828] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:91:0)
[03:51:22.828] Timer tick, asking Buildbucket for the build status
[03:51:23.273] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:51:23.273] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:92:0) after 1m0s
[03:52:23.299] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:92:0)
[03:52:23.299] Timer tick, asking Buildbucket for the build status
[03:52:23.559] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:52:23.559] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:93:0) after 1m0s
[03:53:24.011] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:93:0)
[03:53:24.011] Timer tick, asking Buildbucket for the build status
[03:53:24.371] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:53:24.371] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:94:0) after 1m0s
[03:54:24.387] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:94:0)
[03:54:24.387] Timer tick, asking Buildbucket for the build status
[03:54:24.646] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:54:24.646] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:95:0) after 1m0s
[03:55:24.740] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:95:0)
[03:55:24.740] Timer tick, asking Buildbucket for the build status
[03:55:25.031] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:55:25.031] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:96:0) after 1m0s
[03:56:25.067] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:96:0)
[03:56:25.067] Timer tick, asking Buildbucket for the build status
[03:56:25.421] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:56:25.421] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:97:0) after 1m0s
[03:57:25.452] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:97:0)
[03:57:25.452] Timer tick, asking Buildbucket for the build status
[03:57:25.786] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:57:25.786] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:98:0) after 1m0s
[03:58:25.817] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:98:0)
[03:58:25.817] Timer tick, asking Buildbucket for the build status
[03:58:26.069] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:58:26.069] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:99:0) after 1m0s
[03:59:26.122] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:99:0)
[03:59:26.122] Timer tick, asking Buildbucket for the build status
[03:59:26.912] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[03:59:26.912] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:100:0) after 1m0s
[04:00:27.034] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:100:0)
[04:00:27.034] Timer tick, asking Buildbucket for the build status
[04:00:27.538] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:00:27.538] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:101:0) after 1m0s
[04:01:27.947] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:101:0)
[04:01:27.947] Timer tick, asking Buildbucket for the build status
[04:01:28.055] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:01:28.055] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:102:0) after 1m0s
[04:02:28.474] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:102:0)
[04:02:28.474] Timer tick, asking Buildbucket for the build status
[04:02:29.753] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:02:29.753] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:103:0) after 1m0s
[04:03:30.176] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:103:0)
[04:03:30.176] Timer tick, asking Buildbucket for the build status
[04:03:32.008] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:03:32.008] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:104:0) after 1m0s
[04:04:32.229] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:104:0)
[04:04:32.229] Timer tick, asking Buildbucket for the build status
[04:04:32.402] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:04:32.402] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:105:0) after 1m0s
[04:05:32.608] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:105:0)
[04:05:32.608] Timer tick, asking Buildbucket for the build status
[04:05:33.035] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:05:33.035] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:106:0) after 1m0s
[04:06:33.120] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:106:0)
[04:06:33.120] Timer tick, asking Buildbucket for the build status
[04:06:37.882] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:06:37.882] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:107:0) after 1m0s
[04:07:37.925] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:107:0)
[04:07:37.925] Timer tick, asking Buildbucket for the build status
[04:07:39.713] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:07:39.713] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:108:0) after 1m0s
[04:08:39.978] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:108:0)
[04:08:39.978] Timer tick, asking Buildbucket for the build status
[04:08:40.211] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:08:40.211] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:109:0) after 1m0s
[04:09:40.539] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:109:0)
[04:09:40.539] Timer tick, asking Buildbucket for the build status
[04:09:40.705] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:09:40.705] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:110:0) after 1m0s
[04:10:40.974] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:110:0)
[04:10:40.974] Timer tick, asking Buildbucket for the build status
[04:10:41.246] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:10:41.246] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:111:0) after 1m0s
[04:11:41.443] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:111:0)
[04:11:41.443] Timer tick, asking Buildbucket for the build status
[04:11:42.029] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:11:42.029] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:112:0) after 1m0s
[04:12:42.175] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:112:0)
[04:12:42.175] Timer tick, asking Buildbucket for the build status
[04:12:42.377] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:12:42.377] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:113:0) after 1m0s
[04:13:42.601] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:113:0)
[04:13:42.601] Timer tick, asking Buildbucket for the build status
[04:13:42.785] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:13:42.785] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:114:0) after 1m0s
[04:14:43.065] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:114:0)
[04:14:43.065] Timer tick, asking Buildbucket for the build status
[04:14:44.265] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:14:44.265] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:115:0) after 1m0s
[04:15:44.499] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:115:0)
[04:15:44.499] Timer tick, asking Buildbucket for the build status
[04:15:44.613] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:15:44.613] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:116:0) after 1m0s
[04:16:44.797] Handling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:116:0)
[04:16:44.797] Timer tick, asking Buildbucket for the build status
[04:16:44.934] Build 8896942282543331168: status "STARTED", result "", failure_reason "", cancelation_reason ""
[04:16:44.934] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9062372345014351248:117:0) after 1m0s
[04:16:51.848] Received PubSub notification, asking Buildbucket for the build status
[04:16:51.966] Build 8896942282543331168: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[04:16:51.966] Buildbucket build:
{
"build": {
"bucket": "luci.celab.ci",
"canary_preference": "PROD",
"completed_ts": "1573618611456136",
"created_by": "project:celab",
"created_ts": "1573611672797393",
"failure_reason": "BUILD_FAILURE",
"id": "8896942282543331168",
"parameters_json": "{\"builder_name\": \"Linux\", \"properties\": {\"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}, \"id\": \"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"title\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"url\": \"https://chromium.googlesource.com/enterprise/cel.git/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}}",
"project": "celab",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step('run all tests') (retcode: 1)\"}, \"properties\": {\"$recipe_engine/path\": {\"cache_dir\": \"/b/s/w/ir/cache\", \"temp_dir\": \"/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"$recipe_engine/scheduler\": {\"hostname\": \"luci-scheduler.appspot.com\", \"triggers\": [{\"gitiles\": {\"ref\": \"refs/heads/master\", \"repo\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}, \"id\": \"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"title\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"url\": \"https://chromium.googlesource.com/enterprise/cel.git/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc\"}]}, \"bot_id\": \"luci-flex-ci-xenial-6-efxw\", \"branch\": \"refs/heads/master\", \"buildername\": \"Linux\", \"got_revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"path_config\": \"generic\", \"pool_name\": \"celab-ci\", \"pool_size\": 5.0, \"recipe\": \"celab\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"7832acfdc6c5b9794c04e7dba61cb040223a96fc\", \"target_cpu\": \"x64\", \"tests\": \"*\"}, \"swarming\": {\"bot_dimensions\": {\"caches\": [\"builder_510fe9a959fb6845ae4ece89b65dac460a600e94b8c166b9bb45da605730688a_v2\", \"builder_7ea55abfea25d314356d803a5f0ad62170c3dfd6004ffb0ffd94b75873d1ce3b_v2\", \"builder_a00b1023121ea85e703f19c9cb4a0ba6469d60176e935a395f443f8a2c5759bb_v2\", \"builder_b21fc2474b74a202903fba65fd8166899cce4d46f0d8adaea07be83158cf5611_v2\", \"builder_f58e49d4978dd47022c74d62848afbffa29b3ee52aa79f0e76d160631af2bf15_v2\", \"git\", \"goma_v2\", \"infra_gclient_with_go\", \"vpython\"], \"cores\": [\"8\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gpu\": [\"none\"], \"id\": [\"luci-flex-ci-xenial-6-efxw\"], \"image\": [\"chrome-xenial-19102400-d35fedf5a0d\"], \"inside_docker\": [\"0\"], \"kvm\": [\"1\"], \"locale\": [\"en_US.UTF-8\"], \"machine_type\": [\"n1-standard-8\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16.04\"], \"pool\": [\"luci.flex.ci\"], \"python\": [\"2.7.12\"], \"server_version\": [\"4621-f8a5b1c\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-west\", \"us-west1\", \"us-west1-b\"]}}, \"ui\": {\"info\": \"Step('run all tests') (retcode: 1)\"}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1573611694689648",
"status": "COMPLETED",
"status_changed_ts": "1573611695313703",
"tags": [
"builder:Linux",
"buildset:commit/git/7832acfdc6c5b9794c04e7dba61cb040223a96fc",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/7832acfdc6c5b9794c04e7dba61cb040223a96fc",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9062372345014351248",
"scheduler_job_id:celab/Linux",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/celab/buildbucket/cr-buildbucket.appspot.com/8896942282543331168/+/annotations",
"swarming_tag:luci_project:celab",
"swarming_tag:os:Linux",
"swarming_tag:recipe_name:celab",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:487b62675c2e8410",
"user_agent:luci-scheduler"
],
"updated_ts": "1573618611595629",
"url": "https://ci.chromium.org/b/8896942282543331168",
"utcnow_ts": "1573618611956452"
}
}
[04:16:51.966] Invocation finished in 1h55m40.910009499s with status FAILED