[01:24:38.960] New invocation is queued and will start shortly
[01:24:40.292] Starting the invocation (attempt 1)
[01:24:40.318] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/26d86363d34ebe548f6928c6e1b26734415a198a"
[01:24:40.318] Popped gitiles commit info from properties and tags
[01:24:40.318] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[01:24:40.319] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[01:24:40.319] Buildbucket request:
{
"requestId": "8868770184694090160",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8868770184694090160",
"job": "chromium-m140/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "489a27c4ed108c18e146293f724514b1d0eb254e"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@489a27c4ed108c18e146293f724514b1d0eb254e",
"title": "489a27c4ed108c18e146293f724514b1d0eb254e",
"url": "https://chromium.googlesource.com/chromium/src/+/489a27c4ed108c18e146293f724514b1d0eb254e"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "1ab1cf6d3bf7d9a66a67daa76ffc253db13ae8ff"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@1ab1cf6d3bf7d9a66a67daa76ffc253db13ae8ff",
"title": "1ab1cf6d3bf7d9a66a67daa76ffc253db13ae8ff",
"url": "https://chromium.googlesource.com/chromium/src/+/1ab1cf6d3bf7d9a66a67daa76ffc253db13ae8ff"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "4a6621f1a1af08eb5db1eae8f95de52b9fa41aad"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@4a6621f1a1af08eb5db1eae8f95de52b9fa41aad",
"title": "4a6621f1a1af08eb5db1eae8f95de52b9fa41aad",
"url": "https://chromium.googlesource.com/chromium/src/+/4a6621f1a1af08eb5db1eae8f95de52b9fa41aad"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "187e96e2de445630fcd199e66e3424f55442000c"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@187e96e2de445630fcd199e66e3424f55442000c",
"title": "187e96e2de445630fcd199e66e3424f55442000c",
"url": "https://chromium.googlesource.com/chromium/src/+/187e96e2de445630fcd199e66e3424f55442000c"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "7824641e5b68699b653de691a75c3c54489a0fcd"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@7824641e5b68699b653de691a75c3c54489a0fcd",
"title": "7824641e5b68699b653de691a75c3c54489a0fcd",
"url": "https://chromium.googlesource.com/chromium/src/+/7824641e5b68699b653de691a75c3c54489a0fcd"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "859d65443138dee595e675e56906e0e4650adfb9"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@859d65443138dee595e675e56906e0e4650adfb9",
"title": "859d65443138dee595e675e56906e0e4650adfb9",
"url": "https://chromium.googlesource.com/chromium/src/+/859d65443138dee595e675e56906e0e4650adfb9"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ed9c47ffabe29e5c07ccd200e0642ea9865b6b76"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@ed9c47ffabe29e5c07ccd200e0642ea9865b6b76",
"title": "ed9c47ffabe29e5c07ccd200e0642ea9865b6b76",
"url": "https://chromium.googlesource.com/chromium/src/+/ed9c47ffabe29e5c07ccd200e0642ea9865b6b76"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "aa344b576673be804b9d7fe21d0a66ed01ccf1b0"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@aa344b576673be804b9d7fe21d0a66ed01ccf1b0",
"title": "aa344b576673be804b9d7fe21d0a66ed01ccf1b0",
"url": "https://chromium.googlesource.com/chromium/src/+/aa344b576673be804b9d7fe21d0a66ed01ccf1b0"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "26d86363d34ebe548f6928c6e1b26734415a198a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@26d86363d34ebe548f6928c6e1b26734415a198a",
"title": "26d86363d34ebe548f6928c6e1b26734415a198a",
"url": "https://chromium.googlesource.com/chromium/src/+/26d86363d34ebe548f6928c6e1b26734415a198a"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "26d86363d34ebe548f6928c6e1b26734415a198a",
"ref": "refs/branch-heads/7339"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8868770184694090160"
},
{
"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"
}
}
[01:24:40.859] Scheduled build:
{
"id": "8703340122551216513",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"number": 271,
"createdBy": "project:chromium-m140",
"createTime": "2025-09-19T01:24:40.382294664Z",
"updateTime": "2025-09-19T01:24:40.382294664Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "26d86363d34ebe548f6928c6e1b26734415a198a",
"ref": "refs/branch-heads/7339"
}
},
"canary": true
}
[01:24:40.860] Task URL: https://cr-buildbucket.appspot.com/build/8703340122551216513
[01:24:40.860] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:2:0) after 2m50s
[01:24:40.937] Received PubSub notification, asking Buildbucket for the build status
[01:24:40.966] Build status: SCHEDULED
[01:24:45.115] Received PubSub notification, asking Buildbucket for the build status
[01:24:45.133] Build status: STARTED
[01:27:30.874] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:2:0)
[01:27:30.893] Build status: STARTED
[01:27:30.893] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:5:0) after 9m51s
[01:37:21.955] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:5:0)
[01:37:22.112] Build status: STARTED
[01:37:22.112] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:6:0) after 5m4s
[01:42:26.128] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:6:0)
[01:42:26.161] Build status: STARTED
[01:42:26.162] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:7:0) after 4m20s
[01:46:46.219] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:7:0)
[01:46:46.386] Build status: STARTED
[01:46:46.386] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:8:0) after 8m11s
[01:54:57.441] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:8:0)
[01:54:57.462] Build status: STARTED
[01:54:57.462] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:9:0) after 8m32s
[02:03:29.486] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:9:0)
[02:03:29.506] Build status: STARTED
[02:03:29.506] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:10:0) after 9m18s
[02:12:47.527] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:10:0)
[02:12:47.566] Build status: STARTED
[02:12:47.566] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:11:0) after 9m24s
[02:22:11.630] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:11:0)
[02:22:11.646] Build status: STARTED
[02:22:11.646] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:12:0) after 4m20s
[02:26:31.712] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:12:0)
[02:26:31.731] Build status: STARTED
[02:26:31.731] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:13:0) after 2m11s
[02:28:42.748] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:13:0)
[02:28:42.779] Build status: STARTED
[02:28:42.779] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:14:0) after 4m48s
[02:33:30.797] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:14:0)
[02:33:30.829] Build status: STARTED
[02:33:30.829] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:15:0) after 6m18s
[02:39:48.848] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:15:0)
[02:39:48.869] Build status: STARTED
[02:39:48.869] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:16:0) after 1m43s
[02:41:31.937] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:16:0)
[02:41:31.980] Build status: STARTED
[02:41:31.980] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:17:0) after 8m18s
[02:49:49.996] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:17:0)
[02:49:50.014] Build status: STARTED
[02:49:50.014] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:18:0) after 3m28s
[02:53:18.047] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:18:0)
[02:53:18.074] Build status: STARTED
[02:53:18.074] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:19:0) after 5m32s
[02:58:50.089] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:19:0)
[02:58:50.109] Build status: STARTED
[02:58:50.109] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:20:0) after 4m9s
[03:02:59.123] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:20:0)
[03:02:59.145] Build status: STARTED
[03:02:59.145] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:21:0) after 1m1s
[03:04:00.140] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:21:0)
[03:04:00.166] Build status: STARTED
[03:04:00.166] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:22:0) after 9m59s
[03:13:59.187] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:22:0)
[03:13:59.270] Build status: STARTED
[03:13:59.270] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:23:0) after 1m40s
[03:15:39.295] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:23:0)
[03:15:39.313] Build status: STARTED
[03:15:39.313] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:24:0) after 1m15s
[03:16:54.385] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:24:0)
[03:16:54.411] Build status: STARTED
[03:16:54.411] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:25:0) after 2m21s
[03:19:15.387] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:25:0)
[03:19:15.416] Build status: STARTED
[03:19:15.416] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:26:0) after 2m38s
[03:21:53.437] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:26:0)
[03:21:53.459] Build status: STARTED
[03:21:53.459] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:27:0) after 3m43s
[03:25:36.474] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:27:0)
[03:25:36.491] Build status: STARTED
[03:25:36.492] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:28:0) after 4m28s
[03:30:04.542] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:28:0)
[03:30:04.563] Build status: STARTED
[03:30:04.563] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:29:0) after 1m21s
[03:31:25.599] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:29:0)
[03:31:25.624] Build status: STARTED
[03:31:25.624] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:30:0) after 2m53s
[03:34:18.614] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:30:0)
[03:34:18.636] Build status: STARTED
[03:34:18.636] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:31:0) after 8m50s
[03:43:08.615] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:31:0)
[03:43:08.649] Build status: STARTED
[03:43:08.649] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:32:0) after 2m22s
[03:45:30.720] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:32:0)
[03:45:30.740] Build status: STARTED
[03:45:30.740] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:33:0) after 4m33s
[03:50:03.770] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:33:0)
[03:50:03.791] Build status: STARTED
[03:50:03.791] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:34:0) after 4m59s
[03:55:02.770] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:34:0)
[03:55:02.795] Build status: STARTED
[03:55:02.795] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:35:0) after 7m0s
[04:02:02.918] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:35:0)
[04:02:03.003] Build status: STARTED
[04:02:03.004] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:36:0) after 6m10s
[04:08:13.067] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:36:0)
[04:08:13.103] Build status: STARTED
[04:08:13.103] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:37:0) after 5m55s
[04:14:08.173] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:37:0)
[04:14:08.194] Build status: STARTED
[04:14:08.195] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:38:0) after 2m35s
[04:16:43.210] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:38:0)
[04:16:43.227] Build status: STARTED
[04:16:43.227] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:39:0) after 9m16s
[04:25:59.240] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:39:0)
[04:25:59.288] Build status: STARTED
[04:25:59.288] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:40:0) after 9m54s
[04:35:53.314] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:40:0)
[04:35:53.336] Build status: STARTED
[04:35:53.336] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:41:0) after 8m39s
[04:44:32.355] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:41:0)
[04:44:32.403] Build status: STARTED
[04:44:32.403] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:42:0) after 3m11s
[04:47:43.419] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:42:0)
[04:47:43.462] Build status: STARTED
[04:47:43.462] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:43:0) after 4m5s
[04:51:48.640] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:43:0)
[04:51:48.657] Build status: STARTED
[04:51:48.657] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:44:0) after 2m48s
[04:54:37.047] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:44:0)
[04:54:37.064] Build status: STARTED
[04:54:37.064] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:45:0) after 5m53s
[05:00:30.418] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:45:0)
[05:00:30.504] Build status: STARTED
[05:00:30.504] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:46:0) after 6m17s
[05:06:48.018] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:46:0)
[05:06:48.041] Build status: STARTED
[05:06:48.041] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:47:0) after 9m44s
[05:16:32.103] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:47:0)
[05:16:32.118] Build status: STARTED
[05:16:32.118] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:48:0) after 8m13s
[05:24:45.137] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:48:0)
[05:24:45.209] Build status: STARTED
[05:24:45.209] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8868770184694090160:49:0) after 7m15s
[05:25:48.753] Received PubSub notification, asking Buildbucket for the build status
[05:25:48.780] Build:
{
"id": "8703340122551216513",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"number": 271,
"createdBy": "project:chromium-m140",
"createTime": "2025-09-19T01:24:40.382294664Z",
"startTime": "2025-09-19T01:24:44.682544908Z",
"endTime": "2025-09-19T05:25:48.353285298Z",
"updateTime": "2025-09-19T05:25:48.353285298Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "26d86363d34ebe548f6928c6e1b26734415a198a",
"ref": "refs/branch-heads/7339"
}
},
"canary": true
}
[05:25:48.780] Invocation finished in 4h1m9.824740334s with status SUCCEEDED