[21:23:24.948] New invocation is queued and will start shortly
[21:23:26.054] Starting the invocation (attempt 1)
[21:23:26.100] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:23:26.100] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:23:26.100] Buildbucket request:
{
"bucket": "luci.chromium.ci",
"client_operation_id": "9017726774568668592",
"parameters_json": "{\"builder_name\":\"linux-chromeos-dbg\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/chromium/src\",\"revision\":\"d989e155f30604ea895ba08912a6adcfa43b5ebf\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:linux-chromeos-dbg",
"scheduler_invocation_id:9017726774568668592",
"scheduler_job_id:chromium/linux-chromeos-dbg",
"user_agent:luci-scheduler",
"buildset:commit/git/d989e155f30604ea895ba08912a6adcfa43b5ebf",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/d989e155f30604ea895ba08912a6adcfa43b5ebf",
"gitiles_ref:refs/heads/master"
]
}
[21:23:26.795] Buildbucket response:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "PROD",
"created_by": "project:chromium",
"created_ts": "1616189006239653",
"id": "8852296712551738560",
"parameters_json": "{\"builder_name\": \"linux-chromeos-dbg\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src\", \"revision\": \"d989e155f30604ea895ba08912a6adcfa43b5ebf\"}}",
"project": "chromium",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1616189006653871",
"tags": [
"build_address:luci.chromium.ci/linux-chromeos-dbg/23053",
"builder:linux-chromeos-dbg",
"buildset:commit/git/d989e155f30604ea895ba08912a6adcfa43b5ebf",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/d989e155f30604ea895ba08912a6adcfa43b5ebf",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9017726774568668592",
"scheduler_job_id:chromium/linux-chromeos-dbg",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8852296712551738560/+/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": "1616189006653975",
"url": "https://ci.chromium.org/b/8852296712551738560",
"utcnow_ts": "1616189006787994"
}
}
[21:23:26.795] Task URL: https://ci.chromium.org/b/8852296712551738560
[21:23:26.795] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:2:0) after 1m0s
[21:24:26.896] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:2:0)
[21:24:26.896] Timer tick, asking Buildbucket for the build status
[21:24:26.975] Build 8852296712551738560: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[21:24:26.975] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:3:0) after 1m0s
[21:25:26.998] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:3:0)
[21:25:27.024] Build status: SCHEDULED
[21:25:27.024] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:4:0) after 6m24s
[21:27:11.022] Received PubSub notification, asking Buildbucket for the build status
[21:27:11.048] Build status: STARTED
[21:31:51.182] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:4:0)
[21:31:51.182] Timer tick, asking Buildbucket for the build status
[21:31:51.272] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:31:51.272] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:6:0) after 1m0s
[21:32:51.246] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:6:0)
[21:32:51.289] Build status: STARTED
[21:32:51.289] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:7:0) after 1m9s
[21:34:00.302] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:7:0)
[21:34:00.302] Timer tick, asking Buildbucket for the build status
[21:34:00.400] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:34:00.400] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:8:0) after 1m0s
[21:35:00.412] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:8:0)
[21:35:00.447] Build status: STARTED
[21:35:00.447] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:9:0) after 9m39s
[21:44:39.432] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:9:0)
[21:44:39.432] Timer tick, asking Buildbucket for the build status
[21:44:39.517] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:44:39.517] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:10:0) after 1m0s
[21:45:39.621] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:10:0)
[21:45:39.621] Timer tick, asking Buildbucket for the build status
[21:45:39.844] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:45:39.844] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:11:0) after 1m0s
[21:46:39.924] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:11:0)
[21:46:39.950] Build status: STARTED
[21:46:39.950] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:12:0) after 7m37s
[21:54:16.977] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:12:0)
[21:54:16.977] Timer tick, asking Buildbucket for the build status
[21:54:17.071] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:54:17.071] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:13:0) after 1m0s
[21:55:17.091] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:13:0)
[21:55:17.091] Timer tick, asking Buildbucket for the build status
[21:55:17.221] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:55:17.221] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:14:0) after 1m0s
[21:56:17.264] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:14:0)
[21:56:17.264] Timer tick, asking Buildbucket for the build status
[21:56:17.340] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:56:17.340] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:15:0) after 1m0s
[21:57:17.421] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:15:0)
[21:57:17.421] Timer tick, asking Buildbucket for the build status
[21:57:17.497] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:57:17.497] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:16:0) after 1m0s
[21:58:17.525] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:16:0)
[21:58:17.525] Timer tick, asking Buildbucket for the build status
[21:58:17.602] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[21:58:17.602] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:17:0) after 1m0s
[21:59:17.657] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:17:0)
[21:59:17.719] Build status: STARTED
[21:59:17.720] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:18:0) after 1m57s
[22:01:14.753] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:18:0)
[22:01:14.787] Build status: STARTED
[22:01:14.787] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:19:0) after 6m48s
[22:08:02.819] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:19:0)
[22:08:02.819] Timer tick, asking Buildbucket for the build status
[22:08:04.317] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:08:04.317] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:20:0) after 1m0s
[22:09:04.346] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:20:0)
[22:09:04.346] Timer tick, asking Buildbucket for the build status
[22:09:04.540] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:09:04.540] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:21:0) after 1m0s
[22:10:04.597] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:21:0)
[22:10:04.624] Build status: STARTED
[22:10:04.624] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:22:0) after 5m0s
[22:15:04.643] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:22:0)
[22:15:04.673] Build status: STARTED
[22:15:04.673] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:23:0) after 8m38s
[22:23:42.691] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:23:0)
[22:23:42.691] Timer tick, asking Buildbucket for the build status
[22:23:42.836] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:23:42.836] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:24:0) after 1m0s
[22:24:42.855] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:24:0)
[22:24:42.855] Timer tick, asking Buildbucket for the build status
[22:24:43.075] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:24:43.075] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:25:0) after 1m0s
[22:25:43.094] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:25:0)
[22:25:43.125] Build status: STARTED
[22:25:43.125] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:26:0) after 8m46s
[22:34:29.147] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:26:0)
[22:34:29.172] Build status: STARTED
[22:34:29.173] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:27:0) after 5m56s
[22:40:25.193] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:27:0)
[22:40:25.220] Build status: STARTED
[22:40:25.220] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:28:0) after 5m54s
[22:46:19.304] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:28:0)
[22:46:19.328] Build status: STARTED
[22:46:19.328] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:29:0) after 2m25s
[22:48:44.326] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:29:0)
[22:48:44.326] Timer tick, asking Buildbucket for the build status
[22:48:44.942] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:48:44.942] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:30:0) after 1m0s
[22:49:45.044] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:30:0)
[22:49:45.071] Build status: STARTED
[22:49:45.071] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:31:0) after 9m41s
[22:59:26.139] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:31:0)
[22:59:26.139] Timer tick, asking Buildbucket for the build status
[22:59:26.249] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[22:59:26.249] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:32:0) after 1m0s
[23:00:26.293] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:32:0)
[23:00:26.293] Timer tick, asking Buildbucket for the build status
[23:00:26.416] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:00:26.416] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:33:0) after 1m0s
[23:01:26.494] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:33:0)
[23:01:26.494] Timer tick, asking Buildbucket for the build status
[23:01:26.583] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:01:26.583] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:34:0) after 1m0s
[23:02:26.614] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:34:0)
[23:02:26.614] Timer tick, asking Buildbucket for the build status
[23:02:26.716] Build 8852296712551738560: status "STARTED", result "", failure_reason "", cancelation_reason ""
[23:02:26.716] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:35:0) after 1m0s
[23:03:26.732] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:35:0)
[23:03:26.764] Build status: STARTED
[23:03:26.764] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:36:0) after 9m37s
[23:13:03.860] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:36:0)
[23:13:03.891] Build status: STARTED
[23:13:03.891] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:37:0) after 1m41s
[23:14:44.908] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:37:0)
[23:14:44.941] Build status: STARTED
[23:14:44.941] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:38:0) after 2m36s
[23:17:20.972] Handling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:38:0)
[23:17:21.015] Build status: STARTED
[23:17:21.015] Scheduling timer "check-buildbucket-build-status" (chromium/linux-chromeos-dbg:9017726774568668592:39:0) after 7m10s
[23:23:46.270] Received PubSub notification, asking Buildbucket for the build status
[23:23:46.300] Build:
{
"id": "8852296712551738560",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-chromeos-dbg"
},
"number": 23053,
"createdBy": "project:chromium",
"createTime": "2021-03-19T21:23:26.239653Z",
"startTime": "2021-03-19T21:27:08.486085Z",
"endTime": "2021-03-19T23:23:45.499540Z",
"updateTime": "2021-03-19T23:23:45.790501Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d989e155f30604ea895ba08912a6adcfa43b5ebf",
"ref": "refs/heads/master"
}
}
}
[23:23:46.300] Invocation finished in 2h0m21.368175731s with status SUCCEEDED