[18:31:48.392] New invocation is queued and will start shortly
[18:31:49.521] Starting the invocation (attempt 1)
[18:31:49.546] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/01a7eca8347f37585ecc3f08124c5adcd1c16845"
[18:31:49.546] Popped gitiles commit info from properties and tags
[18:31:49.546] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[18:31:49.547] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[18:31:49.547] Buildbucket request:
{
"requestId": "8852035719736675456",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8852035719736675456",
"job": "chromium-m147/win-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ad59bd15a241dd9643bc2814b04e2609a3704d64"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@ad59bd15a241dd9643bc2814b04e2609a3704d64",
"title": "ad59bd15a241dd9643bc2814b04e2609a3704d64",
"url": "https://chromium.googlesource.com/chromium/src/+/ad59bd15a241dd9643bc2814b04e2609a3704d64"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "f61ef05723a74c6dd1aad628162388e5c21dbb74"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@f61ef05723a74c6dd1aad628162388e5c21dbb74",
"title": "f61ef05723a74c6dd1aad628162388e5c21dbb74",
"url": "https://chromium.googlesource.com/chromium/src/+/f61ef05723a74c6dd1aad628162388e5c21dbb74"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "7d8c86776bb232967968918b52623c64f54e0f60"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@7d8c86776bb232967968918b52623c64f54e0f60",
"title": "7d8c86776bb232967968918b52623c64f54e0f60",
"url": "https://chromium.googlesource.com/chromium/src/+/7d8c86776bb232967968918b52623c64f54e0f60"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "02099e1fd3fb1d3c06b34465c6d0ddd376e9065a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@02099e1fd3fb1d3c06b34465c6d0ddd376e9065a",
"title": "02099e1fd3fb1d3c06b34465c6d0ddd376e9065a",
"url": "https://chromium.googlesource.com/chromium/src/+/02099e1fd3fb1d3c06b34465c6d0ddd376e9065a"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "7e9d3807de5153834340a8a1290b89c68ee912ac"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@7e9d3807de5153834340a8a1290b89c68ee912ac",
"title": "7e9d3807de5153834340a8a1290b89c68ee912ac",
"url": "https://chromium.googlesource.com/chromium/src/+/7e9d3807de5153834340a8a1290b89c68ee912ac"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "be2054efac016cec1c9d001a23744e5c0de1461c"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@be2054efac016cec1c9d001a23744e5c0de1461c",
"title": "be2054efac016cec1c9d001a23744e5c0de1461c",
"url": "https://chromium.googlesource.com/chromium/src/+/be2054efac016cec1c9d001a23744e5c0de1461c"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "c6b806ee4a836e97d103a184d8382e0fef243752"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@c6b806ee4a836e97d103a184d8382e0fef243752",
"title": "c6b806ee4a836e97d103a184d8382e0fef243752",
"url": "https://chromium.googlesource.com/chromium/src/+/c6b806ee4a836e97d103a184d8382e0fef243752"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "0da3050bb774c23ee3724c1f9647f326e16d8156"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@0da3050bb774c23ee3724c1f9647f326e16d8156",
"title": "0da3050bb774c23ee3724c1f9647f326e16d8156",
"url": "https://chromium.googlesource.com/chromium/src/+/0da3050bb774c23ee3724c1f9647f326e16d8156"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "80e20ee44291921d157190efc5bc2ed0a2dc8aba"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@80e20ee44291921d157190efc5bc2ed0a2dc8aba",
"title": "80e20ee44291921d157190efc5bc2ed0a2dc8aba",
"url": "https://chromium.googlesource.com/chromium/src/+/80e20ee44291921d157190efc5bc2ed0a2dc8aba"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b60cff083bd83bb73c1032bdea93245e3d2e346d"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@b60cff083bd83bb73c1032bdea93245e3d2e346d",
"title": "b60cff083bd83bb73c1032bdea93245e3d2e346d",
"url": "https://chromium.googlesource.com/chromium/src/+/b60cff083bd83bb73c1032bdea93245e3d2e346d"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "01a7eca8347f37585ecc3f08124c5adcd1c16845"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@01a7eca8347f37585ecc3f08124c5adcd1c16845",
"title": "01a7eca8347f37585ecc3f08124c5adcd1c16845",
"url": "https://chromium.googlesource.com/chromium/src/+/01a7eca8347f37585ecc3f08124c5adcd1c16845"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "01a7eca8347f37585ecc3f08124c5adcd1c16845",
"ref": "refs/branch-heads/7727"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8852035719736675456"
},
{
"key": "scheduler_job_id",
"value": "chromium-m147/win-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[18:31:50.131] Scheduled build:
{
"id": "8686605657827745889",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"number": 91,
"createdBy": "project:chromium-m147",
"createTime": "2026-03-22T18:31:49.588606957Z",
"updateTime": "2026-03-22T18:31:49.588606957Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "01a7eca8347f37585ecc3f08124c5adcd1c16845",
"ref": "refs/branch-heads/7727"
}
}
}
[18:31:50.131] Task URL: https://cr-buildbucket.appspot.com/build/8686605657827745889
[18:31:50.131] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:2:0) after 8m57s
[18:31:50.976] Received PubSub notification, asking Buildbucket for the build status
[18:31:50.993] Build status: SCHEDULED
[18:35:59.338] Received PubSub notification, asking Buildbucket for the build status
[18:35:59.360] Build status: STARTED
[18:40:47.263] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:2:0)
[18:40:47.281] Build status: STARTED
[18:40:47.281] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:5:0) after 3m22s
[18:44:09.300] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:5:0)
[18:44:09.321] Build status: STARTED
[18:44:09.321] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:6:0) after 3m54s
[18:48:03.538] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:6:0)
[18:48:03.556] Build status: STARTED
[18:48:03.557] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:7:0) after 1m17s
[18:49:20.571] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:7:0)
[18:49:20.586] Build status: STARTED
[18:49:20.586] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:8:0) after 6m13s
[18:55:33.601] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:8:0)
[18:55:33.615] Build status: STARTED
[18:55:33.615] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:9:0) after 9m51s
[19:05:24.693] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:9:0)
[19:05:24.721] Build status: STARTED
[19:05:24.721] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:10:0) after 2m58s
[19:08:22.836] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:10:0)
[19:08:22.854] Build status: STARTED
[19:08:22.854] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:11:0) after 8m22s
[19:16:44.886] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:11:0)
[19:16:44.946] Build status: STARTED
[19:16:44.946] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:12:0) after 3m48s
[19:20:32.991] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:12:0)
[19:20:33.010] Build status: STARTED
[19:20:33.011] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:13:0) after 1m52s
[19:22:25.027] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:13:0)
[19:22:25.047] Build status: STARTED
[19:22:25.047] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:14:0) after 2m53s
[19:25:18.160] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:14:0)
[19:25:18.190] Build status: STARTED
[19:25:18.190] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:15:0) after 8m32s
[19:33:50.206] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:15:0)
[19:33:50.232] Build status: STARTED
[19:33:50.232] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:16:0) after 2m2s
[19:35:52.269] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:16:0)
[19:35:52.297] Build status: STARTED
[19:35:52.297] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:17:0) after 2m27s
[19:38:19.312] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:17:0)
[19:38:19.333] Build status: STARTED
[19:38:19.333] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:18:0) after 6m31s
[19:44:50.307] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:18:0)
[19:44:50.322] Build status: STARTED
[19:44:50.322] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:19:0) after 2m14s
[19:47:04.336] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:19:0)
[19:47:04.469] Build status: STARTED
[19:47:04.469] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:20:0) after 9m37s
[19:56:41.852] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:20:0)
[19:56:41.866] Build status: STARTED
[19:56:41.866] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:21:0) after 3m52s
[20:00:33.963] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:21:0)
[20:00:33.984] Build status: STARTED
[20:00:33.984] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:22:0) after 8m23s
[20:08:57.006] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:22:0)
[20:08:57.035] Build status: STARTED
[20:08:57.035] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:23:0) after 6m30s
[20:15:27.074] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:23:0)
[20:15:27.092] Build status: STARTED
[20:15:27.092] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:24:0) after 3m28s
[20:18:55.061] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:24:0)
[20:18:55.079] Build status: STARTED
[20:18:55.079] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:25:0) after 5m59s
[20:24:54.328] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:25:0)
[20:24:54.348] Build status: STARTED
[20:24:54.349] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:26:0) after 9m58s
[20:34:52.392] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:26:0)
[20:34:52.413] Build status: STARTED
[20:34:52.413] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:27:0) after 7m37s
[20:42:29.499] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:27:0)
[20:42:29.516] Build status: STARTED
[20:42:29.516] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:28:0) after 2m48s
[20:45:17.532] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:28:0)
[20:45:17.553] Build status: STARTED
[20:45:17.553] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:29:0) after 3m55s
[20:49:12.575] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:29:0)
[20:49:12.593] Build status: STARTED
[20:49:12.593] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:30:0) after 5m47s
[20:54:59.605] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:30:0)
[20:54:59.705] Build status: STARTED
[20:54:59.705] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:31:0) after 3m37s
[20:58:36.719] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:31:0)
[20:58:36.743] Build status: STARTED
[20:58:36.743] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:32:0) after 7m27s
[21:06:03.757] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:32:0)
[21:06:03.849] Build status: STARTED
[21:06:03.849] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:33:0) after 3m45s
[21:09:49.176] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:33:0)
[21:09:49.194] Build status: STARTED
[21:09:49.194] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:34:0) after 9m44s
[21:19:33.497] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:34:0)
[21:19:33.524] Build status: STARTED
[21:19:33.524] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:35:0) after 4m45s
[21:24:18.625] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:35:0)
[21:24:18.641] Build status: STARTED
[21:24:18.642] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:36:0) after 8m0s
[21:32:18.704] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:36:0)
[21:32:18.744] Build status: STARTED
[21:32:18.745] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:37:0) after 4m43s
[21:37:01.714] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:37:0)
[21:37:01.728] Build status: STARTED
[21:37:01.728] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:38:0) after 4m31s
[21:41:32.744] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:38:0)
[21:41:32.767] Build status: STARTED
[21:41:32.767] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:39:0) after 6m8s
[21:47:41.460] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:39:0)
[21:47:41.479] Build status: STARTED
[21:47:41.479] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:40:0) after 9m31s
[21:57:12.493] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:40:0)
[21:57:12.518] Build status: STARTED
[21:57:12.518] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:41:0) after 3m38s
[22:00:50.541] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:41:0)
[22:00:50.561] Build status: STARTED
[22:00:50.561] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:42:0) after 2m32s
[22:03:22.578] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:42:0)
[22:03:22.604] Build status: STARTED
[22:03:22.604] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:43:0) after 5m41s
[22:09:03.645] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:43:0)
[22:09:03.690] Build status: STARTED
[22:09:03.690] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:44:0) after 6m27s
[22:15:31.366] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:44:0)
[22:15:31.389] Build status: STARTED
[22:15:31.389] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:45:0) after 5m26s
[22:20:57.405] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:45:0)
[22:20:57.423] Build status: STARTED
[22:20:57.423] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:46:0) after 1m32s
[22:22:29.443] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:46:0)
[22:22:29.525] Build status: STARTED
[22:22:29.525] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:47:0) after 3m38s
[22:26:07.818] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:47:0)
[22:26:07.836] Build status: STARTED
[22:26:07.836] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852035719736675456:48:0) after 9m56s
[22:33:48.946] Received PubSub notification, asking Buildbucket for the build status
[22:33:48.967] Build:
{
"id": "8686605657827745889",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"number": 91,
"createdBy": "project:chromium-m147",
"createTime": "2026-03-22T18:31:49.588606957Z",
"startTime": "2026-03-22T18:35:59.127610474Z",
"endTime": "2026-03-22T22:33:48.648184219Z",
"updateTime": "2026-03-22T22:33:48.648184219Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "01a7eca8347f37585ecc3f08124c5adcd1c16845",
"ref": "refs/branch-heads/7727"
}
}
}
[22:33:48.967] Invocation finished in 4h2m0.583160651s with status SUCCEEDED