[16:59:42.731] New invocation is queued and will start shortly
[16:59:43.820] Starting the invocation (attempt 1)
[16:59:43.840] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/d48f14b28eb9f6ee60a7797649d89c843fd32364"
[16:59:43.840] Popped gitiles commit info from properties and tags
[16:59:43.840] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[16:59:43.840] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[16:59:43.840] Buildbucket request:
{
"requestId": "8860920016515256480",
"builder": {
"project": "chromium-m142",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8860920016515256480",
"job": "chromium-m142/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7444",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "6800fa41ce89f6a5b25d7fd95206a66230b97560"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7444@6800fa41ce89f6a5b25d7fd95206a66230b97560",
"title": "6800fa41ce89f6a5b25d7fd95206a66230b97560",
"url": "https://chromium.googlesource.com/chromium/src/+/6800fa41ce89f6a5b25d7fd95206a66230b97560"
},
{
"gitiles": {
"ref": "refs/branch-heads/7444",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "774af8568649b3d85c4e56882332ce0b4449a72e"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7444@774af8568649b3d85c4e56882332ce0b4449a72e",
"title": "774af8568649b3d85c4e56882332ce0b4449a72e",
"url": "https://chromium.googlesource.com/chromium/src/+/774af8568649b3d85c4e56882332ce0b4449a72e"
},
{
"gitiles": {
"ref": "refs/branch-heads/7444",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "e1f966657a389fee2979f530b9590aed95cf1e57"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7444@e1f966657a389fee2979f530b9590aed95cf1e57",
"title": "e1f966657a389fee2979f530b9590aed95cf1e57",
"url": "https://chromium.googlesource.com/chromium/src/+/e1f966657a389fee2979f530b9590aed95cf1e57"
},
{
"gitiles": {
"ref": "refs/branch-heads/7444",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "7e645b4aac33d562af68f26f8ce433efb918274a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7444@7e645b4aac33d562af68f26f8ce433efb918274a",
"title": "7e645b4aac33d562af68f26f8ce433efb918274a",
"url": "https://chromium.googlesource.com/chromium/src/+/7e645b4aac33d562af68f26f8ce433efb918274a"
},
{
"gitiles": {
"ref": "refs/branch-heads/7444",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "d48f14b28eb9f6ee60a7797649d89c843fd32364"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7444@d48f14b28eb9f6ee60a7797649d89c843fd32364",
"title": "d48f14b28eb9f6ee60a7797649d89c843fd32364",
"url": "https://chromium.googlesource.com/chromium/src/+/d48f14b28eb9f6ee60a7797649d89c843fd32364"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d48f14b28eb9f6ee60a7797649d89c843fd32364",
"ref": "refs/branch-heads/7444"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8860920016515256480"
},
{
"key": "scheduler_job_id",
"value": "chromium-m142/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[16:59:44.682] Scheduled build:
{
"id": "8695489954568574657",
"builder": {
"project": "chromium-m142",
"bucket": "ci",
"builder": "win32-official"
},
"number": 471,
"createdBy": "project:chromium-m142",
"createTime": "2025-12-14T16:59:43.967958050Z",
"updateTime": "2025-12-14T16:59:43.967958050Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d48f14b28eb9f6ee60a7797649d89c843fd32364",
"ref": "refs/branch-heads/7444"
}
},
"canary": true
}
[16:59:44.682] Task URL: https://cr-buildbucket.appspot.com/build/8695489954568574657
[16:59:44.682] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:2:0) after 3m4s
[16:59:45.623] Received PubSub notification, asking Buildbucket for the build status
[16:59:45.637] Build status: SCHEDULED
[17:01:07.861] Received PubSub notification, asking Buildbucket for the build status
[17:01:07.891] Build status: STARTED
[17:02:48.751] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:2:0)
[17:02:48.767] Build status: STARTED
[17:02:48.768] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:5:0) after 6m8s
[17:08:56.758] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:5:0)
[17:08:56.788] Build status: STARTED
[17:08:56.789] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:6:0) after 1m32s
[17:10:28.805] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:6:0)
[17:10:28.936] Build status: STARTED
[17:10:28.936] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:7:0) after 1m30s
[17:11:58.956] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:7:0)
[17:11:58.970] Build status: STARTED
[17:11:58.970] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:8:0) after 5m58s
[17:17:57.149] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:8:0)
[17:17:57.169] Build status: STARTED
[17:17:57.169] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:9:0) after 1m28s
[17:19:25.299] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:9:0)
[17:19:25.316] Build status: STARTED
[17:19:25.316] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:10:0) after 6m58s
[17:26:23.332] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:10:0)
[17:26:23.400] Build status: STARTED
[17:26:23.400] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:11:0) after 7m30s
[17:33:53.413] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:11:0)
[17:33:53.485] Build status: STARTED
[17:33:53.485] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:12:0) after 2m25s
[17:36:18.982] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:12:0)
[17:36:19.006] Build status: STARTED
[17:36:19.006] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:13:0) after 1m5s
[17:37:24.084] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:13:0)
[17:37:24.100] Build status: STARTED
[17:37:24.100] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:14:0) after 7m16s
[17:44:40.068] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:14:0)
[17:44:40.095] Build status: STARTED
[17:44:40.095] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:15:0) after 1m15s
[17:45:55.107] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:15:0)
[17:45:55.124] Build status: STARTED
[17:45:55.124] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:16:0) after 1m19s
[17:47:14.128] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:16:0)
[17:47:14.146] Build status: STARTED
[17:47:14.146] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:17:0) after 2m44s
[17:49:58.160] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:17:0)
[17:49:58.178] Build status: STARTED
[17:49:58.178] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:18:0) after 4m43s
[17:54:41.416] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:18:0)
[17:54:41.432] Build status: STARTED
[17:54:41.432] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:19:0) after 4m26s
[17:59:07.498] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:19:0)
[17:59:07.514] Build status: STARTED
[17:59:07.514] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:20:0) after 5m17s
[18:04:24.527] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:20:0)
[18:04:24.543] Build status: STARTED
[18:04:24.543] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:21:0) after 9m40s
[18:14:04.557] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:21:0)
[18:14:04.576] Build status: STARTED
[18:14:04.576] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:22:0) after 7m4s
[18:21:08.589] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:22:0)
[18:21:08.619] Build status: STARTED
[18:21:08.619] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:23:0) after 1m19s
[18:22:27.633] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:23:0)
[18:22:27.654] Build status: STARTED
[18:22:27.654] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:24:0) after 1m40s
[18:24:07.781] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:24:0)
[18:24:07.796] Build status: STARTED
[18:24:07.796] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:25:0) after 4m11s
[18:28:18.813] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:25:0)
[18:28:18.830] Build status: STARTED
[18:28:18.831] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:26:0) after 9m24s
[18:37:43.197] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:26:0)
[18:37:43.215] Build status: STARTED
[18:37:43.215] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:27:0) after 3m38s
[18:41:21.209] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:27:0)
[18:41:21.288] Build status: STARTED
[18:41:21.288] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:28:0) after 3m52s
[18:45:13.378] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:28:0)
[18:45:13.455] Build status: STARTED
[18:45:13.455] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:29:0) after 4m14s
[18:49:27.649] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:29:0)
[18:49:27.664] Build status: STARTED
[18:49:27.664] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:30:0) after 8m14s
[18:57:41.684] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:30:0)
[18:57:41.700] Build status: STARTED
[18:57:41.701] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:31:0) after 4m45s
[19:02:26.724] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:31:0)
[19:02:26.741] Build status: STARTED
[19:02:26.741] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:32:0) after 2m7s
[19:04:33.759] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:32:0)
[19:04:33.778] Build status: STARTED
[19:04:33.778] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:33:0) after 5m7s
[19:09:40.804] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:33:0)
[19:09:40.837] Build status: STARTED
[19:09:40.837] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:34:0) after 6m52s
[19:16:33.209] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:34:0)
[19:16:33.225] Build status: STARTED
[19:16:33.225] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:35:0) after 5m50s
[19:22:23.238] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:35:0)
[19:22:23.300] Build status: STARTED
[19:22:23.300] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:36:0) after 6m55s
[19:29:18.322] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:36:0)
[19:29:18.336] Build status: STARTED
[19:29:18.336] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:37:0) after 4m9s
[19:33:27.350] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:37:0)
[19:33:27.372] Build status: STARTED
[19:33:27.372] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:38:0) after 3m20s
[19:36:47.533] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:38:0)
[19:36:47.562] Build status: STARTED
[19:36:47.562] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:39:0) after 2m13s
[19:39:00.577] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:39:0)
[19:39:00.597] Build status: STARTED
[19:39:00.597] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:40:0) after 9m10s
[19:48:10.615] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:40:0)
[19:48:10.647] Build status: STARTED
[19:48:10.647] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:41:0) after 2m59s
[19:51:09.713] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:41:0)
[19:51:09.731] Build status: STARTED
[19:51:09.731] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:42:0) after 9m38s
[20:00:47.849] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:42:0)
[20:00:47.862] Build status: STARTED
[20:00:47.862] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:43:0) after 3m40s
[20:04:27.906] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:43:0)
[20:04:27.928] Build status: STARTED
[20:04:27.928] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:44:0) after 5m21s
[20:09:49.077] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:44:0)
[20:09:49.167] Build status: STARTED
[20:09:49.167] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:45:0) after 6m49s
[20:16:38.183] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:45:0)
[20:16:38.196] Build status: STARTED
[20:16:38.196] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:46:0) after 2m55s
[20:19:33.313] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:46:0)
[20:19:33.330] Build status: STARTED
[20:19:33.330] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:47:0) after 8m59s
[20:28:32.374] Handling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:47:0)
[20:28:32.391] Build status: STARTED
[20:28:32.391] Scheduling timer "check-buildbucket-build-status" (chromium-m142/win32-official:8860920016515256480:48:0) after 3m28s
[20:28:35.519] Received PubSub notification, asking Buildbucket for the build status
[20:28:35.532] Build:
{
"id": "8695489954568574657",
"builder": {
"project": "chromium-m142",
"bucket": "ci",
"builder": "win32-official"
},
"number": 471,
"createdBy": "project:chromium-m142",
"createTime": "2025-12-14T16:59:43.967958050Z",
"startTime": "2025-12-14T17:01:07.579365967Z",
"endTime": "2025-12-14T20:28:34.981513031Z",
"updateTime": "2025-12-14T20:28:34.981513031Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d48f14b28eb9f6ee60a7797649d89c843fd32364",
"ref": "refs/branch-heads/7444"
}
},
"canary": true
}
[20:28:35.532] Invocation finished in 3h28m52.804335472s with status SUCCEEDED