[07:58:44.821] New invocation is queued and will start shortly
[07:58:46.162] Starting the invocation (attempt 1)
[07:58:46.187] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/5f04ecaa14d1e7fd1a4b583035e65540339b2feb"
[07:58:46.187] Popped gitiles commit info from properties and tags
[07:58:46.187] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[07:58:46.187] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[07:58:46.187] Buildbucket request:
{
"requestId": "8872188074951689952",
"builder": {
"project": "chromium-m138",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8872188074951689952",
"job": "chromium-m138/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "d80b83f322e49baabe936590483ffa7404ea3c5d"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@d80b83f322e49baabe936590483ffa7404ea3c5d",
"title": "d80b83f322e49baabe936590483ffa7404ea3c5d",
"url": "https://chromium.googlesource.com/chromium/src/+/d80b83f322e49baabe936590483ffa7404ea3c5d"
},
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "a770a61c358ef93364166213d64c0283b6591855"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@a770a61c358ef93364166213d64c0283b6591855",
"title": "a770a61c358ef93364166213d64c0283b6591855",
"url": "https://chromium.googlesource.com/chromium/src/+/a770a61c358ef93364166213d64c0283b6591855"
},
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "9984b3d4028350cdf1324232fdad4ac3a450ca91"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@9984b3d4028350cdf1324232fdad4ac3a450ca91",
"title": "9984b3d4028350cdf1324232fdad4ac3a450ca91",
"url": "https://chromium.googlesource.com/chromium/src/+/9984b3d4028350cdf1324232fdad4ac3a450ca91"
},
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "2ed031ac2bb23584a5952040a18da5386422e1dd"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@2ed031ac2bb23584a5952040a18da5386422e1dd",
"title": "2ed031ac2bb23584a5952040a18da5386422e1dd",
"url": "https://chromium.googlesource.com/chromium/src/+/2ed031ac2bb23584a5952040a18da5386422e1dd"
},
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "366c68035b05b9b5e69383455a4c634ea4b83bcf"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@366c68035b05b9b5e69383455a4c634ea4b83bcf",
"title": "366c68035b05b9b5e69383455a4c634ea4b83bcf",
"url": "https://chromium.googlesource.com/chromium/src/+/366c68035b05b9b5e69383455a4c634ea4b83bcf"
},
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "74f8ac488ce3a0596dec99d7dbe6f647c020c5c1"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@74f8ac488ce3a0596dec99d7dbe6f647c020c5c1",
"title": "74f8ac488ce3a0596dec99d7dbe6f647c020c5c1",
"url": "https://chromium.googlesource.com/chromium/src/+/74f8ac488ce3a0596dec99d7dbe6f647c020c5c1"
},
{
"gitiles": {
"ref": "refs/branch-heads/7204",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "5f04ecaa14d1e7fd1a4b583035e65540339b2feb"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7204@5f04ecaa14d1e7fd1a4b583035e65540339b2feb",
"title": "5f04ecaa14d1e7fd1a4b583035e65540339b2feb",
"url": "https://chromium.googlesource.com/chromium/src/+/5f04ecaa14d1e7fd1a4b583035e65540339b2feb"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "5f04ecaa14d1e7fd1a4b583035e65540339b2feb",
"ref": "refs/branch-heads/7204"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8872188074951689952"
},
{
"key": "scheduler_job_id",
"value": "chromium-m138/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[07:58:46.726] Scheduled build:
{
"id": "8706758012773817697",
"builder": {
"project": "chromium-m138",
"bucket": "ci",
"builder": "win32-official"
},
"number": 456,
"createdBy": "project:chromium-m138",
"createTime": "2025-08-12T07:58:46.261970803Z",
"updateTime": "2025-08-12T07:58:46.261970803Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "5f04ecaa14d1e7fd1a4b583035e65540339b2feb",
"ref": "refs/branch-heads/7204"
}
}
}
[07:58:46.726] Task URL: https://cr-buildbucket.appspot.com/build/8706758012773817697
[07:58:46.726] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:2:0) after 5m28s
[07:58:47.719] Received PubSub notification, asking Buildbucket for the build status
[07:58:47.749] Build status: SCHEDULED
[07:58:50.661] Received PubSub notification, asking Buildbucket for the build status
[07:58:50.683] Build status: STARTED
[08:04:14.751] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:2:0)
[08:04:14.778] Build status: STARTED
[08:04:14.778] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:5:0) after 2m37s
[08:06:51.791] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:5:0)
[08:06:51.823] Build status: STARTED
[08:06:51.823] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:6:0) after 5m35s
[08:12:26.858] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:6:0)
[08:12:26.900] Build status: STARTED
[08:12:26.900] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:7:0) after 8m6s
[08:20:32.916] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:7:0)
[08:20:32.932] Build status: STARTED
[08:20:32.932] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:8:0) after 7m3s
[08:27:35.950] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:8:0)
[08:27:35.972] Build status: STARTED
[08:27:35.972] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:9:0) after 6m8s
[08:33:43.985] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:9:0)
[08:33:44.039] Build status: STARTED
[08:33:44.039] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:10:0) after 5m34s
[08:39:18.053] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:10:0)
[08:39:18.071] Build status: STARTED
[08:39:18.072] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:11:0) after 8m21s
[08:47:39.173] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:11:0)
[08:47:39.188] Build status: STARTED
[08:47:39.189] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:12:0) after 2m47s
[08:50:26.211] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:12:0)
[08:50:26.231] Build status: STARTED
[08:50:26.231] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:13:0) after 8m59s
[08:59:25.411] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:13:0)
[08:59:25.430] Build status: STARTED
[08:59:25.430] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:14:0) after 5m6s
[09:04:31.465] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:14:0)
[09:04:32.029] Build status: STARTED
[09:04:32.029] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:15:0) after 3m47s
[09:08:19.053] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:15:0)
[09:08:19.106] Build status: STARTED
[09:08:19.106] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:16:0) after 1m41s
[09:10:00.177] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:16:0)
[09:10:00.240] Build status: STARTED
[09:10:00.240] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:17:0) after 8m30s
[09:18:30.258] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:17:0)
[09:18:30.283] Build status: STARTED
[09:18:30.283] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:18:0) after 8m59s
[09:27:29.301] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:18:0)
[09:27:29.370] Build status: STARTED
[09:27:29.370] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:19:0) after 4m34s
[09:32:03.432] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:19:0)
[09:32:03.448] Build status: STARTED
[09:32:03.449] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:20:0) after 1m6s
[09:33:09.474] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:20:0)
[09:33:09.489] Build status: STARTED
[09:33:09.489] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:21:0) after 5m23s
[09:38:32.526] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:21:0)
[09:38:32.552] Build status: STARTED
[09:38:32.552] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:22:0) after 7m6s
[09:45:38.570] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:22:0)
[09:45:38.617] Build status: STARTED
[09:45:38.617] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:23:0) after 6m44s
[09:52:22.686] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:23:0)
[09:52:22.760] Build status: STARTED
[09:52:22.760] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:24:0) after 1m35s
[09:53:57.783] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:24:0)
[09:53:57.800] Build status: STARTED
[09:53:57.800] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:25:0) after 1m28s
[09:55:25.817] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:25:0)
[09:55:25.833] Build status: STARTED
[09:55:25.833] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:26:0) after 2m40s
[09:58:05.887] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:26:0)
[09:58:05.919] Build status: STARTED
[09:58:05.919] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:27:0) after 5m50s
[10:03:56.038] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:27:0)
[10:03:56.055] Build status: STARTED
[10:03:56.055] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:28:0) after 6m6s
[10:10:02.074] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:28:0)
[10:10:02.096] Build status: STARTED
[10:10:02.096] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:29:0) after 6m24s
[10:16:26.113] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:29:0)
[10:16:26.132] Build status: STARTED
[10:16:26.132] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:30:0) after 3m1s
[10:19:27.303] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:30:0)
[10:19:27.320] Build status: STARTED
[10:19:27.320] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:31:0) after 6m13s
[10:25:40.441] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:31:0)
[10:25:40.516] Build status: STARTED
[10:25:40.516] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:32:0) after 9m8s
[10:34:48.638] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:32:0)
[10:34:48.663] Build status: STARTED
[10:34:48.663] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:33:0) after 8m3s
[10:42:52.134] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:33:0)
[10:42:52.166] Build status: STARTED
[10:42:52.166] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:34:0) after 6m58s
[10:49:50.183] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:34:0)
[10:49:50.237] Build status: STARTED
[10:49:50.237] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:35:0) after 1m42s
[10:51:32.254] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:35:0)
[10:51:32.286] Build status: STARTED
[10:51:32.286] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:36:0) after 6m35s
[10:58:07.366] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:36:0)
[10:58:07.385] Build status: STARTED
[10:58:07.385] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:37:0) after 8m46s
[11:06:53.406] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:37:0)
[11:06:53.469] Build status: STARTED
[11:06:53.469] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:38:0) after 7m21s
[11:14:14.498] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:38:0)
[11:14:14.527] Build status: STARTED
[11:14:14.527] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:39:0) after 2m11s
[11:16:25.604] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:39:0)
[11:16:25.625] Build status: STARTED
[11:16:25.625] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:40:0) after 8m38s
[11:25:03.690] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:40:0)
[11:25:03.707] Build status: STARTED
[11:25:03.707] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:41:0) after 3m26s
[11:28:29.734] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:41:0)
[11:28:29.758] Build status: STARTED
[11:28:29.758] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:42:0) after 9m8s
[11:37:37.890] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:42:0)
[11:37:37.907] Build status: STARTED
[11:37:37.907] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:43:0) after 7m59s
[11:45:36.897] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:43:0)
[11:45:36.942] Build status: STARTED
[11:45:36.942] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:44:0) after 2m11s
[11:47:47.963] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:44:0)
[11:47:47.985] Build status: STARTED
[11:47:47.985] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:45:0) after 4m4s
[11:51:52.102] Handling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:45:0)
[11:51:52.125] Build status: STARTED
[11:51:52.125] Scheduling timer "check-buildbucket-build-status" (chromium-m138/win32-official:8872188074951689952:46:0) after 7m24s
[11:54:34.203] Received PubSub notification, asking Buildbucket for the build status
[11:54:34.279] Build:
{
"id": "8706758012773817697",
"builder": {
"project": "chromium-m138",
"bucket": "ci",
"builder": "win32-official"
},
"number": 456,
"createdBy": "project:chromium-m138",
"createTime": "2025-08-12T07:58:46.261970803Z",
"startTime": "2025-08-12T07:58:50.478516637Z",
"endTime": "2025-08-12T11:54:33.953676655Z",
"updateTime": "2025-08-12T11:54:33.953676655Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "5f04ecaa14d1e7fd1a4b583035e65540339b2feb",
"ref": "refs/branch-heads/7204"
}
}
}
[11:54:34.279] Invocation finished in 3h55m49.478352782s with status SUCCEEDED