[00:54:20.476] New invocation is queued and will start shortly
[00:54:21.551] Starting the invocation (attempt 1)
[00:54:21.587] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[00:54:21.587] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[00:54:21.588] Buildbucket request:
{
"bucket": "luci.chromium.ci",
"client_operation_id": "9017532310375025056",
"parameters_json": "{\"builder_name\":\"Linux Viz\",\"properties\":{\"branch\":\"refs/heads/master\",\"repository\":\"https://chromium.googlesource.com/chromium/src\",\"revision\":\"4189daf81451bce980ed75a04281fc8d78f1f4d6\"}}",
"pubsub_callback": {
"auth_token": "...",
"topic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
},
"tags": [
"builder:Linux Viz",
"scheduler_invocation_id:9017532310375025056",
"scheduler_job_id:chromium/Linux Viz",
"user_agent:luci-scheduler",
"buildset:commit/git/4189daf81451bce980ed75a04281fc8d78f1f4d6",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4189daf81451bce980ed75a04281fc8d78f1f4d6",
"gitiles_ref:refs/heads/master"
]
}
[00:54:22.200] Buildbucket response:
{
"build": {
"bucket": "luci.chromium.ci",
"canary_preference": "PROD",
"created_by": "project:chromium",
"created_ts": "1616374461663855",
"id": "8852102248445203760",
"parameters_json": "{\"builder_name\": \"Linux Viz\", \"properties\": {\"branch\": \"refs/heads/master\", \"repository\": \"https://chromium.googlesource.com/chromium/src\", \"revision\": \"4189daf81451bce980ed75a04281fc8d78f1f4d6\"}}",
"project": "chromium",
"result_details_json": "{\"properties\": {}}",
"service_account": "chromium-ci-builder@chops-service-accounts.iam.gserviceaccount.com",
"status": "SCHEDULED",
"status_changed_ts": "1616374462057389",
"tags": [
"build_address:luci.chromium.ci/Linux Viz/26895",
"builder:Linux Viz",
"buildset:commit/git/4189daf81451bce980ed75a04281fc8d78f1f4d6",
"buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/4189daf81451bce980ed75a04281fc8d78f1f4d6",
"gitiles_ref:refs/heads/master",
"scheduler_invocation_id:9017532310375025056",
"scheduler_job_id:chromium/Linux Viz",
"swarming_hostname:chromium-swarm.appspot.com",
"swarming_tag:log_location:logdog://logs.chromium.org/chromium/buildbucket/cr-buildbucket.appspot.com/8852102248445203760/+/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": "1616374462057514",
"url": "https://ci.chromium.org/b/8852102248445203760",
"utcnow_ts": "1616374462189975"
}
}
[00:54:22.200] Task URL: https://ci.chromium.org/b/8852102248445203760
[00:54:22.200] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:2:0) after 1m0s
[00:55:22.314] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:2:0)
[00:55:22.314] Timer tick, asking Buildbucket for the build status
[00:55:22.418] Build 8852102248445203760: status "SCHEDULED", result "", failure_reason "", cancelation_reason ""
[00:55:22.418] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:3:0) after 1m0s
[00:56:22.522] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:3:0)
[00:56:22.555] Build status: SCHEDULED
[00:56:22.555] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:4:0) after 1m32s
[00:57:54.683] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:4:0)
[00:57:54.708] Build status: SCHEDULED
[00:57:54.708] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:5:0) after 9m17s
[00:59:17.342] Received PubSub notification, asking Buildbucket for the build status
[00:59:17.435] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:07:11.724] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:5:0)
[01:07:11.724] Timer tick, asking Buildbucket for the build status
[01:07:11.975] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:07:11.975] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:7:0) after 1m0s
[01:08:11.968] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:7:0)
[01:08:12.021] Build status: STARTED
[01:08:12.021] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:8:0) after 2m59s
[01:11:11.242] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:8:0)
[01:11:11.242] Timer tick, asking Buildbucket for the build status
[01:11:11.516] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:11:11.516] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:9:0) after 1m0s
[01:12:11.534] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:9:0)
[01:12:11.575] Build status: STARTED
[01:12:11.575] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:10:0) after 7m18s
[01:19:29.590] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:10:0)
[01:19:29.621] Build status: STARTED
[01:19:29.621] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:11:0) after 1m6s
[01:20:36.604] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:11:0)
[01:20:36.629] Build status: STARTED
[01:20:36.629] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:12:0) after 3m43s
[01:24:19.987] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:12:0)
[01:24:20.019] Build status: STARTED
[01:24:20.019] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:13:0) after 3m24s
[01:27:44.140] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:13:0)
[01:27:44.166] Build status: STARTED
[01:27:44.166] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:14:0) after 8m6s
[01:35:50.208] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:14:0)
[01:35:50.208] Timer tick, asking Buildbucket for the build status
[01:35:50.287] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:35:50.287] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:15:0) after 1m0s
[01:36:50.301] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:15:0)
[01:36:50.301] Timer tick, asking Buildbucket for the build status
[01:36:50.380] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:36:50.380] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:16:0) after 1m0s
[01:37:50.394] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:16:0)
[01:37:50.420] Build status: STARTED
[01:37:50.420] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:17:0) after 2m35s
[01:40:25.436] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:17:0)
[01:40:25.436] Timer tick, asking Buildbucket for the build status
[01:40:25.541] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:40:25.541] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:18:0) after 1m0s
[01:41:25.643] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:18:0)
[01:41:25.676] Build status: STARTED
[01:41:25.676] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:19:0) after 7m29s
[01:48:54.793] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:19:0)
[01:48:54.818] Build status: STARTED
[01:48:54.818] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:20:0) after 3m35s
[01:52:29.891] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:20:0)
[01:52:29.918] Build status: STARTED
[01:52:29.918] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:21:0) after 1m43s
[01:54:12.993] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:21:0)
[01:54:12.993] Timer tick, asking Buildbucket for the build status
[01:54:13.147] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:54:13.147] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:22:0) after 1m0s
[01:55:13.322] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:22:0)
[01:55:13.322] Timer tick, asking Buildbucket for the build status
[01:55:13.412] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[01:55:13.412] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:23:0) after 1m0s
[01:56:13.579] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:23:0)
[01:56:13.607] Build status: STARTED
[01:56:13.607] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:24:0) after 1m0s
[01:57:13.796] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:24:0)
[01:57:13.822] Build status: STARTED
[01:57:13.822] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:25:0) after 8m41s
[02:05:54.861] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:25:0)
[02:05:54.923] Build status: STARTED
[02:05:54.923] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:26:0) after 2m42s
[02:08:37.042] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:26:0)
[02:08:37.042] Timer tick, asking Buildbucket for the build status
[02:08:37.176] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:08:37.176] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:27:0) after 1m0s
[02:09:37.360] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:27:0)
[02:09:37.406] Build status: STARTED
[02:09:37.406] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:28:0) after 9m35s
[02:19:12.424] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:28:0)
[02:19:12.424] Timer tick, asking Buildbucket for the build status
[02:19:12.500] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:19:12.500] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:29:0) after 1m0s
[02:20:12.551] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:29:0)
[02:20:12.551] Timer tick, asking Buildbucket for the build status
[02:20:12.683] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:20:12.683] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:30:0) after 1m0s
[02:21:12.702] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:30:0)
[02:21:12.702] Timer tick, asking Buildbucket for the build status
[02:21:12.765] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:21:12.765] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:31:0) after 1m0s
[02:22:12.785] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:31:0)
[02:22:12.785] Timer tick, asking Buildbucket for the build status
[02:22:12.928] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:22:12.928] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:32:0) after 1m0s
[02:23:13.219] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:32:0)
[02:23:13.249] Build status: STARTED
[02:23:13.249] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:33:0) after 5m52s
[02:29:05.369] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:33:0)
[02:29:05.369] Timer tick, asking Buildbucket for the build status
[02:29:05.596] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:29:05.596] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:34:0) after 1m0s
[02:30:05.689] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:34:0)
[02:30:05.689] Timer tick, asking Buildbucket for the build status
[02:30:05.907] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:30:05.907] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:35:0) after 1m0s
[02:31:06.722] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:35:0)
[02:31:06.746] Build status: STARTED
[02:31:06.746] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:36:0) after 2m43s
[02:33:49.769] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:36:0)
[02:33:49.797] Build status: STARTED
[02:33:49.797] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:37:0) after 3m54s
[02:37:43.873] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:37:0)
[02:37:43.873] Timer tick, asking Buildbucket for the build status
[02:37:43.943] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:37:43.943] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:38:0) after 1m0s
[02:38:44.104] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:38:0)
[02:38:44.104] Timer tick, asking Buildbucket for the build status
[02:38:44.168] Build 8852102248445203760: status "STARTED", result "", failure_reason "", cancelation_reason ""
[02:38:44.168] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:39:0) after 1m0s
[02:39:44.357] Handling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:39:0)
[02:39:44.388] Build status: STARTED
[02:39:44.388] Scheduling timer "check-buildbucket-build-status" (chromium/Linux Viz:9017532310375025056:40:0) after 7m1s
[02:46:45.116] Received PubSub notification, asking Buildbucket for the build status
[02:46:45.143] Build:
{
"id": "8852102248445203760",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Linux Viz"
},
"number": 26895,
"createdBy": "project:chromium",
"createTime": "2021-03-22T00:54:21.663855Z",
"startTime": "2021-03-22T00:59:16.113760Z",
"endTime": "2021-03-22T02:46:44.737004611Z",
"updateTime": "2021-03-22T02:46:44.737470711Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "4189daf81451bce980ed75a04281fc8d78f1f4d6",
"ref": "refs/heads/master"
}
}
}
[02:46:45.143] Invocation finished in 1h52m24.70427818s with status SUCCEEDED