[22:55:52.285] New invocation is queued and will start shortly
[22:55:53.355] Starting the invocation (attempt 1)
[22:55:53.390] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[22:55:53.390] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[22:55:53.391] Buildbucket request:
{
"bucket": "luci.celab.ci",
"client_operation_id": "9069451825579677600",
"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\":\"47307363e3025b5332266789091ea77d83901ba7\"},\"id\":\"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@47307363e3025b5332266789091ea77d83901ba7\",\"title\":\"47307363e3025b5332266789091ea77d83901ba7\",\"url\":\"https://chromium.googlesource.com/enterprise/cel.git/+/47307363e3025b5332266789091ea77d83901ba7\"}]},\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/enterprise/cel.git\",\"revision\":\"47307363e3025b5332266789091ea77d83901ba7\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Linux",
"scheduler_invocation_id:9069451825579677600",
"scheduler_job_id:celab/Linux",
"user_agent:luci-scheduler",
"buildset:commit/git/47307363e3025b5332266789091ea77d83901ba7",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/47307363e3025b5332266789091ea77d83901ba7",
"gitiles_ref:refs/heads/master"
]
}
[22:55:54.667] Buildbucket response:
{
"build": {
"bucket": "luci.celab.ci",
"canary": true,
"canary_preference": "CANARY",
"created_by": "project:celab",
"created_ts": "1566860153495063",
"id": "8904021763647049856",
"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\": \"47307363e3025b5332266789091ea77d83901ba7\"}, \"id\": \"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@47307363e3025b5332266789091ea77d83901ba7\", \"title\": \"47307363e3025b5332266789091ea77d83901ba7\", \"url\": \"https://chromium.googlesource.com/enterprise/cel.git/+/47307363e3025b5332266789091ea77d83901ba7\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"47307363e3025b5332266789091ea77d83901ba7\"}}",
"project": "celab",
"result_details_json": "{\"properties\": {}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1566860154348188",
"tags": [
"builder:Linux",
"buildset:commit/git/47307363e3025b5332266789091ea77d83901ba7",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/47307363e3025b5332266789091ea77d83901ba7",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9069451825579677600",
"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/8904021763647049856/+/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": "1566860154348318",
"url": "https://ci.chromium.org/b/8904021763647049856",
"utcnow_ts": "1566860154653919"
}
}
[22:55:54.667] Task URL: https://ci.chromium.org/b/8904021763647049856
[22:55:54.667] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:2:0) after 1m0s
[22:55:57.462] Received PubSub notification, asking Buildbucket for the build status
[22:55:57.539] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:56:54.695] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:2:0)
[22:56:54.695] Timer tick, asking Buildbucket for the build status
[22:56:55.255] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:56:55.255] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:4:0) after 1m0s
[22:57:55.324] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:4:0)
[22:57:55.324] Timer tick, asking Buildbucket for the build status
[22:57:56.558] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:57:56.558] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:5:0) after 1m0s
[22:58:56.592] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:5:0)
[22:58:56.592] Timer tick, asking Buildbucket for the build status
[22:58:57.731] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:58:57.731] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:6:0) after 1m0s
[22:59:57.775] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:6:0)
[22:59:57.775] Timer tick, asking Buildbucket for the build status
[22:59:58.086] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:59:58.086] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:7:0) after 1m0s
[23:00:58.122] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:7:0)
[23:00:58.122] Timer tick, asking Buildbucket for the build status
[23:00:58.272] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:00:58.272] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:8:0) after 1m0s
[23:01:58.323] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:8:0)
[23:01:58.323] Timer tick, asking Buildbucket for the build status
[23:01:58.461] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:01:58.461] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:9:0) after 1m0s
[23:02:58.511] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:9:0)
[23:02:58.511] Timer tick, asking Buildbucket for the build status
[23:02:58.899] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:02:58.899] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:10:0) after 1m0s
[23:03:58.932] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:10:0)
[23:03:58.932] Timer tick, asking Buildbucket for the build status
[23:03:59.058] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:03:59.058] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:11:0) after 1m0s
[23:04:59.357] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:11:0)
[23:04:59.357] Timer tick, asking Buildbucket for the build status
[23:04:59.715] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:04:59.715] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:12:0) after 1m0s
[23:06:00.450] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:12:0)
[23:06:00.450] Timer tick, asking Buildbucket for the build status
[23:06:00.706] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:06:00.706] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:13:0) after 1m0s
[23:07:01.121] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:13:0)
[23:07:01.121] Timer tick, asking Buildbucket for the build status
[23:07:01.313] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:07:01.313] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:14:0) after 1m0s
[23:08:01.358] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:14:0)
[23:08:01.358] Timer tick, asking Buildbucket for the build status
[23:08:01.453] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:08:01.453] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:15:0) after 1m0s
[23:09:01.510] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:15:0)
[23:09:01.510] Timer tick, asking Buildbucket for the build status
[23:09:01.686] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:09:01.686] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:16:0) after 1m0s
[23:10:01.833] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:16:0)
[23:10:01.833] Timer tick, asking Buildbucket for the build status
[23:10:02.099] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:10:02.099] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:17:0) after 1m0s
[23:11:02.365] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:17:0)
[23:11:02.365] Timer tick, asking Buildbucket for the build status
[23:11:03.348] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:11:03.348] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:18:0) after 1m0s
[23:12:03.648] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:18:0)
[23:12:03.648] Timer tick, asking Buildbucket for the build status
[23:12:04.275] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:12:04.275] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:19:0) after 1m0s
[23:13:04.545] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:19:0)
[23:13:04.545] Timer tick, asking Buildbucket for the build status
[23:13:04.998] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:13:04.998] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:20:0) after 1m0s
[23:14:05.179] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:20:0)
[23:14:05.179] Timer tick, asking Buildbucket for the build status
[23:14:05.860] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:14:05.860] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:21:0) after 1m0s
[23:15:05.914] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:21:0)
[23:15:05.914] Timer tick, asking Buildbucket for the build status
[23:15:06.150] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:15:06.150] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:22:0) after 1m0s
[23:16:06.306] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:22:0)
[23:16:06.306] Timer tick, asking Buildbucket for the build status
[23:16:06.601] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:16:06.601] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:23:0) after 1m0s
[23:17:06.749] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:23:0)
[23:17:06.749] Timer tick, asking Buildbucket for the build status
[23:17:07.176] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:17:07.176] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:24:0) after 1m0s
[23:18:07.159] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:24:0)
[23:18:07.159] Timer tick, asking Buildbucket for the build status
[23:18:07.260] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:18:07.260] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:25:0) after 1m0s
[23:19:07.325] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:25:0)
[23:19:07.325] Timer tick, asking Buildbucket for the build status
[23:19:07.524] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:19:07.524] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:26:0) after 1m0s
[23:20:07.592] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:26:0)
[23:20:07.592] Timer tick, asking Buildbucket for the build status
[23:20:07.723] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:20:07.723] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:27:0) after 1m0s
[23:21:07.751] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:27:0)
[23:21:07.751] Timer tick, asking Buildbucket for the build status
[23:21:07.888] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:21:07.888] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:28:0) after 1m0s
[23:22:08.043] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:28:0)
[23:22:08.043] Timer tick, asking Buildbucket for the build status
[23:22:08.226] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:22:08.226] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:29:0) after 1m0s
[23:23:08.341] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:29:0)
[23:23:08.341] Timer tick, asking Buildbucket for the build status
[23:23:09.076] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:23:09.076] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:30:0) after 1m0s
[23:24:09.183] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:30:0)
[23:24:09.183] Timer tick, asking Buildbucket for the build status
[23:24:09.537] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:24:09.537] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:31:0) after 1m0s
[23:25:09.712] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:31:0)
[23:25:09.712] Timer tick, asking Buildbucket for the build status
[23:25:09.925] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:25:09.925] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:32:0) after 1m0s
[23:26:09.979] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:32:0)
[23:26:09.979] Timer tick, asking Buildbucket for the build status
[23:26:10.275] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:26:10.275] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:33:0) after 1m0s
[23:27:10.332] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:33:0)
[23:27:10.332] Timer tick, asking Buildbucket for the build status
[23:27:10.646] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:27:10.646] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:34:0) after 1m0s
[23:28:10.728] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:34:0)
[23:28:10.728] Timer tick, asking Buildbucket for the build status
[23:28:11.278] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:28:11.278] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:35:0) after 1m0s
[23:29:11.340] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:35:0)
[23:29:11.340] Timer tick, asking Buildbucket for the build status
[23:29:11.675] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:29:11.675] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:36:0) after 1m0s
[23:30:11.672] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:36:0)
[23:30:11.672] Timer tick, asking Buildbucket for the build status
[23:30:11.898] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:30:11.898] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:37:0) after 1m0s
[23:31:12.039] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:37:0)
[23:31:12.039] Timer tick, asking Buildbucket for the build status
[23:31:12.294] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:31:12.294] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:38:0) after 1m0s
[23:32:12.311] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:38:0)
[23:32:12.311] Timer tick, asking Buildbucket for the build status
[23:32:12.738] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:32:12.738] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:39:0) after 1m0s
[23:33:12.911] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:39:0)
[23:33:12.911] Timer tick, asking Buildbucket for the build status
[23:33:13.215] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:33:13.215] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:40:0) after 1m0s
[23:34:13.302] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:40:0)
[23:34:13.302] Timer tick, asking Buildbucket for the build status
[23:34:13.408] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:34:13.408] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:41:0) after 1m0s
[23:35:13.471] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:41:0)
[23:35:13.471] Timer tick, asking Buildbucket for the build status
[23:35:19.390] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:35:19.390] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:42:0) after 1m0s
[23:36:19.484] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:42:0)
[23:36:19.484] Timer tick, asking Buildbucket for the build status
[23:36:20.620] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:36:20.620] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:43:0) after 1m0s
[23:37:20.772] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:43:0)
[23:37:20.772] Timer tick, asking Buildbucket for the build status
[23:37:20.943] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:37:20.943] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:44:0) after 1m0s
[23:38:21.045] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:44:0)
[23:38:21.045] Timer tick, asking Buildbucket for the build status
[23:38:21.442] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:38:21.442] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:45:0) after 1m0s
[23:39:21.515] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:45:0)
[23:39:21.515] Timer tick, asking Buildbucket for the build status
[23:39:21.814] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:39:21.814] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:46:0) after 1m0s
[23:40:21.881] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:46:0)
[23:40:21.881] Timer tick, asking Buildbucket for the build status
[23:40:22.030] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:40:22.030] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:47:0) after 1m0s
[23:41:22.162] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:47:0)
[23:41:22.162] Timer tick, asking Buildbucket for the build status
[23:41:23.033] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:41:23.033] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:48:0) after 1m0s
[23:42:23.058] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:48:0)
[23:42:23.058] Timer tick, asking Buildbucket for the build status
[23:42:23.382] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:42:23.382] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:49:0) after 1m0s
[23:43:23.371] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:49:0)
[23:43:23.371] Timer tick, asking Buildbucket for the build status
[23:43:23.656] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:43:23.656] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:50:0) after 1m0s
[23:44:23.810] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:50:0)
[23:44:23.810] Timer tick, asking Buildbucket for the build status
[23:44:24.031] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:44:24.031] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:51:0) after 1m0s
[23:45:24.142] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:51:0)
[23:45:24.142] Timer tick, asking Buildbucket for the build status
[23:45:24.984] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:45:24.984] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:52:0) after 1m0s
[23:46:25.109] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:52:0)
[23:46:25.109] Timer tick, asking Buildbucket for the build status
[23:46:25.274] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:46:25.274] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:53:0) after 1m0s
[23:47:25.345] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:53:0)
[23:47:25.345] Timer tick, asking Buildbucket for the build status
[23:47:25.493] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:47:25.493] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:54:0) after 1m0s
[23:48:25.598] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:54:0)
[23:48:25.598] Timer tick, asking Buildbucket for the build status
[23:48:30.703] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:48:30.703] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:55:0) after 1m0s
[23:49:30.727] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:55:0)
[23:49:30.727] Timer tick, asking Buildbucket for the build status
[23:49:31.029] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:49:31.029] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:56:0) after 1m0s
[23:50:31.189] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:56:0)
[23:50:31.189] Timer tick, asking Buildbucket for the build status
[23:50:32.082] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:50:32.082] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:57:0) after 1m0s
[23:51:32.121] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:57:0)
[23:51:32.121] Timer tick, asking Buildbucket for the build status
[23:51:32.364] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:51:32.364] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:58:0) after 1m0s
[23:52:32.435] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:58:0)
[23:52:32.435] Timer tick, asking Buildbucket for the build status
[23:52:32.583] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:52:32.583] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:59:0) after 1m0s
[23:53:32.635] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:59:0)
[23:53:32.635] Timer tick, asking Buildbucket for the build status
[23:53:33.314] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:53:33.314] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:60:0) after 1m0s
[23:54:33.348] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:60:0)
[23:54:33.348] Timer tick, asking Buildbucket for the build status
[23:54:33.715] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:54:33.715] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:61:0) after 1m0s
[23:55:33.750] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:61:0)
[23:55:33.750] Timer tick, asking Buildbucket for the build status
[23:55:33.909] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:55:33.909] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:62:0) after 1m0s
[23:56:33.937] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:62:0)
[23:56:33.937] Timer tick, asking Buildbucket for the build status
[23:56:34.880] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:56:34.880] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:63:0) after 1m0s
[23:57:34.908] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:63:0)
[23:57:34.908] Timer tick, asking Buildbucket for the build status
[23:57:35.020] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:57:35.020] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:64:0) after 1m0s
[23:58:35.022] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:64:0)
[23:58:35.022] Timer tick, asking Buildbucket for the build status
[23:58:35.184] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:58:35.184] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:65:0) after 1m0s
[23:59:35.246] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:65:0)
[23:59:35.246] Timer tick, asking Buildbucket for the build status
[23:59:35.369] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:59:35.369] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:66:0) after 1m0s
[00:00:35.402] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:66:0)
[00:00:35.402] Timer tick, asking Buildbucket for the build status
[00:00:36.478] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[00:00:36.478] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:67:0) after 1m0s
[00:01:36.544] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:67:0)
[00:01:36.544] Timer tick, asking Buildbucket for the build status
[00:01:36.718] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[00:01:36.718] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:68:0) after 1m0s
[00:02:36.783] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:68:0)
[00:02:36.783] Timer tick, asking Buildbucket for the build status
[00:02:36.989] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[00:02:36.989] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:69:0) after 1m0s
[00:03:37.124] Handling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:69:0)
[00:03:37.124] Timer tick, asking Buildbucket for the build status
[00:03:37.262] Build 8904021763647049856: status "STARTED", result "", failure_reason "", cancelation_reason ""
[00:03:37.262] Scheduling timer "check-buildbucket-build-status" (celab/Linux:9069451825579677600:70:0) after 1m0s
[00:04:20.634] Received PubSub notification, asking Buildbucket for the build status
[00:04:20.729] Build 8904021763647049856: status "COMPLETED", result "SUCCESS", failure_reason "", cancelation_reason ""
[00:04:20.729] Buildbucket build:
{
"build": {
"bucket": "luci.celab.ci",
"canary": true,
"canary_preference": "CANARY",
"completed_ts": "1566864259133796",
"created_by": "project:celab",
"created_ts": "1566860153495063",
"id": "8904021763647049856",
"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\": \"47307363e3025b5332266789091ea77d83901ba7\"}, \"id\": \"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@47307363e3025b5332266789091ea77d83901ba7\", \"title\": \"47307363e3025b5332266789091ea77d83901ba7\", \"url\": \"https://chromium.googlesource.com/enterprise/cel.git/+/47307363e3025b5332266789091ea77d83901ba7\"}]}, \"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"47307363e3025b5332266789091ea77d83901ba7\"}}",
"project": "celab",
"result": "SUCCESS",
"result_details_json": "{\"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\": \"47307363e3025b5332266789091ea77d83901ba7\"}, \"id\": \"https://chromium.googlesource.com/enterprise/cel.git/+/refs/heads/master@47307363e3025b5332266789091ea77d83901ba7\", \"title\": \"47307363e3025b5332266789091ea77d83901ba7\", \"url\": \"https://chromium.googlesource.com/enterprise/cel.git/+/47307363e3025b5332266789091ea77d83901ba7\"}]}, \"bot_id\": \"luci-flex-ci-xenial-3-tb6f\", \"branch\": \"refs/heads/master\", \"buildername\": \"Linux\", \"got_revision\": \"47307363e3025b5332266789091ea77d83901ba7\", \"path_config\": \"generic\", \"pool_name\": \"celab-ci\", \"pool_size\": 5.0, \"recipe\": \"celab\", \"repository\": \"https://chromium.googlesource.com/enterprise/cel.git\", \"revision\": \"47307363e3025b5332266789091ea77d83901ba7\", \"target_cpu\": \"x64\", \"tests\": \"*\"}, \"swarming\": {\"bot_dimensions\": {\"cores\": [\"8\"], \"cpu\": [\"x86\", \"x86-64\", \"x86-64-Broadwell_GCE\", \"x86-64-avx2\"], \"gce\": [\"1\"], \"gpu\": [\"none\"], \"id\": [\"luci-flex-ci-xenial-3-tb6f\"], \"image\": [\"chrome-xenial-19052201-9cb74617499\"], \"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\": [\"4397-8786906\"], \"ssd\": [\"0\"], \"zone\": [\"us\", \"us-west\", \"us-west1\", \"us-west1-b\"]}}}",
"service_account": "celab-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"started_ts": "1566860156620514",
"status": "COMPLETED",
"status_changed_ts": "1566864260186023",
"tags": [
"builder:Linux",
"buildset:commit/git/47307363e3025b5332266789091ea77d83901ba7",
"buildset:commit/gitiles/chromium.googlesource.com/enterprise/cel/+/47307363e3025b5332266789091ea77d83901ba7",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9069451825579677600",
"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/8904021763647049856/+/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:46e8f6207e8f2a10",
"user_agent:luci-scheduler"
],
"updated_ts": "1566864260202604",
"url": "https://ci.chromium.org/b/8904021763647049856",
"utcnow_ts": "1566864260720763"
}
}
[00:04:20.729] Invocation finished in 1h8m28.460750009s with status SUCCEEDED