[14:04:30.500] New invocation is queued and will start shortly
[14:04:31.560] Starting the invocation (attempt 1)
[14:04:31.586] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/b94c41afc54bcee31a20c15216b7802ef1dac2c9"
[14:04:31.586] Popped gitiles commit info from properties and tags
[14:04:31.586] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[14:04:31.586] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[14:04:31.586] Buildbucket request:
{
"requestId": "8852958506350306368",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8852958506350306368",
"job": "chromium-m147/win-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "d0f7cb1e4f309f9a09f2bafbd2f7b213bbe04d21"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@d0f7cb1e4f309f9a09f2bafbd2f7b213bbe04d21",
"title": "d0f7cb1e4f309f9a09f2bafbd2f7b213bbe04d21",
"url": "https://chromium.googlesource.com/chromium/src/+/d0f7cb1e4f309f9a09f2bafbd2f7b213bbe04d21"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "46a5dfa352af229d48ba38fca965c1e6a63df4b3"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@46a5dfa352af229d48ba38fca965c1e6a63df4b3",
"title": "46a5dfa352af229d48ba38fca965c1e6a63df4b3",
"url": "https://chromium.googlesource.com/chromium/src/+/46a5dfa352af229d48ba38fca965c1e6a63df4b3"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "82c4aef04b4571b93d28a329d951ea622e2c8b00"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@82c4aef04b4571b93d28a329d951ea622e2c8b00",
"title": "82c4aef04b4571b93d28a329d951ea622e2c8b00",
"url": "https://chromium.googlesource.com/chromium/src/+/82c4aef04b4571b93d28a329d951ea622e2c8b00"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "3775e1ebbe3fab171f46b31ae7976ef9dac5e1a9"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@3775e1ebbe3fab171f46b31ae7976ef9dac5e1a9",
"title": "3775e1ebbe3fab171f46b31ae7976ef9dac5e1a9",
"url": "https://chromium.googlesource.com/chromium/src/+/3775e1ebbe3fab171f46b31ae7976ef9dac5e1a9"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "f17bb1967a704e74ef1b73d51ebbeb4f497c4a16"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@f17bb1967a704e74ef1b73d51ebbeb4f497c4a16",
"title": "f17bb1967a704e74ef1b73d51ebbeb4f497c4a16",
"url": "https://chromium.googlesource.com/chromium/src/+/f17bb1967a704e74ef1b73d51ebbeb4f497c4a16"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "fa897749ee053928fe8fdc2d10072280084647f3"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@fa897749ee053928fe8fdc2d10072280084647f3",
"title": "fa897749ee053928fe8fdc2d10072280084647f3",
"url": "https://chromium.googlesource.com/chromium/src/+/fa897749ee053928fe8fdc2d10072280084647f3"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "4658321ce255063ce68c231b71479b3f1d8645a7"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@4658321ce255063ce68c231b71479b3f1d8645a7",
"title": "4658321ce255063ce68c231b71479b3f1d8645a7",
"url": "https://chromium.googlesource.com/chromium/src/+/4658321ce255063ce68c231b71479b3f1d8645a7"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "4d0e33a747a7284d211508186384bee1018b8bed"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@4d0e33a747a7284d211508186384bee1018b8bed",
"title": "4d0e33a747a7284d211508186384bee1018b8bed",
"url": "https://chromium.googlesource.com/chromium/src/+/4d0e33a747a7284d211508186384bee1018b8bed"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "09505b9f1562e635d4e1b45600368ef18fff249a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@09505b9f1562e635d4e1b45600368ef18fff249a",
"title": "09505b9f1562e635d4e1b45600368ef18fff249a",
"url": "https://chromium.googlesource.com/chromium/src/+/09505b9f1562e635d4e1b45600368ef18fff249a"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b3836f0725452043424c0386be6edf9324239b96"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@b3836f0725452043424c0386be6edf9324239b96",
"title": "b3836f0725452043424c0386be6edf9324239b96",
"url": "https://chromium.googlesource.com/chromium/src/+/b3836f0725452043424c0386be6edf9324239b96"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b94c41afc54bcee31a20c15216b7802ef1dac2c9"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@b94c41afc54bcee31a20c15216b7802ef1dac2c9",
"title": "b94c41afc54bcee31a20c15216b7802ef1dac2c9",
"url": "https://chromium.googlesource.com/chromium/src/+/b94c41afc54bcee31a20c15216b7802ef1dac2c9"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b94c41afc54bcee31a20c15216b7802ef1dac2c9",
"ref": "refs/branch-heads/7727"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8852958506350306368"
},
{
"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"
}
}
[14:04:32.269] Scheduled build:
{
"id": "8687528444415538833",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"number": 14,
"createdBy": "project:chromium-m147",
"createTime": "2026-03-12T14:04:31.720489701Z",
"updateTime": "2026-03-12T14:04:31.720489701Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b94c41afc54bcee31a20c15216b7802ef1dac2c9",
"ref": "refs/branch-heads/7727"
}
}
}
[14:04:32.269] Task URL: https://cr-buildbucket.appspot.com/build/8687528444415538833
[14:04:32.269] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:2:0) after 3m46s
[14:04:33.250] Received PubSub notification, asking Buildbucket for the build status
[14:04:33.308] Build status: SCHEDULED
[14:04:37.306] Received PubSub notification, asking Buildbucket for the build status
[14:04:37.341] Build status: STARTED
[14:08:18.288] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:2:0)
[14:08:18.312] Build status: STARTED
[14:08:18.312] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:5:0) after 4m31s
[14:12:49.338] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:5:0)
[14:12:49.400] Build status: STARTED
[14:12:49.400] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:6:0) after 7m46s
[14:20:35.530] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:6:0)
[14:20:35.546] Build status: STARTED
[14:20:35.546] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:7:0) after 7m35s
[14:28:10.773] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:7:0)
[14:28:10.788] Build status: STARTED
[14:28:10.788] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:8:0) after 6m14s
[14:34:24.846] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:8:0)
[14:34:24.872] Build status: STARTED
[14:34:24.873] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:9:0) after 4m30s
[14:38:54.926] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:9:0)
[14:38:54.950] Build status: STARTED
[14:38:54.951] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:10:0) after 4m59s
[14:43:53.971] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:10:0)
[14:43:53.991] Build status: STARTED
[14:43:53.991] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:11:0) after 5m33s
[14:49:27.056] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:11:0)
[14:49:27.075] Build status: STARTED
[14:49:27.076] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:12:0) after 3m0s
[14:52:27.184] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:12:0)
[14:52:27.269] Build status: STARTED
[14:52:27.269] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:13:0) after 2m4s
[14:54:31.392] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:13:0)
[14:54:31.415] Build status: STARTED
[14:54:31.415] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:14:0) after 5m16s
[14:59:47.528] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:14:0)
[14:59:47.564] Build status: STARTED
[14:59:47.564] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:15:0) after 5m39s
[15:05:26.680] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:15:0)
[15:05:26.710] Build status: STARTED
[15:05:26.710] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:16:0) after 4m27s
[15:09:53.789] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:16:0)
[15:09:53.810] Build status: STARTED
[15:09:53.810] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:17:0) after 1m38s
[15:11:31.830] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:17:0)
[15:11:31.861] Build status: STARTED
[15:11:31.861] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:18:0) after 4m18s
[15:15:50.040] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:18:0)
[15:15:50.112] Build status: STARTED
[15:15:50.112] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:19:0) after 5m36s
[15:21:26.297] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:19:0)
[15:21:26.352] Build status: STARTED
[15:21:26.352] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:20:0) after 7m4s
[15:28:30.431] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:20:0)
[15:28:30.544] Build status: STARTED
[15:28:30.544] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:21:0) after 4m19s
[15:32:49.616] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:21:0)
[15:32:49.631] Build status: STARTED
[15:32:49.631] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:22:0) after 2m49s
[15:35:38.813] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:22:0)
[15:35:38.830] Build status: STARTED
[15:35:38.830] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:23:0) after 2m3s
[15:37:41.936] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:23:0)
[15:37:41.957] Build status: STARTED
[15:37:41.957] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:24:0) after 9m8s
[15:46:50.019] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:24:0)
[15:46:50.045] Build status: STARTED
[15:46:50.045] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:25:0) after 5m26s
[15:52:16.121] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:25:0)
[15:52:16.137] Build status: STARTED
[15:52:16.137] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:26:0) after 4m32s
[15:56:48.223] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:26:0)
[15:56:48.269] Build status: STARTED
[15:56:48.269] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:27:0) after 8m32s
[16:05:20.267] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:27:0)
[16:05:20.282] Build status: STARTED
[16:05:20.282] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:28:0) after 2m42s
[16:08:02.306] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:28:0)
[16:08:02.330] Build status: STARTED
[16:08:02.330] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:29:0) after 6m6s
[16:14:08.400] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:29:0)
[16:14:08.440] Build status: STARTED
[16:14:08.440] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:30:0) after 1m46s
[16:15:54.967] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:30:0)
[16:15:54.986] Build status: STARTED
[16:15:54.986] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:31:0) after 4m21s
[16:20:16.087] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:31:0)
[16:20:16.156] Build status: STARTED
[16:20:16.157] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:32:0) after 9m27s
[16:29:43.176] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:32:0)
[16:29:43.194] Build status: STARTED
[16:29:43.194] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:33:0) after 3m50s
[16:33:33.340] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:33:0)
[16:33:33.355] Build status: STARTED
[16:33:33.355] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:34:0) after 6m42s
[16:40:15.371] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:34:0)
[16:40:15.401] Build status: STARTED
[16:40:15.401] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:35:0) after 3m50s
[16:44:05.526] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:35:0)
[16:44:05.547] Build status: STARTED
[16:44:05.547] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:36:0) after 3m5s
[16:47:10.985] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:36:0)
[16:47:11.014] Build status: STARTED
[16:47:11.014] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:37:0) after 9m54s
[16:57:05.011] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:37:0)
[16:57:05.028] Build status: STARTED
[16:57:05.028] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:38:0) after 2m48s
[16:59:53.184] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:38:0)
[16:59:53.239] Build status: STARTED
[16:59:53.239] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:39:0) after 4m54s
[17:04:47.310] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:39:0)
[17:04:47.331] Build status: STARTED
[17:04:47.331] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8852958506350306368:40:0) after 4m52s
[17:05:36.770] Received PubSub notification, asking Buildbucket for the build status
[17:05:36.791] Build:
{
"id": "8687528444415538833",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"number": 14,
"createdBy": "project:chromium-m147",
"createTime": "2026-03-12T14:04:31.720489701Z",
"startTime": "2026-03-12T14:04:36.995690867Z",
"endTime": "2026-03-12T17:05:36.223166691Z",
"updateTime": "2026-03-12T17:05:36.223166691Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b94c41afc54bcee31a20c15216b7802ef1dac2c9",
"ref": "refs/branch-heads/7727"
}
}
}
[17:05:36.791] Invocation finished in 3h1m6.300116369s with status SUCCEEDED