[15:17:56.254] New invocation is queued and will start shortly
[15:17:57.310] Starting the invocation (attempt 1)
[15:17:57.348] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:17:57.349] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:17:57.349] Buildbucket request:
{
"bucket": "luci.celab.ci",
"client_operation_id": "9080080481355482096",
"parameters_json": "{\"builder_name\":\"Linux\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/enterprise/cel.git\",\"revision\":\"857170f266293e360f39af6889e9afa0611be975\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Linux",
"scheduler_invocation_id:9080080481355482096",
"scheduler_job_id:celab/Linux",
"user_agent:luci-scheduler",
"buildset:commit/git/857170f266293e360f39af6889e9afa0611be975",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/857170f266293e360f39af6889e9afa0611be975",
"gitiles_ref:refs/heads/master"
]
}
[15:17:58.372] Buildbucket response:
{
"build": {
"bucket": "luci.celab.ci",
"canary_preference": "AUTO",
"created_by": "project:celab",
"created_ts": "1556723877466233",
"id": "8914650419420987024",
"parameters_json": "{\"builder_name\": \"Linux\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"857170f266293e360f39af6889e9afa0611be975\"}}",
"project": "celab",
"result_details_json": "{\"properties\": {}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1556723877940184",
"tags": [
"builder:Linux",
"buildset:commit/git/857170f266293e360f39af6889e9afa0611be975",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/857170f266293e360f39af6889e9afa0611be975",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9080080481355482096",
"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/8914650419420987024/+/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": "1556723877940309",
"url": "https://ci.chromium.org/b/8914650419420987024",
"utcnow_ts": "1556723878365743"
}
}
[15:17:58.372] Task URL: https://ci.chromium.org/b/8914650419420987024
[15:17:58.373] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:2:0) after 1m0s
[15:18:32.533] Received PubSub notification, asking Buildbucket for the build status
[15:18:32.603] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:18:58.393] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:2:0)
[15:18:58.393] Timer tick, asking Buildbucket for the build status
[15:18:58.468] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:18:58.468] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:4:0) after 1m0s
[15:19:58.488] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:4:0)
[15:19:58.488] Timer tick, asking Buildbucket for the build status
[15:19:58.566] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:19:58.566] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:5:0) after 1m0s
[15:20:58.583] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:5:0)
[15:20:58.583] Timer tick, asking Buildbucket for the build status
[15:20:58.678] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:20:58.678] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:6:0) after 1m0s
[15:21:58.672] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:6:0)
[15:21:58.672] Timer tick, asking Buildbucket for the build status
[15:21:58.968] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:21:58.968] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:7:0) after 1m0s
[15:22:58.987] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:7:0)
[15:22:58.987] Timer tick, asking Buildbucket for the build status
[15:22:59.148] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:22:59.148] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:8:0) after 1m0s
[15:23:59.167] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:8:0)
[15:23:59.167] Timer tick, asking Buildbucket for the build status
[15:23:59.228] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:23:59.228] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:9:0) after 1m0s
[15:24:59.233] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:9:0)
[15:24:59.233] Timer tick, asking Buildbucket for the build status
[15:24:59.297] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:24:59.297] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:10:0) after 1m0s
[15:25:59.363] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:10:0)
[15:25:59.363] Timer tick, asking Buildbucket for the build status
[15:25:59.421] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:25:59.421] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:11:0) after 1m0s
[15:26:59.443] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:11:0)
[15:26:59.443] Timer tick, asking Buildbucket for the build status
[15:26:59.502] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:26:59.502] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:12:0) after 1m0s
[15:27:59.521] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:12:0)
[15:27:59.521] Timer tick, asking Buildbucket for the build status
[15:27:59.574] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:27:59.574] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:13:0) after 1m0s
[15:28:59.601] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:13:0)
[15:28:59.602] Timer tick, asking Buildbucket for the build status
[15:28:59.778] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:28:59.778] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:14:0) after 1m0s
[15:29:59.832] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:14:0)
[15:29:59.832] Timer tick, asking Buildbucket for the build status
[15:29:59.966] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:29:59.966] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:15:0) after 1m0s
[15:30:59.991] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:15:0)
[15:30:59.991] Timer tick, asking Buildbucket for the build status
[15:31:00.177] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:31:00.177] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:16:0) after 1m0s
[15:32:00.223] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:16:0)
[15:32:00.223] Timer tick, asking Buildbucket for the build status
[15:32:00.294] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:32:00.294] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:17:0) after 1m0s
[15:33:00.275] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:17:0)
[15:33:00.275] Timer tick, asking Buildbucket for the build status
[15:33:00.376] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:33:00.376] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:18:0) after 1m0s
[15:34:00.386] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:18:0)
[15:34:00.386] Timer tick, asking Buildbucket for the build status
[15:34:00.429] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:34:00.429] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:19:0) after 1m0s
[15:35:00.413] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:19:0)
[15:35:00.413] Timer tick, asking Buildbucket for the build status
[15:35:00.802] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:35:00.802] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:20:0) after 1m0s
[15:36:00.928] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:20:0)
[15:36:00.928] Timer tick, asking Buildbucket for the build status
[15:36:03.533] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:36:03.533] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:21:0) after 1m0s
[15:37:03.531] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:21:0)
[15:37:03.532] Timer tick, asking Buildbucket for the build status
[15:37:03.800] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:37:03.800] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:22:0) after 1m0s
[15:38:03.827] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:22:0)
[15:38:03.827] Timer tick, asking Buildbucket for the build status
[15:38:03.891] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:38:03.891] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:23:0) after 1m0s
[15:39:03.910] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:23:0)
[15:39:03.910] Timer tick, asking Buildbucket for the build status
[15:39:03.954] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:39:03.954] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:24:0) after 1m0s
[15:40:03.938] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:24:0)
[15:40:03.938] Timer tick, asking Buildbucket for the build status
[15:40:04.003] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:40:04.003] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:25:0) after 1m0s
[15:41:04.034] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:25:0)
[15:41:04.034] Timer tick, asking Buildbucket for the build status
[15:41:04.474] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:41:04.474] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:26:0) after 1m0s
[15:42:04.496] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:26:0)
[15:42:04.496] Timer tick, asking Buildbucket for the build status
[15:42:04.774] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:42:04.774] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:27:0) after 1m0s
[15:43:04.803] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:27:0)
[15:43:04.803] Timer tick, asking Buildbucket for the build status
[15:43:05.084] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:43:05.084] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:28:0) after 1m0s
[15:44:05.092] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:28:0)
[15:44:05.092] Timer tick, asking Buildbucket for the build status
[15:44:05.218] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:44:05.218] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:29:0) after 1m0s
[15:45:05.229] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:29:0)
[15:45:05.229] Timer tick, asking Buildbucket for the build status
[15:45:05.276] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:45:05.276] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:30:0) after 1m0s
[15:46:05.281] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:30:0)
[15:46:05.281] Timer tick, asking Buildbucket for the build status
[15:46:05.362] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:46:05.362] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:31:0) after 1m0s
[15:47:05.345] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:31:0)
[15:47:05.345] Timer tick, asking Buildbucket for the build status
[15:47:05.747] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:47:05.747] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:32:0) after 1m0s
[15:48:05.768] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:32:0)
[15:48:05.768] Timer tick, asking Buildbucket for the build status
[15:48:05.931] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:48:05.931] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:33:0) after 1m0s
[15:49:05.960] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:33:0)
[15:49:05.960] Timer tick, asking Buildbucket for the build status
[15:49:06.033] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:49:06.033] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:34:0) after 1m0s
[15:50:06.029] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:34:0)
[15:50:06.029] Timer tick, asking Buildbucket for the build status
[15:50:06.151] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:50:06.151] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:35:0) after 1m0s
[15:51:06.136] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:35:0)
[15:51:06.136] Timer tick, asking Buildbucket for the build status
[15:51:06.527] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:51:06.527] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:36:0) after 1m0s
[15:52:06.561] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:36:0)
[15:52:06.561] Timer tick, asking Buildbucket for the build status
[15:52:06.607] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:52:06.607] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:37:0) after 1m0s
[15:53:06.623] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:37:0)
[15:53:06.623] Timer tick, asking Buildbucket for the build status
[15:53:06.695] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:53:06.695] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:38:0) after 1m0s
[15:54:06.719] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:38:0)
[15:54:06.719] Timer tick, asking Buildbucket for the build status
[15:54:07.770] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:54:07.770] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:39:0) after 1m0s
[15:55:07.791] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:39:0)
[15:55:07.791] Timer tick, asking Buildbucket for the build status
[15:55:07.841] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:55:07.841] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:40:0) after 1m0s
[15:56:07.865] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:40:0)
[15:56:07.865] Timer tick, asking Buildbucket for the build status
[15:56:07.931] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:56:07.931] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:41:0) after 1m0s
[15:57:07.930] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:41:0)
[15:57:07.930] Timer tick, asking Buildbucket for the build status
[15:57:07.982] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:57:07.982] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:42:0) after 1m0s
[15:58:08.008] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:42:0)
[15:58:08.008] Timer tick, asking Buildbucket for the build status
[15:58:08.205] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:58:08.205] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:43:0) after 1m0s
[15:59:08.221] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:43:0)
[15:59:08.221] Timer tick, asking Buildbucket for the build status
[15:59:08.268] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[15:59:08.268] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:44:0) after 1m0s
[16:00:08.289] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:44:0)
[16:00:08.289] Timer tick, asking Buildbucket for the build status
[16:00:08.343] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:00:08.343] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:45:0) after 1m0s
[16:01:08.364] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:45:0)
[16:01:08.364] Timer tick, asking Buildbucket for the build status
[16:01:13.252] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:01:13.252] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:46:0) after 1m0s
[16:02:13.275] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:46:0)
[16:02:13.275] Timer tick, asking Buildbucket for the build status
[16:02:13.362] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:02:13.362] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:47:0) after 1m0s
[16:03:13.387] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:47:0)
[16:03:13.387] Timer tick, asking Buildbucket for the build status
[16:03:13.558] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:03:13.558] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:48:0) after 1m0s
[16:04:13.575] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:48:0)
[16:04:13.575] Timer tick, asking Buildbucket for the build status
[16:04:13.667] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:04:13.667] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:49:0) after 1m0s
[16:05:13.658] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:49:0)
[16:05:13.658] Timer tick, asking Buildbucket for the build status
[16:05:13.705] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:05:13.705] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:50:0) after 1m0s
[16:06:13.737] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:50:0)
[16:06:13.737] Timer tick, asking Buildbucket for the build status
[16:06:13.825] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:06:13.825] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:51:0) after 1m0s
[16:07:13.827] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:51:0)
[16:07:13.827] Timer tick, asking Buildbucket for the build status
[16:07:13.871] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:07:13.871] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:52:0) after 1m0s
[16:08:13.858] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:52:0)
[16:08:13.858] Timer tick, asking Buildbucket for the build status
[16:08:13.971] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:08:13.971] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:53:0) after 1m0s
[16:09:13.984] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:53:0)
[16:09:13.984] Timer tick, asking Buildbucket for the build status
[16:09:14.134] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:09:14.134] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:54:0) after 1m0s
[16:10:14.147] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:54:0)
[16:10:14.147] Timer tick, asking Buildbucket for the build status
[16:10:14.206] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:10:14.206] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:55:0) after 1m0s
[16:11:14.229] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:55:0)
[16:11:14.229] Timer tick, asking Buildbucket for the build status
[16:11:14.361] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:11:14.361] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:56:0) after 1m0s
[16:12:14.395] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:56:0)
[16:12:14.395] Timer tick, asking Buildbucket for the build status
[16:12:14.484] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:12:14.484] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:57:0) after 1m0s
[16:13:14.508] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:57:0)
[16:13:14.508] Timer tick, asking Buildbucket for the build status
[16:13:14.548] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:13:14.548] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:58:0) after 1m0s
[16:14:14.571] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:58:0)
[16:14:14.571] Timer tick, asking Buildbucket for the build status
[16:14:14.638] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:14:14.638] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:59:0) after 1m0s
[16:15:14.624] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:59:0)
[16:15:14.624] Timer tick, asking Buildbucket for the build status
[16:15:14.673] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:15:14.673] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:60:0) after 1m0s
[16:16:14.678] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:60:0)
[16:16:14.678] Timer tick, asking Buildbucket for the build status
[16:16:14.732] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:16:14.733] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:61:0) after 1m0s
[16:17:14.761] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:61:0)
[16:17:14.761] Timer tick, asking Buildbucket for the build status
[16:17:14.829] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:17:14.829] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:62:0) after 1m0s
[16:18:14.838] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:62:0)
[16:18:14.838] Timer tick, asking Buildbucket for the build status
[16:18:15.007] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:18:15.007] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:63:0) after 1m0s
[16:19:15.009] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:63:0)
[16:19:15.009] Timer tick, asking Buildbucket for the build status
[16:19:15.082] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:19:15.082] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:64:0) after 1m0s
[16:20:15.106] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:64:0)
[16:20:15.106] Timer tick, asking Buildbucket for the build status
[16:20:15.198] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:20:15.198] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:65:0) after 1m0s
[16:21:15.311] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:65:0)
[16:21:15.311] Timer tick, asking Buildbucket for the build status
[16:21:15.458] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:21:15.458] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:66:0) after 1m0s
[16:22:15.481] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:66:0)
[16:22:15.481] Timer tick, asking Buildbucket for the build status
[16:22:15.554] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:22:15.554] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:67:0) after 1m0s
[16:23:15.557] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:67:0)
[16:23:15.557] Timer tick, asking Buildbucket for the build status
[16:23:15.651] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:23:15.651] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:68:0) after 1m0s
[16:24:15.726] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:68:0)
[16:24:15.726] Timer tick, asking Buildbucket for the build status
[16:24:15.765] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:24:15.765] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:69:0) after 1m0s
[16:25:15.770] Handling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:69:0)
[16:25:15.770] Timer tick, asking Buildbucket for the build status
[16:25:15.827] Build 8914650419420987024: status "STARTED", result "", failure_reason "", cancelation_reason ""
[16:25:15.827] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9080080481355482096:70:0) after 1m0s
[16:26:04.805] Received PubSub notification, asking Buildbucket for the build status
[16:26:04.991] Build 8914650419420987024: status "COMPLETED", result "FAILURE", failure_reason "BUILD_FAILURE", cancelation_reason ""
[16:26:04.991] Buildbucket build:
{
"build": {
"bucket": "luci.celab.ci",
"canary_preference": "AUTO",
"completed_ts": "1556727964043651",
"created_by": "project:celab",
"created_ts": "1556723877466233",
"failure_reason": "BUILD_FAILURE",
"id": "8914650419420987024",
"parameters_json": "{\"builder_name\": \"Linux\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"857170f266293e360f39af6889e9afa0611be975\"}}",
"project": "celab",
"result": "FAILURE",
"result_details_json": "{\"error\": {\"message\": \"Step('run all tests') failed with return_code 1\"}, \"properties\": {\"$recipe_engine/path\": {\"cache_dir\": \"/mnt/data/b/s/w/ir/cache\", \"temp_dir\": \"/mnt/data/b/s/w/ir/tmp/rt\"}, \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"bot_id\": \"vm78-m1\", \"branch\": \"refs/heads/master\", \"buildername\": \"Linux\", \"got_revision\": \"857170f266293e360f39af6889e9afa0611be975\", \"path_config\": \"generic\", \"recipe\": \"celab\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"857170f266293e360f39af6889e9afa0611be975\", \"target_cpu\": \"x64\"}, \"swarming\": {\"bot_dimensions\": {\"caches\": [\"git\", \"goma_v2\", \"infra_gclient_with_go\", \"vpython\"], \"cores\": [\"8\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-E5-2670\"], \"gce\": [\"0\"], \"gpu\": [\"none\"], \"id\": [\"vm78-m1\"], \"inside_docker\": [\"0\"], \"kvm\": [\"0\"], \"locale\": [\"en_US.ISO8859-1\"], \"machine_type\": [\"n1-highcpu-8\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16.04\"], \"pool\": [\"luci.flex.ci\"], \"python\": [\"2.7.12\"], \"server_version\": [\"4277-e1590cf\"], \"zone\": [\"us\", \"us-golo\", \"us-golo-1\"]}}, \"ui\": {\"info\": \"Step('run all tests') failed with return_code 1\"}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1556723912040501",
"status": "COMPLETED",
"status_changed_ts": "1556723912321190",
"tags": [
"builder:Linux",
"buildset:commit/git/857170f266293e360f39af6889e9afa0611be975",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/857170f266293e360f39af6889e9afa0611be975",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9080080481355482096",
"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/8914650419420987024/+/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:448ccad5c3d89410",
"user_agent:luci-scheduler"
],
"updated_ts": "1556727964206902",
"url": "https://ci.chromium.org/b/8914650419420987024",
"utcnow_ts": "1556727964974528"
}
}
[16:26:04.991] Invocation finished in 1h8m8.75475676s with status FAILED