[23:07:08.715] New invocation is queued and will start shortly
[23:07:09.860] Starting the invocation (attempt 1)
[23:07:09.888] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/360bf9e09b87ccf6709a42fa557b0540187a18f2"
[23:07:09.888] Popped gitiles commit info from properties and tags
[23:07:09.888] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[23:07:09.888] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[23:07:09.889] Buildbucket request:
{
"requestId": "8861802869293674608",
"builder": {
"project": "chromium-m144",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8861802869293674608",
"job": "chromium-m144/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7559",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "3ee6a80dc1d30565ce6901da66f2c514d4e55303"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7559@3ee6a80dc1d30565ce6901da66f2c514d4e55303",
"title": "3ee6a80dc1d30565ce6901da66f2c514d4e55303",
"url": "https://chromium.googlesource.com/chromium/src/+/3ee6a80dc1d30565ce6901da66f2c514d4e55303"
},
{
"gitiles": {
"ref": "refs/branch-heads/7559",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "9800313ae8613716813bc704694b343d00e97828"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7559@9800313ae8613716813bc704694b343d00e97828",
"title": "9800313ae8613716813bc704694b343d00e97828",
"url": "https://chromium.googlesource.com/chromium/src/+/9800313ae8613716813bc704694b343d00e97828"
},
{
"gitiles": {
"ref": "refs/branch-heads/7559",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "3a9d5bf340d14510cfe3d8037ceef18fecafbf6a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7559@3a9d5bf340d14510cfe3d8037ceef18fecafbf6a",
"title": "3a9d5bf340d14510cfe3d8037ceef18fecafbf6a",
"url": "https://chromium.googlesource.com/chromium/src/+/3a9d5bf340d14510cfe3d8037ceef18fecafbf6a"
},
{
"gitiles": {
"ref": "refs/branch-heads/7559",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "d7a53f914a6d51b521f7039c417cf19ab2e00c34"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7559@d7a53f914a6d51b521f7039c417cf19ab2e00c34",
"title": "d7a53f914a6d51b521f7039c417cf19ab2e00c34",
"url": "https://chromium.googlesource.com/chromium/src/+/d7a53f914a6d51b521f7039c417cf19ab2e00c34"
},
{
"gitiles": {
"ref": "refs/branch-heads/7559",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "360bf9e09b87ccf6709a42fa557b0540187a18f2"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7559@360bf9e09b87ccf6709a42fa557b0540187a18f2",
"title": "360bf9e09b87ccf6709a42fa557b0540187a18f2",
"url": "https://chromium.googlesource.com/chromium/src/+/360bf9e09b87ccf6709a42fa557b0540187a18f2"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "360bf9e09b87ccf6709a42fa557b0540187a18f2",
"ref": "refs/branch-heads/7559"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8861802869293674608"
},
{
"key": "scheduler_job_id",
"value": "chromium-m144/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[23:07:10.375] Scheduled build:
{
"id": "8696372807346273457",
"builder": {
"project": "chromium-m144",
"bucket": "ci",
"builder": "win32-official"
},
"number": 17,
"createdBy": "project:chromium-m144",
"createTime": "2025-12-04T23:07:09.948296022Z",
"updateTime": "2025-12-04T23:07:09.948296022Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "360bf9e09b87ccf6709a42fa557b0540187a18f2",
"ref": "refs/branch-heads/7559"
}
}
}
[23:07:10.375] Task URL: https://cr-buildbucket.appspot.com/build/8696372807346273457
[23:07:10.375] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:2:0) after 5m30s
[23:07:11.350] Received PubSub notification, asking Buildbucket for the build status
[23:07:11.366] Build status: SCHEDULED
[23:07:15.219] Received PubSub notification, asking Buildbucket for the build status
[23:07:15.238] Build status: STARTED
[23:12:40.429] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:2:0)
[23:12:40.449] Build status: STARTED
[23:12:40.449] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:5:0) after 3m30s
[23:16:10.630] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:5:0)
[23:16:10.656] Build status: STARTED
[23:16:10.656] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:6:0) after 4m0s
[23:20:10.820] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:6:0)
[23:20:10.836] Build status: STARTED
[23:20:10.836] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:7:0) after 4m49s
[23:24:59.849] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:7:0)
[23:24:59.875] Build status: STARTED
[23:24:59.875] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:8:0) after 9m0s
[23:33:59.964] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:8:0)
[23:33:59.977] Build status: STARTED
[23:33:59.978] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:9:0) after 3m38s
[23:37:37.995] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:9:0)
[23:37:38.012] Build status: STARTED
[23:37:38.012] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:10:0) after 3m38s
[23:41:16.018] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:10:0)
[23:41:16.101] Build status: STARTED
[23:41:16.101] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:11:0) after 7m37s
[23:48:53.071] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:11:0)
[23:48:53.086] Build status: STARTED
[23:48:53.086] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:12:0) after 2m20s
[23:51:13.148] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:12:0)
[23:51:13.237] Build status: STARTED
[23:51:13.237] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:13:0) after 4m16s
[23:55:29.224] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:13:0)
[23:55:29.246] Build status: STARTED
[23:55:29.246] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:14:0) after 5m36s
[00:01:05.258] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:14:0)
[00:01:05.284] Build status: STARTED
[00:01:05.284] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:15:0) after 8m46s
[00:09:51.301] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:15:0)
[00:09:51.353] Build status: STARTED
[00:09:51.353] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:16:0) after 7m7s
[00:16:58.413] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:16:0)
[00:16:58.434] Build status: STARTED
[00:16:58.434] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:17:0) after 6m45s
[00:23:43.470] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:17:0)
[00:23:43.487] Build status: STARTED
[00:23:43.487] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:18:0) after 5m33s
[00:29:16.974] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:18:0)
[00:29:16.989] Build status: STARTED
[00:29:16.989] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:19:0) after 7m11s
[00:36:28.136] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:19:0)
[00:36:28.211] Build status: STARTED
[00:36:28.211] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:20:0) after 7m34s
[00:44:02.255] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:20:0)
[00:44:02.390] Build status: STARTED
[00:44:02.390] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:21:0) after 7m50s
[00:51:52.402] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:21:0)
[00:51:52.418] Build status: STARTED
[00:51:52.418] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:22:0) after 6m33s
[00:58:25.406] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:22:0)
[00:58:25.424] Build status: STARTED
[00:58:25.424] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:23:0) after 4m58s
[01:03:23.437] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:23:0)
[01:03:23.451] Build status: STARTED
[01:03:23.451] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:24:0) after 7m42s
[01:11:05.538] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:24:0)
[01:11:05.551] Build status: STARTED
[01:11:05.551] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:25:0) after 1m15s
[01:12:20.564] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:25:0)
[01:12:20.580] Build status: STARTED
[01:12:20.580] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:26:0) after 7m27s
[01:19:47.573] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:26:0)
[01:19:47.591] Build status: STARTED
[01:19:47.591] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:27:0) after 2m20s
[01:22:07.605] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:27:0)
[01:22:07.621] Build status: STARTED
[01:22:07.621] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:28:0) after 5m5s
[01:27:12.636] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:28:0)
[01:27:12.668] Build status: STARTED
[01:27:12.668] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:29:0) after 7m12s
[01:34:24.750] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:29:0)
[01:34:24.764] Build status: STARTED
[01:34:24.764] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:30:0) after 2m57s
[01:37:21.909] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:30:0)
[01:37:21.923] Build status: STARTED
[01:37:21.923] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:31:0) after 8m30s
[01:45:52.057] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:31:0)
[01:45:52.073] Build status: STARTED
[01:45:52.073] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:32:0) after 5m0s
[01:50:52.137] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:32:0)
[01:50:52.152] Build status: STARTED
[01:50:52.152] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:33:0) after 5m0s
[01:55:52.258] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:33:0)
[01:55:52.312] Build status: STARTED
[01:55:52.312] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:34:0) after 9m56s
[02:05:48.415] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:34:0)
[02:05:48.430] Build status: STARTED
[02:05:48.430] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:35:0) after 4m51s
[02:10:39.534] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:35:0)
[02:10:39.594] Build status: STARTED
[02:10:39.594] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:36:0) after 4m41s
[02:15:20.643] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:36:0)
[02:15:20.664] Build status: STARTED
[02:15:20.664] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:37:0) after 4m17s
[02:19:37.680] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:37:0)
[02:19:37.700] Build status: STARTED
[02:19:37.700] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:38:0) after 9m5s
[02:28:42.701] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:38:0)
[02:28:42.850] Build status: STARTED
[02:28:42.850] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:39:0) after 4m58s
[02:33:41.061] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:39:0)
[02:33:41.113] Build status: STARTED
[02:33:41.113] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:40:0) after 4m53s
[02:38:34.180] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:40:0)
[02:38:34.201] Build status: STARTED
[02:38:34.201] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:41:0) after 7m27s
[02:46:01.218] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:41:0)
[02:46:01.242] Build status: STARTED
[02:46:01.242] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:42:0) after 8m1s
[02:54:02.303] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:42:0)
[02:54:02.316] Build status: STARTED
[02:54:02.316] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:43:0) after 3m51s
[02:57:53.435] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:43:0)
[02:57:53.452] Build status: STARTED
[02:57:53.452] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:44:0) after 3m14s
[03:01:07.541] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:44:0)
[03:01:07.558] Build status: STARTED
[03:01:07.558] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:45:0) after 6m15s
[03:07:22.598] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:45:0)
[03:07:22.618] Build status: STARTED
[03:07:22.618] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:46:0) after 9m32s
[03:16:54.684] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:46:0)
[03:16:54.698] Build status: STARTED
[03:16:54.698] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:47:0) after 5m19s
[03:22:13.711] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:47:0)
[03:22:13.729] Build status: STARTED
[03:22:13.729] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:48:0) after 2m23s
[03:24:36.758] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:48:0)
[03:24:36.773] Build status: STARTED
[03:24:36.773] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:49:0) after 3m9s
[03:27:45.835] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:49:0)
[03:27:45.849] Build status: STARTED
[03:27:45.849] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:50:0) after 8m58s
[03:36:43.881] Handling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:50:0)
[03:36:43.901] Build status: STARTED
[03:36:43.901] Scheduling timer "check-buildbucket-build-status" (chromium-m144/win32-official:8861802869293674608:51:0) after 8m18s
[03:43:27.202] Received PubSub notification, asking Buildbucket for the build status
[03:43:27.221] Build:
{
"id": "8696372807346273457",
"builder": {
"project": "chromium-m144",
"bucket": "ci",
"builder": "win32-official"
},
"number": 17,
"createdBy": "project:chromium-m144",
"createTime": "2025-12-04T23:07:09.948296022Z",
"startTime": "2025-12-04T23:07:15.060510075Z",
"endTime": "2025-12-05T03:43:22.823302936Z",
"updateTime": "2025-12-05T03:43:22.823302936Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "360bf9e09b87ccf6709a42fa557b0540187a18f2",
"ref": "refs/branch-heads/7559"
}
}
}
[03:43:27.221] Invocation finished in 4h36m18.513802708s with status SUCCEEDED