[13:51:45.722] New invocation is queued and will start shortly
[13:51:46.875] Starting the invocation (attempt 1)
[13:51:46.909] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/6793a568ae52a1e5e6b91f9608191a1f62c86e92"
[13:51:46.909] Popped gitiles commit info from properties and tags
[13:51:46.909] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[13:51:46.909] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[13:51:46.909] Buildbucket request:
{
"requestId": "8868270195596560208",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8868270195596560208",
"job": "chromium-m140/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "20a26b814811424fae667c663341b586e1d5f1dc"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@20a26b814811424fae667c663341b586e1d5f1dc",
"title": "20a26b814811424fae667c663341b586e1d5f1dc",
"url": "https://chromium.googlesource.com/chromium/src/+/20a26b814811424fae667c663341b586e1d5f1dc"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "28652e363a6f781cb01678e6c10c09335d2c79f1"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@28652e363a6f781cb01678e6c10c09335d2c79f1",
"title": "28652e363a6f781cb01678e6c10c09335d2c79f1",
"url": "https://chromium.googlesource.com/chromium/src/+/28652e363a6f781cb01678e6c10c09335d2c79f1"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "d72dd9b01a1510bd02d9c39c1237edf3db58e10f"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@d72dd9b01a1510bd02d9c39c1237edf3db58e10f",
"title": "d72dd9b01a1510bd02d9c39c1237edf3db58e10f",
"url": "https://chromium.googlesource.com/chromium/src/+/d72dd9b01a1510bd02d9c39c1237edf3db58e10f"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "3e21ccf5cac60e50cfb5a0af0c285f3ac4e11149"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@3e21ccf5cac60e50cfb5a0af0c285f3ac4e11149",
"title": "3e21ccf5cac60e50cfb5a0af0c285f3ac4e11149",
"url": "https://chromium.googlesource.com/chromium/src/+/3e21ccf5cac60e50cfb5a0af0c285f3ac4e11149"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "23b073345ddbf2b765ddf7e0cc0e863bd5c13c4d"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@23b073345ddbf2b765ddf7e0cc0e863bd5c13c4d",
"title": "23b073345ddbf2b765ddf7e0cc0e863bd5c13c4d",
"url": "https://chromium.googlesource.com/chromium/src/+/23b073345ddbf2b765ddf7e0cc0e863bd5c13c4d"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "92a451aeb49191e66de77424a64ea42d0ca8fc52"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@92a451aeb49191e66de77424a64ea42d0ca8fc52",
"title": "92a451aeb49191e66de77424a64ea42d0ca8fc52",
"url": "https://chromium.googlesource.com/chromium/src/+/92a451aeb49191e66de77424a64ea42d0ca8fc52"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "463436445571ea4d30dfcdd8428479d06eb2a268"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@463436445571ea4d30dfcdd8428479d06eb2a268",
"title": "463436445571ea4d30dfcdd8428479d06eb2a268",
"url": "https://chromium.googlesource.com/chromium/src/+/463436445571ea4d30dfcdd8428479d06eb2a268"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "a4c2aa324c285f9d1cb3aa58b3c1df4fed0fb4da"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@a4c2aa324c285f9d1cb3aa58b3c1df4fed0fb4da",
"title": "a4c2aa324c285f9d1cb3aa58b3c1df4fed0fb4da",
"url": "https://chromium.googlesource.com/chromium/src/+/a4c2aa324c285f9d1cb3aa58b3c1df4fed0fb4da"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "cc0f6d5f7b484b536c8d6cd13ca73c929927fec1"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@cc0f6d5f7b484b536c8d6cd13ca73c929927fec1",
"title": "cc0f6d5f7b484b536c8d6cd13ca73c929927fec1",
"url": "https://chromium.googlesource.com/chromium/src/+/cc0f6d5f7b484b536c8d6cd13ca73c929927fec1"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "92628de9459da1fd521bef3284ce13adcde2e361"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@92628de9459da1fd521bef3284ce13adcde2e361",
"title": "92628de9459da1fd521bef3284ce13adcde2e361",
"url": "https://chromium.googlesource.com/chromium/src/+/92628de9459da1fd521bef3284ce13adcde2e361"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "6793a568ae52a1e5e6b91f9608191a1f62c86e92"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@6793a568ae52a1e5e6b91f9608191a1f62c86e92",
"title": "6793a568ae52a1e5e6b91f9608191a1f62c86e92",
"url": "https://chromium.googlesource.com/chromium/src/+/6793a568ae52a1e5e6b91f9608191a1f62c86e92"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "6793a568ae52a1e5e6b91f9608191a1f62c86e92",
"ref": "refs/branch-heads/7339"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8868270195596560208"
},
{
"key": "scheduler_job_id",
"value": "chromium-m140/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[13:51:47.408] Scheduled build:
{
"id": "8702840133604063697",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"number": 307,
"createdBy": "project:chromium-m140",
"createTime": "2025-09-24T13:51:47.000070385Z",
"updateTime": "2025-09-24T13:51:47.000070385Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "6793a568ae52a1e5e6b91f9608191a1f62c86e92",
"ref": "refs/branch-heads/7339"
}
}
}
[13:51:47.408] Task URL: https://cr-buildbucket.appspot.com/build/8702840133604063697
[13:51:47.408] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:2:0) after 2m30s
[13:51:48.411] Received PubSub notification, asking Buildbucket for the build status
[13:51:48.449] Build status: SCHEDULED
[13:51:51.625] Received PubSub notification, asking Buildbucket for the build status
[13:51:51.641] Build status: STARTED
[13:54:17.491] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:2:0)
[13:54:17.507] Build status: STARTED
[13:54:17.507] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:5:0) after 6m28s
[14:00:45.535] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:5:0)
[14:00:45.569] Build status: STARTED
[14:00:45.569] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:6:0) after 1m24s
[14:02:09.591] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:6:0)
[14:02:09.608] Build status: STARTED
[14:02:09.608] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:7:0) after 6m22s
[14:08:31.649] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:7:0)
[14:08:31.670] Build status: STARTED
[14:08:31.670] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:8:0) after 2m29s
[14:11:00.688] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:8:0)
[14:11:00.714] Build status: STARTED
[14:11:00.714] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:9:0) after 8m56s
[14:19:56.729] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:9:0)
[14:19:56.768] Build status: STARTED
[14:19:56.768] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:10:0) after 5m44s
[14:25:40.784] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:10:0)
[14:25:40.801] Build status: STARTED
[14:25:40.801] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:11:0) after 9m47s
[14:35:27.818] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:11:0)
[14:35:27.835] Build status: STARTED
[14:35:27.835] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:12:0) after 5m59s
[14:41:26.853] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:12:0)
[14:41:26.879] Build status: STARTED
[14:41:26.879] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:13:0) after 1m38s
[14:43:04.966] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:13:0)
[14:43:04.995] Build status: STARTED
[14:43:04.995] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:14:0) after 7m10s
[14:50:15.061] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:14:0)
[14:50:15.077] Build status: STARTED
[14:50:15.077] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:15:0) after 9m29s
[14:59:44.139] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:15:0)
[14:59:44.167] Build status: STARTED
[14:59:44.167] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:16:0) after 9m22s
[15:09:06.212] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:16:0)
[15:09:06.248] Build status: STARTED
[15:09:06.248] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:17:0) after 7m41s
[15:16:47.266] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:17:0)
[15:16:47.286] Build status: STARTED
[15:16:47.286] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:18:0) after 9m19s
[15:26:06.302] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:18:0)
[15:26:06.351] Build status: STARTED
[15:26:06.352] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:19:0) after 3m29s
[15:29:35.372] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:19:0)
[15:29:35.962] Build status: STARTED
[15:29:35.962] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:20:0) after 2m10s
[15:31:46.014] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:20:0)
[15:31:46.033] Build status: STARTED
[15:31:46.033] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:21:0) after 2m19s
[15:34:05.016] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:21:0)
[15:34:05.030] Build status: STARTED
[15:34:05.030] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:22:0) after 8m26s
[15:42:31.092] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:22:0)
[15:42:31.113] Build status: STARTED
[15:42:31.113] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:23:0) after 6m42s
[15:49:13.126] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:23:0)
[15:49:13.147] Build status: STARTED
[15:49:13.147] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:24:0) after 6m45s
[15:55:58.161] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:24:0)
[15:55:58.186] Build status: STARTED
[15:55:58.186] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:25:0) after 7m0s
[16:02:58.211] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:25:0)
[16:02:58.238] Build status: STARTED
[16:02:58.238] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:26:0) after 4m30s
[16:07:28.318] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:26:0)
[16:07:28.341] Build status: STARTED
[16:07:28.341] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:27:0) after 4m3s
[16:11:31.361] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:27:0)
[16:11:31.394] Build status: STARTED
[16:11:31.394] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:28:0) after 8m51s
[16:20:22.446] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:28:0)
[16:20:22.467] Build status: STARTED
[16:20:22.467] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:29:0) after 7m47s
[16:28:09.491] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:29:0)
[16:28:09.509] Build status: STARTED
[16:28:09.509] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:30:0) after 4m0s
[16:32:09.523] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:30:0)
[16:32:09.539] Build status: STARTED
[16:32:09.539] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:31:0) after 6m28s
[16:38:37.555] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:31:0)
[16:38:37.577] Build status: STARTED
[16:38:37.577] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:32:0) after 4m49s
[16:43:26.581] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:32:0)
[16:43:26.597] Build status: STARTED
[16:43:26.597] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:33:0) after 7m3s
[16:50:29.657] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:33:0)
[16:50:29.677] Build status: STARTED
[16:50:29.677] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:34:0) after 5m19s
[16:55:48.689] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:34:0)
[16:55:48.706] Build status: STARTED
[16:55:48.706] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:35:0) after 8m28s
[17:04:16.778] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:35:0)
[17:04:16.795] Build status: STARTED
[17:04:16.795] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:36:0) after 3m37s
[17:07:53.839] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:36:0)
[17:07:53.904] Build status: STARTED
[17:07:53.904] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:37:0) after 4m40s
[17:12:33.950] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:37:0)
[17:12:33.968] Build status: STARTED
[17:12:33.968] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:38:0) after 9m25s
[17:21:58.941] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:38:0)
[17:21:58.955] Build status: STARTED
[17:21:58.955] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:39:0) after 3m56s
[17:25:55.021] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:39:0)
[17:25:55.085] Build status: STARTED
[17:25:55.085] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:40:0) after 3m49s
[17:29:44.195] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:40:0)
[17:29:44.213] Build status: STARTED
[17:29:44.213] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:41:0) after 4m42s
[17:34:26.279] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:41:0)
[17:34:26.300] Build status: STARTED
[17:34:26.300] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:42:0) after 1m17s
[17:35:43.432] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:42:0)
[17:35:43.456] Build status: STARTED
[17:35:43.456] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:43:0) after 5m56s
[17:41:39.484] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:43:0)
[17:41:39.500] Build status: STARTED
[17:41:39.500] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868270195596560208:44:0) after 9m37s
[17:43:24.849] Received PubSub notification, asking Buildbucket for the build status
[17:43:24.867] Build:
{
"id": "8702840133604063697",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"number": 307,
"createdBy": "project:chromium-m140",
"createTime": "2025-09-24T13:51:47.000070385Z",
"startTime": "2025-09-24T13:51:51.338069160Z",
"endTime": "2025-09-24T17:43:22.820051834Z",
"updateTime": "2025-09-24T17:43:22.820051834Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "6793a568ae52a1e5e6b91f9608191a1f62c86e92",
"ref": "refs/branch-heads/7339"
}
}
}
[17:43:24.867] Invocation finished in 3h51m39.15122252s with status SUCCEEDED