[14:24:14.547] New invocation is queued and will start shortly
[14:24:15.610] Starting the invocation (attempt 1)
[14:24:15.639] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/b13c3e575d69613100cbd15db982b6e68a0c9c39"
[14:24:15.639] Popped gitiles commit info from properties and tags
[14:24:15.639] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[14:24:15.639] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[14:24:15.640] Buildbucket request:
{
"requestId": "8897621569216697072",
"builder": {
"project": "chromium-m130",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8897621569216697072",
"job": "chromium-m130/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "4fdfbdead00c0bfc2c0434f00164fe9339062cde"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@4fdfbdead00c0bfc2c0434f00164fe9339062cde",
"title": "4fdfbdead00c0bfc2c0434f00164fe9339062cde",
"url": "https://chromium.googlesource.com/chromium/src/+/4fdfbdead00c0bfc2c0434f00164fe9339062cde"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "06a8da1a5163c720942d90a05e8299f97f06ebed"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@06a8da1a5163c720942d90a05e8299f97f06ebed",
"title": "06a8da1a5163c720942d90a05e8299f97f06ebed",
"url": "https://chromium.googlesource.com/chromium/src/+/06a8da1a5163c720942d90a05e8299f97f06ebed"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "93d08ab1bb3ef61cb2e02f662a1013e166055dd9"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@93d08ab1bb3ef61cb2e02f662a1013e166055dd9",
"title": "93d08ab1bb3ef61cb2e02f662a1013e166055dd9",
"url": "https://chromium.googlesource.com/chromium/src/+/93d08ab1bb3ef61cb2e02f662a1013e166055dd9"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "396528cf0554479564dec677e07ed968313ec531"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@396528cf0554479564dec677e07ed968313ec531",
"title": "396528cf0554479564dec677e07ed968313ec531",
"url": "https://chromium.googlesource.com/chromium/src/+/396528cf0554479564dec677e07ed968313ec531"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "9ee1607750064f5ae4c9864c5b56a83dc246f243"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@9ee1607750064f5ae4c9864c5b56a83dc246f243",
"title": "9ee1607750064f5ae4c9864c5b56a83dc246f243",
"url": "https://chromium.googlesource.com/chromium/src/+/9ee1607750064f5ae4c9864c5b56a83dc246f243"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b13c3e575d69613100cbd15db982b6e68a0c9c39"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@b13c3e575d69613100cbd15db982b6e68a0c9c39",
"title": "b13c3e575d69613100cbd15db982b6e68a0c9c39",
"url": "https://chromium.googlesource.com/chromium/src/+/b13c3e575d69613100cbd15db982b6e68a0c9c39"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b13c3e575d69613100cbd15db982b6e68a0c9c39",
"ref": "refs/branch-heads/6723"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8897621569216697072"
},
{
"key": "scheduler_job_id",
"value": "chromium-m130/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[14:24:16.135] Scheduled build:
{
"id": "8732191507355126481",
"builder": {
"project": "chromium-m130",
"bucket": "ci",
"builder": "win32-official"
},
"number": 272,
"createdBy": "project:chromium-m130",
"createTime": "2024-11-04T14:24:15.702975657Z",
"updateTime": "2024-11-04T14:24:15.702975657Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b13c3e575d69613100cbd15db982b6e68a0c9c39",
"ref": "refs/branch-heads/6723"
}
}
}
[14:24:16.135] Task URL: https://cr-buildbucket.appspot.com/build/8732191507355126481
[14:24:16.135] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:2:0) after 6m42s
[14:24:17.102] Received PubSub notification, asking Buildbucket for the build status
[14:24:17.133] Build status: SCHEDULED
[14:24:23.672] Received PubSub notification, asking Buildbucket for the build status
[14:24:23.689] Build status: STARTED
[14:30:58.246] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:2:0)
[14:30:58.263] Build status: STARTED
[14:30:58.263] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:5:0) after 2m53s
[14:33:51.338] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:5:0)
[14:33:51.357] Build status: STARTED
[14:33:51.357] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:6:0) after 3m54s
[14:37:45.370] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:6:0)
[14:37:45.413] Build status: STARTED
[14:37:45.413] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:7:0) after 7m34s
[14:45:19.430] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:7:0)
[14:45:19.447] Build status: STARTED
[14:45:19.447] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:8:0) after 1m12s
[14:46:31.721] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:8:0)
[14:46:31.738] Build status: STARTED
[14:46:31.738] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:9:0) after 1m0s
[14:47:32.480] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:9:0)
[14:47:32.500] Build status: STARTED
[14:47:32.500] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:10:0) after 2m20s
[14:49:53.198] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:10:0)
[14:49:53.216] Build status: STARTED
[14:49:53.216] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:11:0) after 4m24s
[14:54:17.682] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:11:0)
[14:54:17.704] Build status: STARTED
[14:54:17.704] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:12:0) after 7m27s
[15:01:44.764] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:12:0)
[15:01:44.797] Build status: STARTED
[15:01:44.797] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:13:0) after 7m55s
[15:09:39.997] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:13:0)
[15:09:40.016] Build status: STARTED
[15:09:40.016] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:14:0) after 3m8s
[15:12:48.036] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:14:0)
[15:12:48.090] Build status: STARTED
[15:12:48.090] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:15:0) after 9m56s
[15:22:44.336] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:15:0)
[15:22:44.365] Build status: STARTED
[15:22:44.365] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:16:0) after 6m54s
[15:29:38.414] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:16:0)
[15:29:38.431] Build status: STARTED
[15:29:38.431] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:17:0) after 4m47s
[15:34:25.547] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:17:0)
[15:34:25.563] Build status: STARTED
[15:34:25.563] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:18:0) after 5m20s
[15:39:45.771] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:18:0)
[15:39:45.821] Build status: STARTED
[15:39:45.822] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:19:0) after 3m25s
[15:43:11.144] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:19:0)
[15:43:11.162] Build status: STARTED
[15:43:11.162] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:20:0) after 7m31s
[15:50:42.394] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:20:0)
[15:50:42.411] Build status: STARTED
[15:50:42.411] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:21:0) after 5m43s
[15:56:25.427] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:21:0)
[15:56:25.445] Build status: STARTED
[15:56:25.445] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:22:0) after 8m52s
[16:05:17.792] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:22:0)
[16:05:17.814] Build status: STARTED
[16:05:17.814] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:23:0) after 4m24s
[16:09:41.916] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:23:0)
[16:09:41.944] Build status: STARTED
[16:09:41.945] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:24:0) after 2m26s
[16:12:08.066] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:24:0)
[16:12:08.090] Build status: STARTED
[16:12:08.090] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:25:0) after 5m39s
[16:17:47.503] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:25:0)
[16:17:47.524] Build status: STARTED
[16:17:47.524] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:26:0) after 6m49s
[16:24:36.696] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:26:0)
[16:24:36.759] Build status: STARTED
[16:24:36.759] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:27:0) after 9m9s
[16:33:45.954] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:27:0)
[16:33:45.973] Build status: STARTED
[16:33:45.973] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:28:0) after 2m10s
[16:35:56.505] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:28:0)
[16:35:56.572] Build status: STARTED
[16:35:56.572] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:29:0) after 1m11s
[16:37:07.587] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:29:0)
[16:37:07.611] Build status: STARTED
[16:37:07.611] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:30:0) after 9m57s
[16:47:04.728] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:30:0)
[16:47:04.749] Build status: STARTED
[16:47:04.749] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:31:0) after 7m59s
[16:55:03.744] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:31:0)
[16:55:03.767] Build status: STARTED
[16:55:03.767] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:32:0) after 5m44s
[17:00:47.786] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:32:0)
[17:00:47.809] Build status: STARTED
[17:00:47.809] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:33:0) after 3m7s
[17:03:54.828] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:33:0)
[17:03:54.892] Build status: STARTED
[17:03:54.892] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:34:0) after 2m30s
[17:06:25.003] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:34:0)
[17:06:25.029] Build status: STARTED
[17:06:25.030] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:35:0) after 2m29s
[17:08:54.087] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:35:0)
[17:08:54.112] Build status: STARTED
[17:08:54.112] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:36:0) after 4m57s
[17:13:51.173] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:36:0)
[17:13:51.199] Build status: STARTED
[17:13:51.199] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:37:0) after 6m13s
[17:20:04.223] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:37:0)
[17:20:04.251] Build status: STARTED
[17:20:04.251] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:38:0) after 4m5s
[17:24:09.301] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:38:0)
[17:24:09.320] Build status: STARTED
[17:24:09.320] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:39:0) after 1m58s
[17:26:07.348] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:39:0)
[17:26:07.443] Build status: STARTED
[17:26:07.443] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:40:0) after 8m18s
[17:34:25.514] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:40:0)
[17:34:25.545] Build status: STARTED
[17:34:25.545] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:41:0) after 2m14s
[17:36:39.723] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:41:0)
[17:36:39.825] Build status: STARTED
[17:36:39.825] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:42:0) after 4m13s
[17:40:52.889] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:42:0)
[17:40:52.907] Build status: STARTED
[17:40:52.907] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:43:0) after 4m11s
[17:45:03.988] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:43:0)
[17:45:04.013] Build status: STARTED
[17:45:04.013] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:44:0) after 4m41s
[17:49:45.048] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:44:0)
[17:49:45.066] Build status: STARTED
[17:49:45.066] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:45:0) after 1m49s
[17:51:34.084] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:45:0)
[17:51:34.114] Build status: STARTED
[17:51:34.114] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:46:0) after 2m33s
[17:54:07.153] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:46:0)
[17:54:07.241] Build status: STARTED
[17:54:07.241] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:47:0) after 1m33s
[17:55:40.261] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:47:0)
[17:55:40.284] Build status: STARTED
[17:55:40.285] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:48:0) after 5m47s
[18:01:27.412] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:48:0)
[18:01:27.458] Build status: STARTED
[18:01:27.458] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:49:0) after 3m37s
[18:05:04.485] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:49:0)
[18:05:04.502] Build status: STARTED
[18:05:04.502] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:50:0) after 6m43s
[18:11:47.597] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:50:0)
[18:11:47.621] Build status: STARTED
[18:11:47.621] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:51:0) after 2m0s
[18:13:47.640] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:51:0)
[18:13:47.656] Build status: STARTED
[18:13:47.656] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:52:0) after 6m29s
[18:20:16.672] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:52:0)
[18:20:16.690] Build status: STARTED
[18:20:16.690] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8897621569216697072:53:0) after 3m53s
[18:20:58.724] Received PubSub notification, asking Buildbucket for the build status
[18:20:58.772] Build:
{
"id": "8732191507355126481",
"builder": {
"project": "chromium-m130",
"bucket": "ci",
"builder": "win32-official"
},
"number": 272,
"createdBy": "project:chromium-m130",
"createTime": "2024-11-04T14:24:15.702975657Z",
"startTime": "2024-11-04T14:24:23.473425790Z",
"endTime": "2024-11-04T18:20:58.357168832Z",
"updateTime": "2024-11-04T18:20:58.357168832Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "b13c3e575d69613100cbd15db982b6e68a0c9c39",
"ref": "refs/branch-heads/6723"
}
}
}
[18:20:58.772] Invocation finished in 3h56m44.229776307s with status SUCCEEDED