[03:28:47.249] New invocation is queued and will start shortly
[03:28:48.304] Starting the invocation (attempt 1)
[03:28:48.325] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac"
[03:28:48.325] Popped gitiles commit info from properties and tags
[03:28:48.325] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[03:28:48.325] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[03:28:48.325] Buildbucket request:
{
"requestId": "8851458354013792960",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8851458354013792960",
"job": "chromium-m147/win-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "09411b2a4b47ece62a7260df219204ea948b2c15"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@09411b2a4b47ece62a7260df219204ea948b2c15",
"title": "09411b2a4b47ece62a7260df219204ea948b2c15",
"url": "https://chromium.googlesource.com/chromium/src/+/09411b2a4b47ece62a7260df219204ea948b2c15"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "453af4fbeaeff89c29c037a479d0def71529e700"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@453af4fbeaeff89c29c037a479d0def71529e700",
"title": "453af4fbeaeff89c29c037a479d0def71529e700",
"url": "https://chromium.googlesource.com/chromium/src/+/453af4fbeaeff89c29c037a479d0def71529e700"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "f8544d51605152bca5eeba5f66a8a5393363d578"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@f8544d51605152bca5eeba5f66a8a5393363d578",
"title": "f8544d51605152bca5eeba5f66a8a5393363d578",
"url": "https://chromium.googlesource.com/chromium/src/+/f8544d51605152bca5eeba5f66a8a5393363d578"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "963cb98a28cc8bb8bd6089236187695bac1803a0"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@963cb98a28cc8bb8bd6089236187695bac1803a0",
"title": "963cb98a28cc8bb8bd6089236187695bac1803a0",
"url": "https://chromium.googlesource.com/chromium/src/+/963cb98a28cc8bb8bd6089236187695bac1803a0"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "a627ade402fb5bb681e98906cf06be655f098a5d"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@a627ade402fb5bb681e98906cf06be655f098a5d",
"title": "a627ade402fb5bb681e98906cf06be655f098a5d",
"url": "https://chromium.googlesource.com/chromium/src/+/a627ade402fb5bb681e98906cf06be655f098a5d"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "17c1d6759d941f3d1757046edb85759d64834510"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@17c1d6759d941f3d1757046edb85759d64834510",
"title": "17c1d6759d941f3d1757046edb85759d64834510",
"url": "https://chromium.googlesource.com/chromium/src/+/17c1d6759d941f3d1757046edb85759d64834510"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "f1f1c9c6db1ffa6f231e0b2f6119264f386332dc"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@f1f1c9c6db1ffa6f231e0b2f6119264f386332dc",
"title": "f1f1c9c6db1ffa6f231e0b2f6119264f386332dc",
"url": "https://chromium.googlesource.com/chromium/src/+/f1f1c9c6db1ffa6f231e0b2f6119264f386332dc"
},
{
"gitiles": {
"ref": "refs/branch-heads/7727",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7727@267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac",
"title": "267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac",
"url": "https://chromium.googlesource.com/chromium/src/+/267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac",
"ref": "refs/branch-heads/7727"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8851458354013792960"
},
{
"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"
}
}
[03:28:48.950] Scheduled build:
{
"id": "8686028292139942609",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"number": 138,
"createdBy": "project:chromium-m147",
"createTime": "2026-03-29T03:28:48.416910358Z",
"updateTime": "2026-03-29T03:28:48.416910358Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac",
"ref": "refs/branch-heads/7727"
}
}
}
[03:28:48.950] Task URL: https://cr-buildbucket.appspot.com/build/8686028292139942609
[03:28:48.950] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:2:0) after 5m16s
[03:28:49.950] Received PubSub notification, asking Buildbucket for the build status
[03:28:49.977] Build status: SCHEDULED
[03:28:53.259] Received PubSub notification, asking Buildbucket for the build status
[03:28:53.287] Build status: STARTED
[03:34:06.366] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:2:0)
[03:34:06.404] Build status: STARTED
[03:34:06.404] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:5:0) after 1m26s
[03:35:32.419] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:5:0)
[03:35:32.436] Build status: STARTED
[03:35:32.436] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:6:0) after 5m16s
[03:40:48.549] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:6:0)
[03:40:48.578] Build status: STARTED
[03:40:48.578] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:7:0) after 3m0s
[03:43:48.684] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:7:0)
[03:43:48.707] Build status: STARTED
[03:43:48.707] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:8:0) after 2m23s
[03:46:11.831] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:8:0)
[03:46:11.851] Build status: STARTED
[03:46:11.851] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:9:0) after 4m25s
[03:50:37.317] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:9:0)
[03:50:37.334] Build status: STARTED
[03:50:37.334] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:10:0) after 6m15s
[03:56:52.351] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:10:0)
[03:56:52.378] Build status: STARTED
[03:56:52.378] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:11:0) after 2m9s
[03:59:01.434] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:11:0)
[03:59:01.455] Build status: STARTED
[03:59:01.455] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:12:0) after 7m10s
[04:06:11.566] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:12:0)
[04:06:11.632] Build status: STARTED
[04:06:11.632] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:13:0) after 3m18s
[04:09:29.744] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:13:0)
[04:09:29.767] Build status: STARTED
[04:09:29.767] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:14:0) after 9m57s
[04:19:26.828] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:14:0)
[04:19:26.847] Build status: STARTED
[04:19:26.847] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:15:0) after 2m4s
[04:21:31.064] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:15:0)
[04:21:31.085] Build status: STARTED
[04:21:31.085] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:16:0) after 7m13s
[04:28:44.555] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:16:0)
[04:28:44.573] Build status: STARTED
[04:28:44.573] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:17:0) after 5m46s
[04:34:30.592] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:17:0)
[04:34:30.641] Build status: STARTED
[04:34:30.641] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:18:0) after 4m35s
[04:39:05.708] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:18:0)
[04:39:05.728] Build status: STARTED
[04:39:05.728] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:19:0) after 8m39s
[04:47:44.745] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:19:0)
[04:47:44.762] Build status: STARTED
[04:47:44.762] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:20:0) after 9m4s
[04:56:48.780] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:20:0)
[04:56:48.804] Build status: STARTED
[04:56:48.804] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:21:0) after 4m3s
[05:00:51.821] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:21:0)
[05:00:51.842] Build status: STARTED
[05:00:51.842] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:22:0) after 1m3s
[05:01:54.919] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:22:0)
[05:01:54.993] Build status: STARTED
[05:01:54.993] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:23:0) after 4m52s
[05:06:47.006] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:23:0)
[05:06:47.023] Build status: STARTED
[05:06:47.024] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:24:0) after 8m2s
[05:14:49.042] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:24:0)
[05:14:49.060] Build status: STARTED
[05:14:49.060] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:25:0) after 1m58s
[05:16:47.485] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:25:0)
[05:16:47.513] Build status: STARTED
[05:16:47.513] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:26:0) after 4m59s
[05:21:46.527] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:26:0)
[05:21:46.543] Build status: STARTED
[05:21:46.543] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:27:0) after 8m49s
[05:30:35.656] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:27:0)
[05:30:35.685] Build status: STARTED
[05:30:35.685] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:28:0) after 1m2s
[05:31:38.175] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:28:0)
[05:31:38.191] Build status: STARTED
[05:31:38.191] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:29:0) after 1m48s
[05:33:26.207] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:29:0)
[05:33:26.247] Build status: STARTED
[05:33:26.248] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:30:0) after 9m50s
[05:43:16.476] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:30:0)
[05:43:16.523] Build status: STARTED
[05:43:16.523] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:31:0) after 9m3s
[05:52:19.555] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:31:0)
[05:52:19.665] Build status: STARTED
[05:52:19.665] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:32:0) after 5m39s
[05:57:58.768] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:32:0)
[05:57:58.850] Build status: STARTED
[05:57:58.850] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:33:0) after 7m19s
[06:05:18.247] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:33:0)
[06:05:18.264] Build status: STARTED
[06:05:18.264] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:34:0) after 6m42s
[06:12:00.287] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:34:0)
[06:12:00.309] Build status: STARTED
[06:12:00.309] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:35:0) after 3m48s
[06:15:48.330] Handling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:35:0)
[06:15:48.349] Build status: STARTED
[06:15:48.349] Scheduling timer "check-buildbucket-build-status" (chromium-m147/win-official:8851458354013792960:36:0) after 9m21s
[06:23:55.574] Received PubSub notification, asking Buildbucket for the build status
[06:23:55.598] Build:
{
"id": "8686028292139942609",
"builder": {
"project": "chromium-m147",
"bucket": "ci",
"builder": "win-official"
},
"number": 138,
"createdBy": "project:chromium-m147",
"createTime": "2026-03-29T03:28:48.416910358Z",
"startTime": "2026-03-29T03:28:53.103861164Z",
"endTime": "2026-03-29T06:23:55.222517211Z",
"updateTime": "2026-03-29T06:23:55.222517211Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "267b9f2b8e35ff4bf10f53cc8e6910f9fd6fecac",
"ref": "refs/branch-heads/7727"
}
}
}
[06:23:55.598] Invocation finished in 2h55m8.353049041s with status SUCCEEDED