[09:52:20.772] New invocation is queued and will start shortly
[09:52:21.877] Starting the invocation (attempt 1)
[09:52:21.905] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/d8517c959bbc3315fa17e33d95fba1cc77a010a8"
[09:52:21.905] Popped gitiles commit info from properties and tags
[09:52:21.905] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[09:52:21.905] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[09:52:21.906] Buildbucket request:
{
"requestId": "8953084018897036720",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win-rel-cft"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d8517c959bbc3315fa17e33d95fba1cc77a010a8",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8953084018897036720"
},
{
"key": "scheduler_job_id",
"value": "chromium/win-rel-cft"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[09:52:22.594] Scheduled build:
{
"id": "8787653956707966769",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win-rel-cft"
},
"number": 2179,
"createdBy": "project:chromium",
"createTime": "2023-03-03T09:52:22.229647391Z",
"updateTime": "2023-03-03T09:52:22.229647391Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d8517c959bbc3315fa17e33d95fba1cc77a010a8",
"ref": "refs/heads/main"
}
}
}
[09:52:22.594] Task URL: https://cr-buildbucket.appspot.com/build/8787653956707966769
[09:52:22.595] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:2:0) after 3m11s
[09:52:59.975] Received PubSub notification, asking Buildbucket for the build status
[09:53:00.003] Build status: STARTED
[09:55:33.622] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:2:0)
[09:55:33.645] Build status: STARTED
[09:55:33.645] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:4:0) after 5m30s
[10:01:03.664] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:4:0)
[10:01:03.699] Build status: STARTED
[10:01:03.699] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:5:0) after 4m5s
[10:05:08.842] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:5:0)
[10:05:08.878] Build status: STARTED
[10:05:08.878] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:6:0) after 1m58s
[10:07:06.899] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:6:0)
[10:07:06.928] Build status: STARTED
[10:07:06.928] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:7:0) after 3m20s
[10:10:26.953] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:7:0)
[10:10:26.987] Build status: STARTED
[10:10:26.987] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:8:0) after 1m1s
[10:11:28.128] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:8:0)
[10:11:28.163] Build status: STARTED
[10:11:28.163] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:9:0) after 9m39s
[10:21:07.231] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:9:0)
[10:21:07.260] Build status: STARTED
[10:21:07.260] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:10:0) after 1m25s
[10:22:32.278] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:10:0)
[10:22:32.300] Build status: STARTED
[10:22:32.300] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:11:0) after 8m14s
[10:30:46.431] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:11:0)
[10:30:46.458] Build status: STARTED
[10:30:46.458] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:12:0) after 2m56s
[10:33:42.521] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:12:0)
[10:33:42.541] Build status: STARTED
[10:33:42.541] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:13:0) after 2m49s
[10:36:31.789] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:13:0)
[10:36:31.807] Build status: STARTED
[10:36:31.807] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:14:0) after 9m8s
[10:45:39.883] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:14:0)
[10:45:39.912] Build status: STARTED
[10:45:39.912] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:15:0) after 5m30s
[10:51:09.996] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:15:0)
[10:51:10.054] Build status: STARTED
[10:51:10.054] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:16:0) after 4m57s
[10:56:07.073] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:16:0)
[10:56:07.101] Build status: STARTED
[10:56:07.101] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:17:0) after 8m58s
[11:05:05.220] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:17:0)
[11:05:05.256] Build status: STARTED
[11:05:05.256] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:18:0) after 9m45s
[11:14:50.283] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:18:0)
[11:14:50.341] Build status: STARTED
[11:14:50.341] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:19:0) after 2m13s
[11:17:03.605] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:19:0)
[11:17:03.627] Build status: STARTED
[11:17:03.627] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:20:0) after 5m8s
[11:22:11.753] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:20:0)
[11:22:11.781] Build status: STARTED
[11:22:11.781] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:21:0) after 6m22s
[11:28:33.893] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:21:0)
[11:28:33.930] Build status: STARTED
[11:28:33.930] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:22:0) after 8m21s
[11:36:55.253] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:22:0)
[11:36:55.273] Build status: STARTED
[11:36:55.273] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:23:0) after 1m7s
[11:38:02.348] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:23:0)
[11:38:02.372] Build status: STARTED
[11:38:02.372] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:24:0) after 2m12s
[11:40:14.401] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:24:0)
[11:40:14.423] Build status: STARTED
[11:40:14.423] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:25:0) after 6m52s
[11:47:06.442] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:25:0)
[11:47:06.463] Build status: STARTED
[11:47:06.463] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:26:0) after 5m53s
[11:52:59.482] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:26:0)
[11:52:59.507] Build status: STARTED
[11:52:59.507] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:27:0) after 4m38s
[11:57:37.656] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:27:0)
[11:57:37.681] Build status: STARTED
[11:57:37.681] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:28:0) after 8m56s
[12:06:33.802] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:28:0)
[12:06:33.825] Build status: STARTED
[12:06:33.825] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:29:0) after 4m12s
[12:10:45.861] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:29:0)
[12:10:45.928] Build status: STARTED
[12:10:45.928] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:30:0) after 8m38s
[12:19:23.955] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:30:0)
[12:19:23.977] Build status: STARTED
[12:19:23.977] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:31:0) after 4m47s
[12:24:10.977] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:31:0)
[12:24:10.998] Build status: STARTED
[12:24:10.998] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:32:0) after 8m11s
[12:32:22.241] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:32:0)
[12:32:22.260] Build status: STARTED
[12:32:22.260] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:33:0) after 3m49s
[12:36:11.680] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:33:0)
[12:36:11.703] Build status: STARTED
[12:36:11.703] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:34:0) after 9m40s
[12:45:51.730] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:34:0)
[12:45:51.748] Build status: STARTED
[12:45:51.748] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:35:0) after 2m42s
[12:48:33.859] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:35:0)
[12:48:33.884] Build status: STARTED
[12:48:33.884] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:36:0) after 1m30s
[12:50:04.020] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:36:0)
[12:50:04.075] Build status: STARTED
[12:50:04.075] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:37:0) after 8m11s
[12:58:15.095] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:37:0)
[12:58:15.123] Build status: STARTED
[12:58:15.123] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:38:0) after 7m32s
[13:05:47.136] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:38:0)
[13:05:47.201] Build status: STARTED
[13:05:47.201] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:39:0) after 6m12s
[13:11:59.312] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:39:0)
[13:11:59.345] Build status: STARTED
[13:11:59.345] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:40:0) after 6m28s
[13:18:27.371] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:40:0)
[13:18:27.393] Build status: STARTED
[13:18:27.393] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:41:0) after 9m39s
[13:28:06.423] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:41:0)
[13:28:06.450] Build status: STARTED
[13:28:06.450] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:42:0) after 2m37s
[13:30:43.489] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:42:0)
[13:30:43.509] Build status: STARTED
[13:30:43.509] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:43:0) after 5m13s
[13:35:56.531] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:43:0)
[13:35:56.557] Build status: STARTED
[13:35:56.557] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:44:0) after 7m2s
[13:42:58.592] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:44:0)
[13:42:58.621] Build status: STARTED
[13:42:58.621] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:45:0) after 9m21s
[13:52:19.639] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:45:0)
[13:52:19.658] Build status: STARTED
[13:52:19.658] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:46:0) after 8m38s
[14:00:57.704] Handling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:46:0)
[14:00:57.723] Build status: STARTED
[14:00:57.723] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-cft:8953084018897036720:47:0) after 8m42s
[14:04:59.666] Received PubSub notification, asking Buildbucket for the build status
[14:04:59.691] Build:
{
"id": "8787653956707966769",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win-rel-cft"
},
"number": 2179,
"createdBy": "project:chromium",
"createTime": "2023-03-03T09:52:22.229647391Z",
"startTime": "2023-03-03T09:52:59.419673Z",
"endTime": "2023-03-03T14:04:59.164973604Z",
"updateTime": "2023-03-03T14:04:59.164973604Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d8517c959bbc3315fa17e33d95fba1cc77a010a8",
"ref": "refs/heads/main"
}
}
}
[14:04:59.691] Invocation finished in 4h12m38.933291685s with status FAILED