[17:01:12.816] New invocation is queued and will start shortly
[17:01:14.003] Starting the invocation (attempt 1)
[17:01:14.039] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[17:01:14.039] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[17:01:14.039] Buildbucket request:
{
"bucket": "luci.chromium.ci",
"client_operation_id": "9017562076971300096",
"parameters_json": "{\"builder_name\":\"linux-chromeos-rel\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/chromium/src\",\"revision\":\"e87d2578d26830baf1572d9ca77e748af3046f2c\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux-chromeos-rel",
"scheduler_invocation_id:9017562076971300096",
"scheduler_job_id:chromium/linux-chromeos-rel",
"user_agent:luci-scheduler",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/e87d2578d26830baf1572d9ca77e748af3046f2c",
"gitiles_ref:refs/heads/master"
]
}
[17:01:14.940] Buildbucket response:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "PROD",
"created_by": "project:chromium",
"created_ts": "1616346074159499",
"id": "8852132014900492448",
"parameters_json": "{\"builder_name\": \"linux-chromeos-rel\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src\", \"revision\": \"e87d2578d26830baf1572d9ca77e748af3046f2c\"}}",
"project": "chromium",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1616346074745375",
"tags": [
"build_address:luci.chromium.ci/linux-chromeos-rel/46307",
"builder:linux-chromeos-rel",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/e87d2578d26830baf1572d9ca77e748af3046f2c",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9017562076971300096",
"scheduler_job_id:chromium/linux-chromeos-rel",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8852132014900492448/+/annotations",
"swarming_tag:luci_project:chromium",
"swarming_tag:recipe_name:chromium",
"swarming_tag:recipe_package:infra/recipe_bundles/chromium.googlesource.com/chromium/tools/build",
"swarming_task_id:",
"user_agent:luci-scheduler"
],
"updated_ts": "1616346074745529",
"url": "https://ci.chromium.org/b/8852132014900492448",
"utcnow_ts": "1616346074929136"
}
}
[17:01:14.940] Task URL: https://ci.chromium.org/b/8852132014900492448
[17:01:14.940] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:2:0) after 1m0s
[17:02:14.940] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:2:0)
[17:02:14.965] Build status: SCHEDULED
[17:02:14.965] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:3:0) after 5m57s
[17:08:12.034] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:3:0)
[17:08:12.060] Build status: SCHEDULED
[17:08:12.060] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:4:0) after 8m3s
[17:16:15.079] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:4:0)
[17:16:15.079] Timer tick, asking Buildbucket for the build status
[17:16:15.175] Build 8852132014900492448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:16:15.175] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:5:0) after 1m0s
[17:17:15.635] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:5:0)
[17:17:15.672] Build status: SCHEDULED
[17:17:15.672] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:6:0) after 3m21s
[17:20:36.688] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:6:0)
[17:20:36.688] Timer tick, asking Buildbucket for the build status
[17:20:36.773] Build 8852132014900492448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:20:36.773] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:7:0) after 1m0s
[17:21:36.789] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:7:0)
[17:21:36.789] Timer tick, asking Buildbucket for the build status
[17:21:36.872] Build 8852132014900492448: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[17:21:36.872] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:8:0) after 1m0s
[17:22:36.887] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:8:0)
[17:22:36.912] Build status: SCHEDULED
[17:22:36.912] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:9:0) after 5m22s
[17:23:25.898] Received PubSub notification, asking Buildbucket for the build status
[17:23:26.085] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:27:58.939] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:9:0)
[17:27:58.963] Build status: STARTED
[17:27:58.963] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:11:0) after 6m27s
[17:34:26.143] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:11:0)
[17:34:26.143] Timer tick, asking Buildbucket for the build status
[17:34:26.245] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:34:26.245] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:12:0) after 1m0s
[17:35:26.315] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:12:0)
[17:35:26.341] Build status: STARTED
[17:35:26.341] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:13:0) after 2m6s
[17:37:32.382] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:13:0)
[17:37:32.382] Timer tick, asking Buildbucket for the build status
[17:37:32.621] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:37:32.621] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:14:0) after 1m0s
[17:38:32.726] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:14:0)
[17:38:32.758] Build status: STARTED
[17:38:32.758] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:15:0) after 5m9s
[17:43:41.815] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:15:0)
[17:43:41.840] Build status: STARTED
[17:43:41.840] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:16:0) after 6m54s
[17:50:35.857] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:16:0)
[17:50:35.857] Timer tick, asking Buildbucket for the build status
[17:50:35.946] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:50:35.946] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:17:0) after 1m0s
[17:51:35.971] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:17:0)
[17:51:36.043] Build status: STARTED
[17:51:36.043] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:18:0) after 2m34s
[17:54:10.059] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:18:0)
[17:54:10.059] Timer tick, asking Buildbucket for the build status
[17:54:10.221] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:54:10.221] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:19:0) after 1m0s
[17:55:10.238] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:19:0)
[17:55:10.238] Timer tick, asking Buildbucket for the build status
[17:55:10.416] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:55:10.416] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:20:0) after 1m0s
[17:56:10.439] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:20:0)
[17:56:10.439] Timer tick, asking Buildbucket for the build status
[17:56:10.522] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:56:10.523] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:21:0) after 1m0s
[17:57:10.540] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:21:0)
[17:57:10.540] Timer tick, asking Buildbucket for the build status
[17:57:10.611] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[17:57:10.611] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:22:0) after 1m0s
[17:58:10.668] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:22:0)
[17:58:10.697] Build status: STARTED
[17:58:10.697] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:23:0) after 6m32s
[18:04:42.746] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:23:0)
[18:04:42.772] Build status: STARTED
[18:04:42.772] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:24:0) after 6m0s
[18:10:42.915] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:24:0)
[18:10:42.970] Build status: STARTED
[18:10:42.970] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:25:0) after 5m41s
[18:16:24.090] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:25:0)
[18:16:24.119] Build status: STARTED
[18:16:24.119] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:26:0) after 7m43s
[18:24:07.133] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:26:0)
[18:24:07.161] Build status: STARTED
[18:24:07.161] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:27:0) after 1m54s
[18:26:01.162] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:27:0)
[18:26:01.162] Timer tick, asking Buildbucket for the build status
[18:26:01.242] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:26:01.242] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:28:0) after 1m0s
[18:27:01.400] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:28:0)
[18:27:01.425] Build status: STARTED
[18:27:01.425] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:29:0) after 6m1s
[18:33:02.540] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:29:0)
[18:33:02.540] Timer tick, asking Buildbucket for the build status
[18:33:02.704] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:33:02.704] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:30:0) after 1m0s
[18:34:02.816] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:30:0)
[18:34:02.816] Timer tick, asking Buildbucket for the build status
[18:34:03.225] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:34:03.225] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:31:0) after 1m0s
[18:35:03.362] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:31:0)
[18:35:03.362] Timer tick, asking Buildbucket for the build status
[18:35:03.517] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:35:03.517] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:32:0) after 1m0s
[18:36:03.539] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:32:0)
[18:36:03.567] Build status: STARTED
[18:36:03.567] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:33:0) after 8m37s
[18:44:40.584] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:33:0)
[18:44:40.584] Timer tick, asking Buildbucket for the build status
[18:44:40.823] Build 8852132014900492448: status "STARTED", result "", failure_reason "", cancelation_reason ""
[18:44:40.823] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:34:0) after 1m0s
[18:45:40.894] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:34:0)
[18:45:40.930] Build status: STARTED
[18:45:40.930] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-rel:9017562076971300096:35:0) after 5m53s
[18:50:15.333] Received PubSub notification, asking Buildbucket for the build status
[18:50:15.363] Build:
{
"id": "8852132014900492448",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-chromeos-rel"
},
"number": 46307,
"createdBy": "project:chromium",
"createTime": "2021-03-21T17:01:14.159499Z",
"startTime": "2021-03-21T17:23:25.455807Z",
"endTime": "2021-03-21T18:50:12.260619Z",
"updateTime": "2021-03-21T18:50:12.571033Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "e87d2578d26830baf1572d9ca77e748af3046f2c",
"ref": "refs/heads/master"
}
}
}
[18:50:15.363] Invocation finished in 1h49m2.562619645s with status SUCCEEDED