[09:29:42.091] New invocation is queued and will start shortly
[09:29:43.150] Starting the invocation (attempt 1)
[09:29:43.178] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/eb7c58136a2a26a6920a743fc958633198540c47"
[09:29:43.178] Popped gitiles commit info from properties and tags
[09:29:43.178] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[09:29:43.178] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[09:29:43.178] Buildbucket request:
{
"requestId": "8872635337403497248",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8872635337403497248",
"job": "r8/linux-internal",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "41e86fa4d7ba9e06b5934ab0b22b969f0c9313ed"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@41e86fa4d7ba9e06b5934ab0b22b969f0c9313ed",
"title": "41e86fa4d7ba9e06b5934ab0b22b969f0c9313ed",
"url": "https://r8.googlesource.com/r8/+/41e86fa4d7ba9e06b5934ab0b22b969f0c9313ed"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "132b7ebde940c7e04247e8ad0d83f295a072a6e3"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@132b7ebde940c7e04247e8ad0d83f295a072a6e3",
"title": "132b7ebde940c7e04247e8ad0d83f295a072a6e3",
"url": "https://r8.googlesource.com/r8/+/132b7ebde940c7e04247e8ad0d83f295a072a6e3"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "19a4f1bc0e83739d179cd20e883cdb4a425d497f"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@19a4f1bc0e83739d179cd20e883cdb4a425d497f",
"title": "19a4f1bc0e83739d179cd20e883cdb4a425d497f",
"url": "https://r8.googlesource.com/r8/+/19a4f1bc0e83739d179cd20e883cdb4a425d497f"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "146d3107be56b11093cc865c1548c9a93df62aa8"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@146d3107be56b11093cc865c1548c9a93df62aa8",
"title": "146d3107be56b11093cc865c1548c9a93df62aa8",
"url": "https://r8.googlesource.com/r8/+/146d3107be56b11093cc865c1548c9a93df62aa8"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "b3ea3fcd0b629bc8051923e09eaae3ccac9eed7d"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@b3ea3fcd0b629bc8051923e09eaae3ccac9eed7d",
"title": "b3ea3fcd0b629bc8051923e09eaae3ccac9eed7d",
"url": "https://r8.googlesource.com/r8/+/b3ea3fcd0b629bc8051923e09eaae3ccac9eed7d"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "95aad87255dce1f13412848fcb8f05cc3dd5b421"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@95aad87255dce1f13412848fcb8f05cc3dd5b421",
"title": "95aad87255dce1f13412848fcb8f05cc3dd5b421",
"url": "https://r8.googlesource.com/r8/+/95aad87255dce1f13412848fcb8f05cc3dd5b421"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "eb7c58136a2a26a6920a743fc958633198540c47"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@eb7c58136a2a26a6920a743fc958633198540c47",
"title": "eb7c58136a2a26a6920a743fc958633198540c47",
"url": "https://r8.googlesource.com/r8/+/eb7c58136a2a26a6920a743fc958633198540c47"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "eb7c58136a2a26a6920a743fc958633198540c47",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8872635337403497248"
},
{
"key": "scheduler_job_id",
"value": "r8/linux-internal"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[09:29:43.619] Scheduled build:
{
"id": "8707205275553213601",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"number": 5088,
"createdBy": "project:r8",
"createTime": "2025-08-07T09:29:43.235794615Z",
"updateTime": "2025-08-07T09:29:43.235794615Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "eb7c58136a2a26a6920a743fc958633198540c47",
"ref": "refs/heads/main"
}
}
}
[09:29:43.619] Task URL: https://cr-buildbucket.appspot.com/build/8707205275553213601
[09:29:43.619] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:2:0) after 9m6s
[09:29:44.019] Received PubSub notification, asking Buildbucket for the build status
[09:29:44.122] Build status: SCHEDULED
[09:38:49.630] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:2:0)
[09:38:49.657] Build status: SCHEDULED
[09:38:49.657] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:4:0) after 1m41s
[09:40:30.783] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:4:0)
[09:40:30.799] Build status: SCHEDULED
[09:40:30.799] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:5:0) after 8m17s
[09:48:47.813] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:5:0)
[09:48:47.853] Build status: SCHEDULED
[09:48:47.853] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:6:0) after 8m48s
[09:57:35.896] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:6:0)
[09:57:35.913] Build status: SCHEDULED
[09:57:35.913] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:7:0) after 7m50s
[10:05:25.986] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:7:0)
[10:05:26.019] Build status: SCHEDULED
[10:05:26.019] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:8:0) after 6m10s
[10:11:36.035] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:8:0)
[10:11:36.077] Build status: SCHEDULED
[10:11:36.077] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:9:0) after 7m15s
[10:18:51.092] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:9:0)
[10:18:51.141] Build status: SCHEDULED
[10:18:51.141] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:10:0) after 5m19s
[10:24:10.154] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:10:0)
[10:24:10.177] Build status: SCHEDULED
[10:24:10.177] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:11:0) after 5m48s
[10:29:58.201] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:11:0)
[10:29:58.261] Build status: SCHEDULED
[10:29:58.261] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:12:0) after 4m4s
[10:34:02.272] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:12:0)
[10:34:02.290] Build status: SCHEDULED
[10:34:02.290] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:13:0) after 1m29s
[10:35:31.421] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:13:0)
[10:35:31.446] Build status: SCHEDULED
[10:35:31.446] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:14:0) after 5m58s
[10:41:29.541] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:14:0)
[10:41:29.654] Build status: SCHEDULED
[10:41:29.654] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:15:0) after 9m49s
[10:51:18.722] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:15:0)
[10:51:18.739] Build status: SCHEDULED
[10:51:18.739] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:16:0) after 2m20s
[10:53:38.751] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:16:0)
[10:53:38.769] Build status: SCHEDULED
[10:53:38.769] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:17:0) after 4m23s
[10:58:01.786] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:17:0)
[10:58:01.816] Build status: SCHEDULED
[10:58:01.816] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:18:0) after 6m34s
[11:04:35.830] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:18:0)
[11:04:35.861] Build status: SCHEDULED
[11:04:35.861] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:19:0) after 3m35s
[11:08:10.875] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:19:0)
[11:08:10.901] Build status: SCHEDULED
[11:08:10.901] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:20:0) after 4m9s
[11:12:19.917] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:20:0)
[11:12:19.945] Build status: SCHEDULED
[11:12:19.945] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:21:0) after 2m54s
[11:15:14.013] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:21:0)
[11:15:14.053] Build status: SCHEDULED
[11:15:14.053] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:22:0) after 1m43s
[11:16:57.176] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:22:0)
[11:16:57.193] Build status: SCHEDULED
[11:16:57.193] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:23:0) after 6m10s
[11:23:07.257] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:23:0)
[11:23:07.276] Build status: SCHEDULED
[11:23:07.277] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:24:0) after 7m49s
[11:30:56.344] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:24:0)
[11:30:56.362] Build status: SCHEDULED
[11:30:56.362] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:25:0) after 5m26s
[11:36:22.417] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:25:0)
[11:36:22.443] Build status: SCHEDULED
[11:36:22.443] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:26:0) after 7m1s
[11:43:23.496] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:26:0)
[11:43:23.524] Build status: SCHEDULED
[11:43:23.524] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:27:0) after 7m23s
[11:50:46.547] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:27:0)
[11:50:46.594] Build status: SCHEDULED
[11:50:46.594] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:28:0) after 4m43s
[11:53:31.930] Received PubSub notification, asking Buildbucket for the build status
[11:53:31.957] Build status: STARTED
[11:55:29.618] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:28:0)
[11:55:29.640] Build status: STARTED
[11:55:29.640] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:30:0) after 3m27s
[11:58:56.656] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:30:0)
[11:58:56.768] Build status: STARTED
[11:58:56.768] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:31:0) after 3m14s
[12:02:10.783] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:31:0)
[12:02:10.801] Build status: STARTED
[12:02:10.801] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:32:0) after 5m15s
[12:07:25.816] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:32:0)
[12:07:25.834] Build status: STARTED
[12:07:25.835] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:33:0) after 8m13s
[12:15:38.891] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:33:0)
[12:15:38.940] Build status: STARTED
[12:15:38.940] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:34:0) after 7m50s
[12:23:28.948] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:34:0)
[12:23:28.974] Build status: STARTED
[12:23:28.974] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:35:0) after 7m42s
[12:31:11.103] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:35:0)
[12:31:11.180] Build status: STARTED
[12:31:11.180] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:36:0) after 3m37s
[12:34:48.246] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:36:0)
[12:34:48.276] Build status: STARTED
[12:34:48.276] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:37:0) after 9m11s
[12:43:59.406] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:37:0)
[12:43:59.423] Build status: STARTED
[12:43:59.423] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:38:0) after 7m28s
[12:51:27.487] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:38:0)
[12:51:27.556] Build status: STARTED
[12:51:27.556] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:39:0) after 8m40s
[13:00:07.548] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:39:0)
[13:00:07.570] Build status: STARTED
[13:00:07.570] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:40:0) after 2m33s
[13:02:40.588] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:40:0)
[13:02:40.641] Build status: STARTED
[13:02:40.641] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:41:0) after 2m0s
[13:04:40.666] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:41:0)
[13:04:40.680] Build status: STARTED
[13:04:40.680] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:42:0) after 6m31s
[13:11:11.712] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:42:0)
[13:11:11.740] Build status: STARTED
[13:11:11.740] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:43:0) after 2m13s
[13:13:24.756] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:43:0)
[13:13:24.780] Build status: STARTED
[13:13:24.780] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:44:0) after 7m52s
[13:21:16.843] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:44:0)
[13:21:16.878] Build status: STARTED
[13:21:16.878] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:45:0) after 1m50s
[13:23:06.912] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:45:0)
[13:23:06.954] Build status: STARTED
[13:23:06.954] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:46:0) after 1m7s
[13:24:13.937] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:46:0)
[13:24:14.002] Build status: STARTED
[13:24:14.002] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:47:0) after 4m50s
[13:29:04.115] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:47:0)
[13:29:04.137] Build status: STARTED
[13:29:04.138] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:48:0) after 5m13s
[13:34:17.210] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:48:0)
[13:34:17.231] Build status: STARTED
[13:34:17.231] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:49:0) after 6m34s
[13:40:51.341] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:49:0)
[13:40:51.369] Build status: STARTED
[13:40:51.369] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:50:0) after 9m54s
[13:50:45.486] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:50:0)
[13:50:45.537] Build status: STARTED
[13:50:45.537] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:51:0) after 8m24s
[13:59:09.552] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:51:0)
[13:59:09.569] Build status: STARTED
[13:59:09.569] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:52:0) after 9m7s
[14:08:16.564] Handling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:52:0)
[14:08:16.615] Build status: STARTED
[14:08:16.615] Scheduling timer "check-buildbucket-build-status" (r8/linux-internal:8872635337403497248:53:0) after 5m47s
[14:13:59.670] Received PubSub notification, asking Buildbucket for the build status
[14:13:59.689] Build:
{
"id": "8707205275553213601",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-internal"
},
"number": 5088,
"createdBy": "project:r8",
"createTime": "2025-08-07T09:29:43.235794615Z",
"startTime": "2025-08-07T11:53:31.501857625Z",
"endTime": "2025-08-07T14:13:59.441697033Z",
"updateTime": "2025-08-07T14:13:59.441697033Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "eb7c58136a2a26a6920a743fc958633198540c47",
"ref": "refs/heads/main"
}
}
}
[14:13:59.689] Invocation finished in 4h44m17.601837125s with status SUCCEEDED