[19:47:36.357] New invocation is queued and will start shortly
[19:47:37.717] Starting the invocation (attempt 1)
[19:47:37.761] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[19:47:37.761] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[19:47:37.761] Buildbucket request:
{
"bucket": "luci.celab.ci",
"client_operation_id": "9087583063499796960",
"parameters_json": "{\"builder_name\":\"Linux\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/enterprise/cel.git\",\"revision\":\"6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Linux",
"scheduler_invocation_id:9087583063499796960",
"scheduler_job_id:celab/Linux",
"user_agent:luci-scheduler",
"buildset:commit/git/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a",
"gitiles_ref:refs/heads/master"
]
}
[19:47:38.936] Buildbucket response:
{
"build": {
"bucket": "luci.celab.ci",
"canary_preference": "AUTO",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1549568857861503",
"id": "8922153001258155328",
"lease_expiration_ts": "1549687658521710",
"lease_key": "881392794",
"parameters_json": "{\"builder_name\": \"Linux\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\"}}",
"project": "celab",
"result_details_json": "{\"properties\": {}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1549568858665221",
"tags": [
"builder:Linux",
"buildset:commit/git/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9087583063499796960",
"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/8922153001258155328/+/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:42e251e091cbfe10",
"user_agent:luci-scheduler"
],
"updated_ts": "1549568858665350",
"url": "https://ci.chromium.org/b/8922153001258155328",
"utcnow_ts": "1549568858927631"
}
}
[19:47:38.936] Task URL: https://ci.chromium.org/b/8922153001258155328
[19:47:38.936] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:2:0) after 1m0s
[19:47:54.249] Received PubSub notification, asking Buildbucket for the build status
[19:47:54.368] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:48:38.961] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:2:0)
[19:48:38.961] Timer tick, asking Buildbucket for the build status
[19:48:39.290] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:48:39.290] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:4:0) after 1m0s
[19:49:39.316] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:4:0)
[19:49:39.316] Timer tick, asking Buildbucket for the build status
[19:49:39.568] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:49:39.568] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:5:0) after 1m0s
[19:50:39.591] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:5:0)
[19:50:39.591] Timer tick, asking Buildbucket for the build status
[19:50:39.681] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:50:39.682] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:6:0) after 1m0s
[19:51:39.782] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:6:0)
[19:51:39.782] Timer tick, asking Buildbucket for the build status
[19:51:39.905] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:51:39.905] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:7:0) after 1m0s
[19:52:39.924] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:7:0)
[19:52:39.924] Timer tick, asking Buildbucket for the build status
[19:52:39.974] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:52:39.974] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:8:0) after 1m0s
[19:53:39.992] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:8:0)
[19:53:39.992] Timer tick, asking Buildbucket for the build status
[19:53:40.178] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:53:40.178] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:9:0) after 1m0s
[19:54:40.198] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:9:0)
[19:54:40.198] Timer tick, asking Buildbucket for the build status
[19:54:40.260] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:54:40.260] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:10:0) after 1m0s
[19:55:40.295] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:10:0)
[19:55:40.295] Timer tick, asking Buildbucket for the build status
[19:55:40.419] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:55:40.419] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:11:0) after 1m0s
[19:56:40.432] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:11:0)
[19:56:40.432] Timer tick, asking Buildbucket for the build status
[19:56:40.587] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:56:40.587] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:12:0) after 1m0s
[19:57:40.612] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:12:0)
[19:57:40.612] Timer tick, asking Buildbucket for the build status
[19:57:40.695] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:57:40.695] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:13:0) after 1m0s
[19:58:40.719] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:13:0)
[19:58:40.719] Timer tick, asking Buildbucket for the build status
[19:58:40.864] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:58:40.864] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:14:0) after 1m0s
[19:59:40.904] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:14:0)
[19:59:40.904] Timer tick, asking Buildbucket for the build status
[19:59:40.981] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[19:59:40.981] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:15:0) after 1m0s
[20:00:41.017] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:15:0)
[20:00:41.017] Timer tick, asking Buildbucket for the build status
[20:00:41.080] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:00:41.080] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:16:0) after 1m0s
[20:01:41.218] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:16:0)
[20:01:41.218] Timer tick, asking Buildbucket for the build status
[20:01:41.575] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:01:41.575] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:17:0) after 1m0s
[20:02:41.610] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:17:0)
[20:02:41.610] Timer tick, asking Buildbucket for the build status
[20:02:41.833] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:02:41.833] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:18:0) after 1m0s
[20:03:41.916] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:18:0)
[20:03:41.916] Timer tick, asking Buildbucket for the build status
[20:03:41.970] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:03:41.970] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:19:0) after 1m0s
[20:04:42.157] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:19:0)
[20:04:42.157] Timer tick, asking Buildbucket for the build status
[20:04:42.436] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:04:42.436] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:20:0) after 1m0s
[20:05:42.458] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:20:0)
[20:05:42.458] Timer tick, asking Buildbucket for the build status
[20:05:42.747] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:05:42.747] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:21:0) after 1m0s
[20:06:42.785] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:21:0)
[20:06:42.785] Timer tick, asking Buildbucket for the build status
[20:06:42.854] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:06:42.854] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:22:0) after 1m0s
[20:07:42.877] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:22:0)
[20:07:42.877] Timer tick, asking Buildbucket for the build status
[20:07:42.948] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:07:42.948] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:23:0) after 1m0s
[20:08:42.967] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:23:0)
[20:08:42.967] Timer tick, asking Buildbucket for the build status
[20:08:43.019] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:08:43.019] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:24:0) after 1m0s
[20:09:43.047] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:24:0)
[20:09:43.047] Timer tick, asking Buildbucket for the build status
[20:09:43.115] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:09:43.115] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:25:0) after 1m0s
[20:10:43.137] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:25:0)
[20:10:43.137] Timer tick, asking Buildbucket for the build status
[20:10:43.207] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:10:43.207] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:26:0) after 1m0s
[20:11:43.228] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:26:0)
[20:11:43.228] Timer tick, asking Buildbucket for the build status
[20:11:43.299] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:11:43.299] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:27:0) after 1m0s
[20:12:43.323] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:27:0)
[20:12:43.323] Timer tick, asking Buildbucket for the build status
[20:12:43.373] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:12:43.373] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:28:0) after 1m0s
[20:13:43.396] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:28:0)
[20:13:43.396] Timer tick, asking Buildbucket for the build status
[20:13:43.594] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:13:43.594] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:29:0) after 1m0s
[20:14:43.637] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:29:0)
[20:14:43.637] Timer tick, asking Buildbucket for the build status
[20:14:43.791] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:14:43.791] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:30:0) after 1m0s
[20:15:43.815] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:30:0)
[20:15:43.815] Timer tick, asking Buildbucket for the build status
[20:15:43.929] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:15:43.929] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:31:0) after 1m0s
[20:16:43.952] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:31:0)
[20:16:43.952] Timer tick, asking Buildbucket for the build status
[20:16:44.067] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:16:44.067] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:32:0) after 1m0s
[20:17:44.101] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:32:0)
[20:17:44.101] Timer tick, asking Buildbucket for the build status
[20:17:44.159] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:17:44.159] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:33:0) after 1m0s
[20:18:44.182] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:33:0)
[20:18:44.182] Timer tick, asking Buildbucket for the build status
[20:18:44.237] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:18:44.237] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:34:0) after 1m0s
[20:19:44.269] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:34:0)
[20:19:44.269] Timer tick, asking Buildbucket for the build status
[20:19:44.332] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:19:44.332] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:35:0) after 1m0s
[20:20:44.367] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:35:0)
[20:20:44.367] Timer tick, asking Buildbucket for the build status
[20:20:44.548] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:20:44.548] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:36:0) after 1m0s
[20:21:44.565] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:36:0)
[20:21:44.565] Timer tick, asking Buildbucket for the build status
[20:21:44.624] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:21:44.624] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:37:0) after 1m0s
[20:22:44.646] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:37:0)
[20:22:44.646] Timer tick, asking Buildbucket for the build status
[20:22:44.772] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:22:44.772] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:38:0) after 1m0s
[20:23:44.790] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:38:0)
[20:23:44.790] Timer tick, asking Buildbucket for the build status
[20:23:45.063] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:23:45.063] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:39:0) after 1m0s
[20:24:45.146] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:39:0)
[20:24:45.146] Timer tick, asking Buildbucket for the build status
[20:24:45.208] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:24:45.208] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:40:0) after 1m0s
[20:25:45.234] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:40:0)
[20:25:45.234] Timer tick, asking Buildbucket for the build status
[20:25:45.296] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:25:45.296] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:41:0) after 1m0s
[20:26:45.317] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:41:0)
[20:26:45.317] Timer tick, asking Buildbucket for the build status
[20:26:45.494] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:26:45.494] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:42:0) after 1m0s
[20:27:45.512] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:42:0)
[20:27:45.512] Timer tick, asking Buildbucket for the build status
[20:27:45.561] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:27:45.561] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:43:0) after 1m0s
[20:28:45.588] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:43:0)
[20:28:45.588] Timer tick, asking Buildbucket for the build status
[20:28:45.699] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:28:45.699] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:44:0) after 1m0s
[20:29:45.719] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:44:0)
[20:29:45.719] Timer tick, asking Buildbucket for the build status
[20:29:45.868] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:29:45.868] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:45:0) after 1m0s
[20:30:45.911] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:45:0)
[20:30:45.911] Timer tick, asking Buildbucket for the build status
[20:30:45.977] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:30:45.977] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:46:0) after 1m0s
[20:31:45.999] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:46:0)
[20:31:45.999] Timer tick, asking Buildbucket for the build status
[20:31:46.045] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:31:46.045] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:47:0) after 1m0s
[20:32:46.068] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:47:0)
[20:32:46.068] Timer tick, asking Buildbucket for the build status
[20:32:46.148] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:32:46.148] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:48:0) after 1m0s
[20:33:46.292] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:48:0)
[20:33:46.292] Timer tick, asking Buildbucket for the build status
[20:33:46.346] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:33:46.346] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:49:0) after 1m0s
[20:34:46.369] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:49:0)
[20:34:46.369] Timer tick, asking Buildbucket for the build status
[20:34:46.426] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:34:46.426] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:50:0) after 1m0s
[20:35:46.483] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:50:0)
[20:35:46.483] Timer tick, asking Buildbucket for the build status
[20:35:46.674] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:35:46.674] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:51:0) after 1m0s
[20:36:46.701] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:51:0)
[20:36:46.701] Timer tick, asking Buildbucket for the build status
[20:36:46.873] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:36:46.873] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:52:0) after 1m0s
[20:37:46.920] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:52:0)
[20:37:46.920] Timer tick, asking Buildbucket for the build status
[20:37:47.102] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:37:47.102] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:53:0) after 1m0s
[20:38:47.201] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:53:0)
[20:38:47.201] Timer tick, asking Buildbucket for the build status
[20:38:47.275] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:38:47.275] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:54:0) after 1m0s
[20:39:47.342] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:54:0)
[20:39:47.342] Timer tick, asking Buildbucket for the build status
[20:39:47.398] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:39:47.398] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:55:0) after 1m0s
[20:40:47.470] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:55:0)
[20:40:47.470] Timer tick, asking Buildbucket for the build status
[20:40:47.652] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:40:47.652] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:56:0) after 1m0s
[20:41:47.695] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:56:0)
[20:41:47.695] Timer tick, asking Buildbucket for the build status
[20:41:47.749] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:41:47.749] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:57:0) after 1m0s
[20:42:47.773] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:57:0)
[20:42:47.773] Timer tick, asking Buildbucket for the build status
[20:42:48.043] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:42:48.043] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:58:0) after 1m0s
[20:43:48.095] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:58:0)
[20:43:48.095] Timer tick, asking Buildbucket for the build status
[20:43:48.164] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:43:48.165] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:59:0) after 1m0s
[20:44:48.222] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:59:0)
[20:44:48.222] Timer tick, asking Buildbucket for the build status
[20:44:48.309] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:44:48.309] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:60:0) after 1m0s
[20:45:48.336] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:60:0)
[20:45:48.336] Timer tick, asking Buildbucket for the build status
[20:45:48.481] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:45:48.481] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:61:0) after 1m0s
[20:46:48.546] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:61:0)
[20:46:48.546] Timer tick, asking Buildbucket for the build status
[20:46:48.685] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:46:48.685] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:62:0) after 1m0s
[20:47:48.725] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:62:0)
[20:47:48.725] Timer tick, asking Buildbucket for the build status
[20:47:48.780] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:47:48.780] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:63:0) after 1m0s
[20:48:48.801] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:63:0)
[20:48:48.802] Timer tick, asking Buildbucket for the build status
[20:48:48.885] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:48:48.885] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:64:0) after 1m0s
[20:49:48.978] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:64:0)
[20:49:48.978] Timer tick, asking Buildbucket for the build status
[20:49:49.164] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:49:49.164] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:65:0) after 1m0s
[20:50:49.193] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:65:0)
[20:50:49.193] Timer tick, asking Buildbucket for the build status
[20:50:49.242] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:50:49.242] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:66:0) after 1m0s
[20:51:49.273] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:66:0)
[20:51:49.273] Timer tick, asking Buildbucket for the build status
[20:51:49.390] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:51:49.390] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:67:0) after 1m0s
[20:52:49.421] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:67:0)
[20:52:49.421] Timer tick, asking Buildbucket for the build status
[20:52:49.574] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:52:49.574] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:68:0) after 1m0s
[20:53:49.597] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:68:0)
[20:53:49.597] Timer tick, asking Buildbucket for the build status
[20:53:49.647] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:53:49.647] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:69:0) after 1m0s
[20:54:49.668] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:69:0)
[20:54:49.668] Timer tick, asking Buildbucket for the build status
[20:54:49.857] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:54:49.857] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:70:0) after 1m0s
[20:55:49.880] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:70:0)
[20:55:49.880] Timer tick, asking Buildbucket for the build status
[20:55:49.973] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:55:49.973] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:71:0) after 1m0s
[20:56:50.003] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:71:0)
[20:56:50.003] Timer tick, asking Buildbucket for the build status
[20:56:50.205] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:56:50.205] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:72:0) after 1m0s
[20:57:50.251] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:72:0)
[20:57:50.251] Timer tick, asking Buildbucket for the build status
[20:57:50.306] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:57:50.306] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:73:0) after 1m0s
[20:58:50.368] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:73:0)
[20:58:50.368] Timer tick, asking Buildbucket for the build status
[20:58:50.415] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:58:50.415] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:74:0) after 1m0s
[20:59:50.452] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:74:0)
[20:59:50.452] Timer tick, asking Buildbucket for the build status
[20:59:50.513] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[20:59:50.513] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:75:0) after 1m0s
[21:00:50.535] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:75:0)
[21:00:50.535] Timer tick, asking Buildbucket for the build status
[21:00:50.781] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:00:50.781] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:76:0) after 1m0s
[21:01:50.824] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:76:0)
[21:01:50.824] Timer tick, asking Buildbucket for the build status
[21:01:50.990] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:01:50.990] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:77:0) after 1m0s
[21:02:51.072] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:77:0)
[21:02:51.072] Timer tick, asking Buildbucket for the build status
[21:02:51.165] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:02:51.165] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:78:0) after 1m0s
[21:03:51.192] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:78:0)
[21:03:51.193] Timer tick, asking Buildbucket for the build status
[21:03:51.373] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:03:51.373] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:79:0) after 1m0s
[21:07:01.586] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:79:0)
[21:07:01.586] Timer tick, asking Buildbucket for the build status
[21:07:01.640] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:07:01.640] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:80:0) after 1m0s
[21:08:01.731] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:80:0)
[21:08:01.731] Timer tick, asking Buildbucket for the build status
[21:08:01.786] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:08:01.786] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:81:0) after 1m0s
[21:09:01.852] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:81:0)
[21:09:01.852] Timer tick, asking Buildbucket for the build status
[21:09:01.927] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:09:01.927] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:82:0) after 1m0s
[21:10:01.971] Handling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:82:0)
[21:10:01.971] Timer tick, asking Buildbucket for the build status
[21:10:02.093] Build 8922153001258155328: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:10:02.093] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9087583063499796960:83:0) after 1m0s
[21:10:55.530] Received PubSub notification, asking Buildbucket for the build status
[21:10:55.575] Build 8922153001258155328: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[21:10:55.575] Buildbucket build:
{
"build": {
"bucket": "luci.celab.ci",
"canary_preference": "AUTO",
"completed_ts": "1549573854356877",
"created_by": "user:luci-scheduler@appspot.gserviceaccount.com",
"created_ts": "1549568857861503",
"id": "8922153001258155328",
"parameters_json": "{\"builder_name\": \"Linux\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\"}}",
"project": "celab",
"result": "SUCCESS",
"result_details_json": "{\"swarming\": {\"bot_dimensions\": {\"gce\": [\"0\"], \"zone\": [\"us\", \"us-golo\", \"us-golo-1\"], \"inside_docker\": [\"0\"], \"locale\": [\"en_US.ISO8859-1\"], \"kvm\": [\"0\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-E5-2670\"], \"python\": [\"2.7.12\"], \"server_version\": [\"4064-3687a02\"], \"machine_type\": [\"n1-highcpu-8\"], \"gpu\": [\"none\"], \"cores\": [\"8\"], \"os\": [\"Linux\", \"Ubuntu\", \"Ubuntu-16.04\"], \"id\": [\"vm78-m1\"], \"pool\": [\"luci.flex.ci\"], \"caches\": [\"git\", \"goma_v2\", \"infra_gclient_with_go\", \"vpython\"]}}, \"ui\": {\"info\": \"\"}, \"properties\": {\"$recipe_engine/path\": {\"cache_dir\": \"/mnt/data/b/s/w/ir/cache\", \"temp_dir\": \"/mnt/data/b/s/w/ir/tmp/rt\"}, \"target_cpu\": \"x64\", \"$recipe_engine/buildbucket\": {\"build\": {\"tags\": [{\"value\": \"Linux\", \"key\": \"builder\"}, {\"value\": \"commit/git/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\", \"key\": \"buildset\"}, {\"value\": \"commit/gitiles/chromium.googlesource.com/enterprise/cel/+/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\", \"key\": \"buildset\"}, {\"value\": \"9087583063499796960\", \"key\": \"scheduler_invocation_id\"}, {\"value\": \"celab/Linux\", \"key\": \"scheduler_job_id\"}, {\"value\": \"luci-scheduler\", \"key\": \"user_agent\"}], \"builder\": {\"project\": \"celab\", \"builder\": \"Linux\", \"bucket\": \"ci\"}, \"infra\": {\"buildbucket\": {\"serviceConfigRevision\": \"ef156230f5cd7f8c23f689fa4dc7f92742cd904d\"}, \"recipe\": {\"name\": \"celab\", \"cipdPackage\": \"infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build\"}, \"swarming\": {\"hostname\": \"chromium-swarm.appspot.com\"}}, \"createdBy\": \"user:luci-scheduler@appspot.gserviceaccount.com\", \"id\": \"8922153001258155328\", \"input\": {\"gitilesCommit\": {\"project\": \"enterprise/cel\", \"host\": \"chromium.googlesource.com\", \"ref\": \"refs/heads/master\", \"id\": \"6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\"}}, \"createTime\": \"2019-02-07T19:47:37.861503Z\"}}, \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"buildername\": \"Linux\", \"got_revision\": \"6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\", \"recipe\": \"celab\", \"$recipe_engine/runtime\": {\"is_experimental\": false, \"is_luci\": true}, \"buildbucket\": {\"hostname\": \"cr-buildbucket.appspot.com\", \"build\": {\"created_ts\": 1549568857861503, \"tags\": [\"builder:Linux\", \"buildset:commit/git/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\", \"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\", \"gitiles_ref:refs/heads/master\", \"scheduler_invocation_id:9087583063499796960\", \"scheduler_job_id:celab/Linux\", \"user_agent:luci-scheduler\"], \"bucket\": \"luci.celab.ci\", \"created_by\": \"user:luci-scheduler@appspot.gserviceaccount.com\", \"project\": \"celab\", \"id\": \"8922153001258155328\"}}, \"branch\": \"refs/heads/master\", \"path_config\": \"generic\", \"revision\": \"6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a\", \"bot_id\": \"vm78-m1\"}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1549568873656127",
"status": "COMPLETED",
"status_changed_ts": "1549573855051637",
"tags": [
"builder:Linux",
"buildset:commit/git/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/6a9b7ff459f47f4ab2ca57eaebc3e03f9bf5f75a",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9087583063499796960",
"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/8922153001258155328/+/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:42e251e091cbfe10",
"user_agent:luci-scheduler"
],
"updated_ts": "1549573855052986",
"url": "https://ci.chromium.org/b/8922153001258155328",
"utcnow_ts": "1549573855565688"
}
}
[21:10:55.575] Invocation finished in 1h23m19.235872935s with status SUCCEEDED