[03:41:46.590] New invocation is queued and will start shortly
[03:41:47.704] Starting the invocation (attempt 1)
[03:41:47.730] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/139b1fd2e9c22785d62f240b87e06abae5be0d90"
[03:41:47.730] Popped gitiles commit info from properties and tags
[03:41:47.730] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[03:41:47.730] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[03:41:47.730] Buildbucket request:
{
"requestId": "8893222738336253936",
"builder": {
"project": "chromium-m132",
"bucket": "ci",
"builder": "win-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8893222738336253936",
"job": "chromium-m132/win-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "1cd5b9e7bb26334e6794c3a76358f6ada4632a76"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@1cd5b9e7bb26334e6794c3a76358f6ada4632a76",
"title": "1cd5b9e7bb26334e6794c3a76358f6ada4632a76",
"url": "https://chromium.googlesource.com/chromium/src/+/1cd5b9e7bb26334e6794c3a76358f6ada4632a76"
},
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "9e9cad2d2af1123cda7b60d0cfe9f76ae01edcfc"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@9e9cad2d2af1123cda7b60d0cfe9f76ae01edcfc",
"title": "9e9cad2d2af1123cda7b60d0cfe9f76ae01edcfc",
"url": "https://chromium.googlesource.com/chromium/src/+/9e9cad2d2af1123cda7b60d0cfe9f76ae01edcfc"
},
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "91b9656fadc2d8f986f589deaf27f20b83893ed7"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@91b9656fadc2d8f986f589deaf27f20b83893ed7",
"title": "91b9656fadc2d8f986f589deaf27f20b83893ed7",
"url": "https://chromium.googlesource.com/chromium/src/+/91b9656fadc2d8f986f589deaf27f20b83893ed7"
},
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "c005388cca06d891d439dacf142772a7603d28b1"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@c005388cca06d891d439dacf142772a7603d28b1",
"title": "c005388cca06d891d439dacf142772a7603d28b1",
"url": "https://chromium.googlesource.com/chromium/src/+/c005388cca06d891d439dacf142772a7603d28b1"
},
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "b2d1a584692cdabaa04ae4d62a73fa9b3ec7d721"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@b2d1a584692cdabaa04ae4d62a73fa9b3ec7d721",
"title": "b2d1a584692cdabaa04ae4d62a73fa9b3ec7d721",
"url": "https://chromium.googlesource.com/chromium/src/+/b2d1a584692cdabaa04ae4d62a73fa9b3ec7d721"
},
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "f2e72bef3fad0f18f3efa246cdbf66ef21381e0c"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@f2e72bef3fad0f18f3efa246cdbf66ef21381e0c",
"title": "f2e72bef3fad0f18f3efa246cdbf66ef21381e0c",
"url": "https://chromium.googlesource.com/chromium/src/+/f2e72bef3fad0f18f3efa246cdbf66ef21381e0c"
},
{
"gitiles": {
"ref": "refs/branch-heads/6834",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "139b1fd2e9c22785d62f240b87e06abae5be0d90"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6834@139b1fd2e9c22785d62f240b87e06abae5be0d90",
"title": "139b1fd2e9c22785d62f240b87e06abae5be0d90",
"url": "https://chromium.googlesource.com/chromium/src/+/139b1fd2e9c22785d62f240b87e06abae5be0d90"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "139b1fd2e9c22785d62f240b87e06abae5be0d90",
"ref": "refs/branch-heads/6834"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8893222738336253936"
},
{
"key": "scheduler_job_id",
"value": "chromium-m132/win-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[03:41:48.236] Scheduled build:
{
"id": "8727792676410446641",
"builder": {
"project": "chromium-m132",
"bucket": "ci",
"builder": "win-official"
},
"number": 261,
"createdBy": "project:chromium-m132",
"createTime": "2024-12-23T03:41:47.796825170Z",
"updateTime": "2024-12-23T03:41:47.796825170Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "139b1fd2e9c22785d62f240b87e06abae5be0d90",
"ref": "refs/branch-heads/6834"
}
}
}
[03:41:48.236] Task URL: https://cr-buildbucket.appspot.com/build/8727792676410446641
[03:41:48.237] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:2:0) after 1m26s
[03:41:49.224] Received PubSub notification, asking Buildbucket for the build status
[03:41:49.250] Build status: SCHEDULED
[03:43:14.354] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:2:0)
[03:43:14.385] Build status: SCHEDULED
[03:43:14.385] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:4:0) after 8m53s
[03:43:14.734] Received PubSub notification, asking Buildbucket for the build status
[03:43:14.769] Build status: STARTED
[03:52:07.407] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:4:0)
[03:52:07.433] Build status: STARTED
[03:52:07.433] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:6:0) after 7m57s
[04:00:04.540] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:6:0)
[04:00:04.578] Build status: STARTED
[04:00:04.578] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:7:0) after 2m23s
[04:02:27.603] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:7:0)
[04:02:27.625] Build status: STARTED
[04:02:27.625] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:8:0) after 4m29s
[04:06:56.650] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:8:0)
[04:06:56.754] Build status: STARTED
[04:06:56.754] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:9:0) after 6m3s
[04:13:00.056] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:9:0)
[04:13:00.082] Build status: STARTED
[04:13:00.083] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:10:0) after 3m59s
[04:16:59.130] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:10:0)
[04:16:59.160] Build status: STARTED
[04:16:59.160] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:11:0) after 7m18s
[04:24:17.172] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:11:0)
[04:24:17.346] Build status: STARTED
[04:24:17.346] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:12:0) after 2m35s
[04:26:52.357] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:12:0)
[04:26:52.382] Build status: STARTED
[04:26:52.382] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:13:0) after 4m24s
[04:31:16.483] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:13:0)
[04:31:16.506] Build status: STARTED
[04:31:16.506] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:14:0) after 7m41s
[04:38:57.489] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:14:0)
[04:38:57.520] Build status: STARTED
[04:38:57.520] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:15:0) after 8m23s
[04:47:20.645] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:15:0)
[04:47:20.670] Build status: STARTED
[04:47:20.670] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:16:0) after 8m21s
[04:55:41.680] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:16:0)
[04:55:41.704] Build status: STARTED
[04:55:41.704] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:17:0) after 1m8s
[04:56:49.729] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:17:0)
[04:56:49.749] Build status: STARTED
[04:56:49.749] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:18:0) after 6m22s
[05:03:11.871] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:18:0)
[05:03:11.899] Build status: STARTED
[05:03:11.899] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:19:0) after 2m34s
[05:05:45.995] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:19:0)
[05:05:46.025] Build status: STARTED
[05:05:46.025] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:20:0) after 2m19s
[05:08:05.168] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:20:0)
[05:08:05.196] Build status: STARTED
[05:08:05.196] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:21:0) after 6m17s
[05:14:22.287] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:21:0)
[05:14:22.314] Build status: STARTED
[05:14:22.315] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:22:0) after 3m38s
[05:18:00.334] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:22:0)
[05:18:00.367] Build status: STARTED
[05:18:00.367] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:23:0) after 5m17s
[05:23:17.536] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:23:0)
[05:23:17.560] Build status: STARTED
[05:23:17.560] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:24:0) after 9m37s
[05:32:54.678] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:24:0)
[05:32:54.703] Build status: STARTED
[05:32:54.703] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:25:0) after 9m51s
[05:42:45.726] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:25:0)
[05:42:45.797] Build status: STARTED
[05:42:45.797] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:26:0) after 4m36s
[05:47:21.818] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:26:0)
[05:47:21.839] Build status: STARTED
[05:47:21.840] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:27:0) after 5m17s
[05:52:38.826] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:27:0)
[05:52:38.910] Build status: STARTED
[05:52:38.910] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:28:0) after 4m13s
[05:56:52.175] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:28:0)
[05:56:52.198] Build status: STARTED
[05:56:52.198] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:29:0) after 5m47s
[06:02:39.222] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:29:0)
[06:02:39.246] Build status: STARTED
[06:02:39.247] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:30:0) after 1m43s
[06:04:22.285] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:30:0)
[06:04:22.338] Build status: STARTED
[06:04:22.339] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:31:0) after 7m46s
[06:12:08.360] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:31:0)
[06:12:08.383] Build status: STARTED
[06:12:08.383] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:32:0) after 6m28s
[06:18:36.504] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:32:0)
[06:18:36.522] Build status: STARTED
[06:18:36.522] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:33:0) after 1m58s
[06:20:34.630] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:33:0)
[06:20:34.662] Build status: STARTED
[06:20:34.662] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:34:0) after 5m13s
[06:25:47.684] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:34:0)
[06:25:47.716] Build status: STARTED
[06:25:47.716] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:35:0) after 9m3s
[06:34:50.768] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:35:0)
[06:34:50.837] Build status: STARTED
[06:34:50.837] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:36:0) after 2m8s
[06:36:58.900] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:36:0)
[06:36:58.930] Build status: STARTED
[06:36:58.930] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:37:0) after 9m43s
[06:46:41.948] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:37:0)
[06:46:41.973] Build status: STARTED
[06:46:41.973] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:38:0) after 1m34s
[06:48:15.999] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:38:0)
[06:48:16.019] Build status: STARTED
[06:48:16.019] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:39:0) after 4m38s
[06:52:54.054] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:39:0)
[06:52:54.076] Build status: STARTED
[06:52:54.076] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:40:0) after 8m35s
[07:01:29.095] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:40:0)
[07:01:29.111] Build status: STARTED
[07:01:29.111] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:41:0) after 8m35s
[07:10:04.138] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:41:0)
[07:10:04.156] Build status: STARTED
[07:10:04.156] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:42:0) after 4m18s
[07:14:22.288] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:42:0)
[07:14:22.482] Build status: STARTED
[07:14:22.482] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:43:0) after 7m39s
[07:22:01.664] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:43:0)
[07:22:01.687] Build status: STARTED
[07:22:01.687] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:44:0) after 4m12s
[07:26:13.749] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:44:0)
[07:26:13.765] Build status: STARTED
[07:26:13.765] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:45:0) after 1m42s
[07:27:56.146] Handling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:45:0)
[07:27:56.177] Build status: STARTED
[07:27:56.177] Scheduling timer "check-buildbucket-build-status" (chromium-m132/win-official:8893222738336253936:46:0) after 7m46s
[07:34:28.501] Received PubSub notification, asking Buildbucket for the build status
[07:34:28.531] Build:
{
"id": "8727792676410446641",
"builder": {
"project": "chromium-m132",
"bucket": "ci",
"builder": "win-official"
},
"number": 261,
"createdBy": "project:chromium-m132",
"createTime": "2024-12-23T03:41:47.796825170Z",
"startTime": "2024-12-23T03:43:14.485599786Z",
"endTime": "2024-12-23T07:34:28.008572479Z",
"updateTime": "2024-12-23T07:34:28.008572479Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "139b1fd2e9c22785d62f240b87e06abae5be0d90",
"ref": "refs/branch-heads/6834"
}
}
}
[07:34:28.531] Invocation finished in 3h52m41.954135066s with status SUCCEEDED