[15:49:42.923] New invocation is queued and will start shortly
[15:49:43.978] Starting the invocation (attempt 1)
[15:49:44.003] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/b1a74447f251f21e4868ab7547dcd12b74336787"
[15:49:44.003] Popped gitiles commit info from properties and tags
[15:49:44.003] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:49:44.003] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:49:44.004] Buildbucket request:
{
"requestId": "8867175611021992656",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8867175611021992656",
"job": "chromium-m140/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "71fad13d5205d2e6383d1c26242ddf67d0c82c67"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@71fad13d5205d2e6383d1c26242ddf67d0c82c67",
"title": "71fad13d5205d2e6383d1c26242ddf67d0c82c67",
"url": "https://chromium.googlesource.com/chromium/src/+/71fad13d5205d2e6383d1c26242ddf67d0c82c67"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "38727556e470ba6aa096bafe7e76dc257f2de8d8"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@38727556e470ba6aa096bafe7e76dc257f2de8d8",
"title": "38727556e470ba6aa096bafe7e76dc257f2de8d8",
"url": "https://chromium.googlesource.com/chromium/src/+/38727556e470ba6aa096bafe7e76dc257f2de8d8"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "d5532c3c7abdaf4bc08f310c124214db7a518a74"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@d5532c3c7abdaf4bc08f310c124214db7a518a74",
"title": "d5532c3c7abdaf4bc08f310c124214db7a518a74",
"url": "https://chromium.googlesource.com/chromium/src/+/d5532c3c7abdaf4bc08f310c124214db7a518a74"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "12d4731dbf2cb128b9e328caea8512e30a74ca7c"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@12d4731dbf2cb128b9e328caea8512e30a74ca7c",
"title": "12d4731dbf2cb128b9e328caea8512e30a74ca7c",
"url": "https://chromium.googlesource.com/chromium/src/+/12d4731dbf2cb128b9e328caea8512e30a74ca7c"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "482af1d5693e4b0f69bfe2d56ea3208f8960be82"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@482af1d5693e4b0f69bfe2d56ea3208f8960be82",
"title": "482af1d5693e4b0f69bfe2d56ea3208f8960be82",
"url": "https://chromium.googlesource.com/chromium/src/+/482af1d5693e4b0f69bfe2d56ea3208f8960be82"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "313ad3cebf9654245491034201b839866baf3b90"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@313ad3cebf9654245491034201b839866baf3b90",
"title": "313ad3cebf9654245491034201b839866baf3b90",
"url": "https://chromium.googlesource.com/chromium/src/+/313ad3cebf9654245491034201b839866baf3b90"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "1c2f6781e89866b94c89bac5902814094c54eb6e"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@1c2f6781e89866b94c89bac5902814094c54eb6e",
"title": "1c2f6781e89866b94c89bac5902814094c54eb6e",
"url": "https://chromium.googlesource.com/chromium/src/+/1c2f6781e89866b94c89bac5902814094c54eb6e"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ab0ba41bd0bd01d269f3cae86cbca6957c1eb186"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@ab0ba41bd0bd01d269f3cae86cbca6957c1eb186",
"title": "ab0ba41bd0bd01d269f3cae86cbca6957c1eb186",
"url": "https://chromium.googlesource.com/chromium/src/+/ab0ba41bd0bd01d269f3cae86cbca6957c1eb186"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "512ad80411baf192774d66a619cd57da200b6b46"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@512ad80411baf192774d66a619cd57da200b6b46",
"title": "512ad80411baf192774d66a619cd57da200b6b46",
"url": "https://chromium.googlesource.com/chromium/src/+/512ad80411baf192774d66a619cd57da200b6b46"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b03d6df5f30bc73c7a703f60acb99159da87dcba"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@b03d6df5f30bc73c7a703f60acb99159da87dcba",
"title": "b03d6df5f30bc73c7a703f60acb99159da87dcba",
"url": "https://chromium.googlesource.com/chromium/src/+/b03d6df5f30bc73c7a703f60acb99159da87dcba"
},
{
"gitiles": {
"ref": "refs/branch-heads/7339",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b1a74447f251f21e4868ab7547dcd12b74336787"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@b1a74447f251f21e4868ab7547dcd12b74336787",
"title": "b1a74447f251f21e4868ab7547dcd12b74336787",
"url": "https://chromium.googlesource.com/chromium/src/+/b1a74447f251f21e4868ab7547dcd12b74336787"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b1a74447f251f21e4868ab7547dcd12b74336787",
"ref": "refs/branch-heads/7339"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8867175611021992656"
},
{
"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"
}
}
[15:49:44.535] Scheduled build:
{
"id": "8701745549167708321",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"number": 388,
"createdBy": "project:chromium-m140",
"createTime": "2025-10-06T15:49:44.064906683Z",
"updateTime": "2025-10-06T15:49:44.064906683Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b1a74447f251f21e4868ab7547dcd12b74336787",
"ref": "refs/branch-heads/7339"
}
},
"canary": true
}
[15:49:44.535] Task URL: https://cr-buildbucket.appspot.com/build/8701745549167708321
[15:49:44.535] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:2:0) after 3m25s
[15:49:45.528] Received PubSub notification, asking Buildbucket for the build status
[15:49:45.550] Build status: SCHEDULED
[15:49:48.301] Received PubSub notification, asking Buildbucket for the build status
[15:49:48.328] Build status: STARTED
[15:53:09.550] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:2:0)
[15:53:09.572] Build status: STARTED
[15:53:09.572] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:5:0) after 2m30s
[15:55:39.599] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:5:0)
[15:55:39.614] Build status: STARTED
[15:55:39.614] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:6:0) after 3m10s
[15:58:49.640] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:6:0)
[15:58:49.662] Build status: STARTED
[15:58:49.662] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:7:0) after 2m16s
[16:01:05.884] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:7:0)
[16:01:05.905] Build status: STARTED
[16:01:05.905] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:8:0) after 1m13s
[16:02:18.922] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:8:0)
[16:02:18.941] Build status: STARTED
[16:02:18.941] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:9:0) after 4m25s
[16:06:43.957] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:9:0)
[16:06:43.995] Build status: STARTED
[16:06:43.995] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:10:0) after 4m58s
[16:11:42.057] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:10:0)
[16:11:42.080] Build status: STARTED
[16:11:42.081] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:11:0) after 5m1s
[16:16:43.098] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:11:0)
[16:16:43.144] Build status: STARTED
[16:16:43.144] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:12:0) after 8m26s
[16:25:09.259] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:12:0)
[16:25:09.285] Build status: STARTED
[16:25:09.285] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:13:0) after 2m21s
[16:27:30.299] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:13:0)
[16:27:30.319] Build status: STARTED
[16:27:30.319] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:14:0) after 8m46s
[16:36:16.358] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:14:0)
[16:36:16.374] Build status: STARTED
[16:36:16.374] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:15:0) after 4m3s
[16:40:19.392] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:15:0)
[16:40:19.406] Build status: STARTED
[16:40:19.406] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:16:0) after 9m42s
[16:50:01.428] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:16:0)
[16:50:01.463] Build status: STARTED
[16:50:01.464] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:17:0) after 7m0s
[16:57:01.553] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:17:0)
[16:57:01.570] Build status: STARTED
[16:57:01.570] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:18:0) after 7m47s
[17:04:48.716] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:18:0)
[17:04:48.748] Build status: STARTED
[17:04:48.748] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:19:0) after 7m28s
[17:12:16.763] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:19:0)
[17:12:16.787] Build status: STARTED
[17:12:16.787] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:20:0) after 8m24s
[17:20:40.817] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:20:0)
[17:20:40.832] Build status: STARTED
[17:20:40.832] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:21:0) after 7m54s
[17:28:34.845] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:21:0)
[17:28:34.866] Build status: STARTED
[17:28:34.866] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:22:0) after 4m47s
[17:33:21.977] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:22:0)
[17:33:21.997] Build status: STARTED
[17:33:21.997] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:23:0) after 9m57s
[17:43:19.024] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:23:0)
[17:43:19.062] Build status: STARTED
[17:43:19.062] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:24:0) after 3m10s
[17:46:29.029] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:24:0)
[17:46:29.048] Build status: STARTED
[17:46:29.048] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:25:0) after 7m9s
[17:53:38.064] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:25:0)
[17:53:38.082] Build status: STARTED
[17:53:38.082] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:26:0) after 1m29s
[17:55:07.199] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:26:0)
[17:55:07.221] Build status: STARTED
[17:55:07.221] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:27:0) after 1m0s
[17:56:07.467] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:27:0)
[17:56:07.483] Build status: STARTED
[17:56:07.483] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:28:0) after 3m50s
[17:59:57.499] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:28:0)
[17:59:57.529] Build status: STARTED
[17:59:57.529] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:29:0) after 3m49s
[18:03:46.693] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:29:0)
[18:03:46.725] Build status: STARTED
[18:03:46.725] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:30:0) after 5m20s
[18:09:06.742] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:30:0)
[18:09:06.779] Build status: STARTED
[18:09:06.779] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:31:0) after 4m55s
[18:14:01.850] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:31:0)
[18:14:01.875] Build status: STARTED
[18:14:01.875] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:32:0) after 4m4s
[18:18:05.936] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:32:0)
[18:18:05.970] Build status: STARTED
[18:18:05.970] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:33:0) after 8m33s
[18:26:39.021] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:33:0)
[18:26:39.042] Build status: STARTED
[18:26:39.042] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:34:0) after 7m28s
[18:34:07.093] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:34:0)
[18:34:07.181] Build status: STARTED
[18:34:07.181] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:35:0) after 5m28s
[18:39:35.206] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:35:0)
[18:39:35.240] Build status: STARTED
[18:39:35.241] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:36:0) after 7m30s
[18:47:05.296] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:36:0)
[18:47:05.316] Build status: STARTED
[18:47:05.316] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:37:0) after 8m23s
[18:55:28.462] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:37:0)
[18:55:28.482] Build status: STARTED
[18:55:28.482] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:38:0) after 9m44s
[19:05:12.500] Handling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:38:0)
[19:05:12.518] Build status: STARTED
[19:05:12.518] Scheduling timer "check-buildbucket-build-status" (chromium-m140/win32-official:8867175611021992656:39:0) after 3m48s
[19:07:39.443] Received PubSub notification, asking Buildbucket for the build status
[19:07:39.461] Build:
{
"id": "8701745549167708321",
"builder": {
"project": "chromium-m140",
"bucket": "ci",
"builder": "win32-official"
},
"number": 388,
"createdBy": "project:chromium-m140",
"createTime": "2025-10-06T15:49:44.064906683Z",
"startTime": "2025-10-06T15:49:48.139812590Z",
"endTime": "2025-10-06T19:07:38.559156450Z",
"updateTime": "2025-10-06T19:07:38.559156450Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b1a74447f251f21e4868ab7547dcd12b74336787",
"ref": "refs/branch-heads/7339"
}
},
"canary": true
}
[19:07:39.461] Invocation finished in 3h17m56.548908632s with status SUCCEEDED