[22:51:06.794] New invocation is queued and will start shortly
[22:51:07.881] Starting the invocation (attempt 1)
[22:51:07.910] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/bfda086f291cc18d203bc7ca30631dbbb221c697"
[22:51:07.910] Popped gitiles commit info from properties and tags
[22:51:07.910] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[22:51:07.911] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[22:51:07.911] Buildbucket request:
{
"requestId": "8893150428311405728",
"builder": {
"project": "chromium-m131",
"bucket": "ci",
"builder": "win-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8893150428311405728",
"job": "chromium-m131/win-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "18450aae0452c550f3656e7017feaed883777ab8"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@18450aae0452c550f3656e7017feaed883777ab8",
"title": "18450aae0452c550f3656e7017feaed883777ab8",
"url": "https://chromium.googlesource.com/chromium/src/+/18450aae0452c550f3656e7017feaed883777ab8"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "3cb606ff318a0eff0647910437427ec158d6f725"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@3cb606ff318a0eff0647910437427ec158d6f725",
"title": "3cb606ff318a0eff0647910437427ec158d6f725",
"url": "https://chromium.googlesource.com/chromium/src/+/3cb606ff318a0eff0647910437427ec158d6f725"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "008fed860f5515ef41b0e3ace3570a145b7480ee"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@008fed860f5515ef41b0e3ace3570a145b7480ee",
"title": "008fed860f5515ef41b0e3ace3570a145b7480ee",
"url": "https://chromium.googlesource.com/chromium/src/+/008fed860f5515ef41b0e3ace3570a145b7480ee"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "08c6bd7149f436db035ae5bfb4606e982da6f731"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@08c6bd7149f436db035ae5bfb4606e982da6f731",
"title": "08c6bd7149f436db035ae5bfb4606e982da6f731",
"url": "https://chromium.googlesource.com/chromium/src/+/08c6bd7149f436db035ae5bfb4606e982da6f731"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ef30a24f29435481dec462fdb64902e862c8442b"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@ef30a24f29435481dec462fdb64902e862c8442b",
"title": "ef30a24f29435481dec462fdb64902e862c8442b",
"url": "https://chromium.googlesource.com/chromium/src/+/ef30a24f29435481dec462fdb64902e862c8442b"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "7bf96efe2650f6ee0cb8b28c4cd449cdb828704b"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@7bf96efe2650f6ee0cb8b28c4cd449cdb828704b",
"title": "7bf96efe2650f6ee0cb8b28c4cd449cdb828704b",
"url": "https://chromium.googlesource.com/chromium/src/+/7bf96efe2650f6ee0cb8b28c4cd449cdb828704b"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ffdc8123f2a32f02e76ccd00151833766c693dad"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@ffdc8123f2a32f02e76ccd00151833766c693dad",
"title": "ffdc8123f2a32f02e76ccd00151833766c693dad",
"url": "https://chromium.googlesource.com/chromium/src/+/ffdc8123f2a32f02e76ccd00151833766c693dad"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "89c82ccf8d9f5191525581339368b0a57f554fe6"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@89c82ccf8d9f5191525581339368b0a57f554fe6",
"title": "89c82ccf8d9f5191525581339368b0a57f554fe6",
"url": "https://chromium.googlesource.com/chromium/src/+/89c82ccf8d9f5191525581339368b0a57f554fe6"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "57489480cb26b829343d8e8476d0d25d569aa290"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@57489480cb26b829343d8e8476d0d25d569aa290",
"title": "57489480cb26b829343d8e8476d0d25d569aa290",
"url": "https://chromium.googlesource.com/chromium/src/+/57489480cb26b829343d8e8476d0d25d569aa290"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "aad131736ad6b490823bd628be22a08286a596df"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@aad131736ad6b490823bd628be22a08286a596df",
"title": "aad131736ad6b490823bd628be22a08286a596df",
"url": "https://chromium.googlesource.com/chromium/src/+/aad131736ad6b490823bd628be22a08286a596df"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "4b0785b00d446f390883700894cfaca4323e4b5b"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@4b0785b00d446f390883700894cfaca4323e4b5b",
"title": "4b0785b00d446f390883700894cfaca4323e4b5b",
"url": "https://chromium.googlesource.com/chromium/src/+/4b0785b00d446f390883700894cfaca4323e4b5b"
},
{
"gitiles": {
"ref": "refs/branch-heads/6778",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "bfda086f291cc18d203bc7ca30631dbbb221c697"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6778@bfda086f291cc18d203bc7ca30631dbbb221c697",
"title": "bfda086f291cc18d203bc7ca30631dbbb221c697",
"url": "https://chromium.googlesource.com/chromium/src/+/bfda086f291cc18d203bc7ca30631dbbb221c697"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "bfda086f291cc18d203bc7ca30631dbbb221c697",
"ref": "refs/branch-heads/6778"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8893150428311405728"
},
{
"key": "scheduler_job_id",
"value": "chromium-m131/win-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[22:51:08.389] Scheduled build:
{
"id": "8727720366427898433",
"builder": {
"project": "chromium-m131",
"bucket": "ci",
"builder": "win-official"
},
"number": 491,
"createdBy": "project:chromium-m131",
"createTime": "2024-12-23T22:51:07.969980366Z",
"updateTime": "2024-12-23T22:51:07.969980366Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "bfda086f291cc18d203bc7ca30631dbbb221c697",
"ref": "refs/branch-heads/6778"
}
}
}
[22:51:08.389] Task URL: https://cr-buildbucket.appspot.com/build/8727720366427898433
[22:51:08.389] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:2:0) after 9m40s
[22:51:09.420] Received PubSub notification, asking Buildbucket for the build status
[22:51:09.562] Build status: SCHEDULED
[22:51:13.603] Received PubSub notification, asking Buildbucket for the build status
[22:51:13.632] Build status: STARTED
[23:00:48.432] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:2:0)
[23:00:48.460] Build status: STARTED
[23:00:48.460] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:5:0) after 3m21s
[23:04:09.495] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:5:0)
[23:04:09.520] Build status: STARTED
[23:04:09.520] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:6:0) after 1m14s
[23:05:23.588] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:6:0)
[23:05:23.616] Build status: STARTED
[23:05:23.616] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:7:0) after 8m1s
[23:13:24.694] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:7:0)
[23:13:24.720] Build status: STARTED
[23:13:24.720] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:8:0) after 1m37s
[23:15:01.836] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:8:0)
[23:15:01.876] Build status: STARTED
[23:15:01.876] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:9:0) after 1m53s
[23:16:54.901] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:9:0)
[23:16:54.926] Build status: STARTED
[23:16:54.926] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:10:0) after 4m9s
[23:21:04.702] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:10:0)
[23:21:04.738] Build status: STARTED
[23:21:04.739] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:11:0) after 4m8s
[23:25:12.772] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:11:0)
[23:25:12.808] Build status: STARTED
[23:25:12.808] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:12:0) after 8m8s
[23:33:21.441] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:12:0)
[23:33:21.468] Build status: STARTED
[23:33:21.468] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:13:0) after 4m5s
[23:37:26.591] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:13:0)
[23:37:26.616] Build status: STARTED
[23:37:26.616] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:14:0) after 9m56s
[23:47:22.816] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:14:0)
[23:47:22.923] Build status: STARTED
[23:47:22.923] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:15:0) after 6m31s
[23:53:54.461] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:15:0)
[23:53:54.526] Build status: STARTED
[23:53:54.526] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:16:0) after 9m28s
[00:03:22.665] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:16:0)
[00:03:22.688] Build status: STARTED
[00:03:22.688] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:17:0) after 7m10s
[00:10:32.967] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:17:0)
[00:10:32.983] Build status: STARTED
[00:10:32.983] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:18:0) after 1m18s
[00:11:51.093] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:18:0)
[00:11:51.117] Build status: STARTED
[00:11:51.117] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:19:0) after 4m6s
[00:15:57.242] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:19:0)
[00:15:57.263] Build status: STARTED
[00:15:57.263] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:20:0) after 4m56s
[00:20:53.283] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:20:0)
[00:20:53.303] Build status: STARTED
[00:20:53.303] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:21:0) after 2m8s
[00:23:01.329] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:21:0)
[00:23:01.347] Build status: STARTED
[00:23:01.347] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:22:0) after 7m50s
[00:30:51.729] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:22:0)
[00:30:51.751] Build status: STARTED
[00:30:51.751] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:23:0) after 5m4s
[00:35:55.779] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:23:0)
[00:35:55.798] Build status: STARTED
[00:35:55.798] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:24:0) after 7m4s
[00:42:59.818] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:24:0)
[00:42:59.865] Build status: STARTED
[00:42:59.865] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:25:0) after 6m48s
[00:49:47.944] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:25:0)
[00:49:47.965] Build status: STARTED
[00:49:47.965] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:26:0) after 1m58s
[00:51:45.989] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:26:0)
[00:51:46.149] Build status: STARTED
[00:51:46.149] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:27:0) after 4m38s
[00:56:24.191] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:27:0)
[00:56:24.215] Build status: STARTED
[00:56:24.215] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:28:0) after 6m22s
[01:02:46.244] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:28:0)
[01:02:46.270] Build status: STARTED
[01:02:46.271] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:29:0) after 6m43s
[01:09:29.386] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:29:0)
[01:09:29.403] Build status: STARTED
[01:09:29.403] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:30:0) after 5m27s
[01:14:56.412] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:30:0)
[01:14:56.431] Build status: STARTED
[01:14:56.431] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:31:0) after 4m7s
[01:19:03.670] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:31:0)
[01:19:03.688] Build status: STARTED
[01:19:03.688] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:32:0) after 1m18s
[01:20:22.165] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:32:0)
[01:20:22.195] Build status: STARTED
[01:20:22.195] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:33:0) after 5m42s
[01:26:04.476] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:33:0)
[01:26:04.538] Build status: STARTED
[01:26:04.538] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:34:0) after 3m15s
[01:29:19.651] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:34:0)
[01:29:19.677] Build status: STARTED
[01:29:19.677] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:35:0) after 7m28s
[01:36:47.813] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:35:0)
[01:36:47.864] Build status: STARTED
[01:36:47.864] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:36:0) after 5m40s
[01:42:27.929] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:36:0)
[01:42:27.950] Build status: STARTED
[01:42:27.950] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:37:0) after 3m48s
[01:46:16.067] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:37:0)
[01:46:16.084] Build status: STARTED
[01:46:16.084] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:38:0) after 5m12s
[01:51:28.270] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:38:0)
[01:51:28.296] Build status: STARTED
[01:51:28.296] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:39:0) after 3m55s
[01:55:23.957] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:39:0)
[01:55:23.973] Build status: STARTED
[01:55:23.973] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:40:0) after 3m22s
[01:58:45.997] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:40:0)
[01:58:46.016] Build status: STARTED
[01:58:46.016] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:41:0) after 9m57s
[02:08:43.110] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:41:0)
[02:08:43.132] Build status: STARTED
[02:08:43.132] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:42:0) after 7m8s
[02:15:51.128] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:42:0)
[02:15:51.270] Build status: STARTED
[02:15:51.270] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:43:0) after 2m45s
[02:18:36.255] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:43:0)
[02:18:36.274] Build status: STARTED
[02:18:36.274] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:44:0) after 2m50s
[02:21:26.407] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:44:0)
[02:21:26.439] Build status: STARTED
[02:21:26.439] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:45:0) after 1m46s
[02:23:12.605] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:45:0)
[02:23:12.691] Build status: STARTED
[02:23:12.691] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:46:0) after 5m59s
[02:29:12.338] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:46:0)
[02:29:12.356] Build status: STARTED
[02:29:12.356] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:47:0) after 3m24s
[02:32:36.392] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:47:0)
[02:32:36.456] Build status: STARTED
[02:32:36.456] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:48:0) after 3m43s
[02:36:19.478] Handling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:48:0)
[02:36:19.498] Build status: STARTED
[02:36:19.498] Scheduling timer "check-buildbucket-build-status" (chromium-m131/win-official:8893150428311405728:49:0) after 4m18s
[02:39:17.922] Received PubSub notification, asking Buildbucket for the build status
[02:39:17.946] Build:
{
"id": "8727720366427898433",
"builder": {
"project": "chromium-m131",
"bucket": "ci",
"builder": "win-official"
},
"number": 491,
"createdBy": "project:chromium-m131",
"createTime": "2024-12-23T22:51:07.969980366Z",
"startTime": "2024-12-23T22:51:13.212052709Z",
"endTime": "2024-12-24T02:39:17.534279964Z",
"updateTime": "2024-12-24T02:39:17.534279964Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "bfda086f291cc18d203bc7ca30631dbbb221c697",
"ref": "refs/branch-heads/6778"
}
}
}
[02:39:17.946] Invocation finished in 3h48m11.156182514s with status SUCCEEDED