[00:05:34.945] New invocation is queued and will start shortly
[00:05:36.070] Starting the invocation (attempt 1)
[00:05:36.096] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/0a67694c5d4b939e5ee8165790aea0073ea2f4cc"
[00:05:36.096] Popped gitiles commit info from properties and tags
[00:05:36.096] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[00:05:36.096] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[00:05:36.096] Buildbucket request:
{
"requestId": "8913530060565547984",
"builder": {
"project": "chromium-m124",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8913530060565547984",
"job": "chromium-m124/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/6367",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "0a67694c5d4b939e5ee8165790aea0073ea2f4cc"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6367@0a67694c5d4b939e5ee8165790aea0073ea2f4cc",
"title": "0a67694c5d4b939e5ee8165790aea0073ea2f4cc",
"url": "https://chromium.googlesource.com/chromium/src/+/0a67694c5d4b939e5ee8165790aea0073ea2f4cc"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "0a67694c5d4b939e5ee8165790aea0073ea2f4cc",
"ref": "refs/branch-heads/6367"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8913530060565547984"
},
{
"key": "scheduler_job_id",
"value": "chromium-m124/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[00:05:36.951] Scheduled build:
{
"id": "8748099998614315217",
"builder": {
"project": "chromium-m124",
"bucket": "ci",
"builder": "win32-official"
},
"number": 259,
"createdBy": "project:chromium-m124",
"createTime": "2024-05-13T00:05:36.175957666Z",
"updateTime": "2024-05-13T00:05:36.175957666Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "0a67694c5d4b939e5ee8165790aea0073ea2f4cc",
"ref": "refs/branch-heads/6367"
}
}
}
[00:05:36.951] Task URL: https://cr-buildbucket.appspot.com/build/8748099998614315217
[00:05:36.951] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:2:0) after 4m27s
[00:05:37.242] Received PubSub notification, asking Buildbucket for the build status
[00:05:37.307] Build status: SCHEDULED
[00:05:47.036] Received PubSub notification, asking Buildbucket for the build status
[00:05:47.056] Build status: STARTED
[00:10:03.991] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:2:0)
[00:10:04.040] Build status: STARTED
[00:10:04.040] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:5:0) after 6m44s
[00:16:48.106] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:5:0)
[00:16:48.167] Build status: STARTED
[00:16:48.167] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:6:0) after 2m53s
[00:19:41.226] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:6:0)
[00:19:41.267] Build status: STARTED
[00:19:41.267] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:7:0) after 1m5s
[00:20:46.573] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:7:0)
[00:20:46.592] Build status: STARTED
[00:20:46.592] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:8:0) after 9m38s
[00:30:24.702] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:8:0)
[00:30:24.839] Build status: STARTED
[00:30:24.840] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:9:0) after 1m25s
[00:31:49.833] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:9:0)
[00:31:49.864] Build status: STARTED
[00:31:49.864] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:10:0) after 8m49s
[00:40:38.907] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:10:0)
[00:40:38.949] Build status: STARTED
[00:40:38.949] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:11:0) after 1m13s
[00:41:52.028] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:11:0)
[00:41:52.049] Build status: STARTED
[00:41:52.049] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:12:0) after 3m0s
[00:44:52.284] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:12:0)
[00:44:52.305] Build status: STARTED
[00:44:52.305] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:13:0) after 9m12s
[00:54:04.390] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:13:0)
[00:54:04.406] Build status: STARTED
[00:54:04.406] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:14:0) after 7m51s
[01:01:55.576] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:14:0)
[01:01:55.612] Build status: STARTED
[01:01:55.612] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:15:0) after 6m26s
[01:08:21.735] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:15:0)
[01:08:21.753] Build status: STARTED
[01:08:21.753] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:16:0) after 1m58s
[01:10:19.854] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:16:0)
[01:10:19.872] Build status: STARTED
[01:10:19.872] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:17:0) after 1m50s
[01:12:10.236] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:17:0)
[01:12:10.267] Build status: STARTED
[01:12:10.267] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:18:0) after 4m46s
[01:16:56.477] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:18:0)
[01:16:56.498] Build status: STARTED
[01:16:56.498] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:19:0) after 4m6s
[01:21:02.606] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:19:0)
[01:21:02.693] Build status: STARTED
[01:21:02.693] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:20:0) after 4m41s
[01:25:43.821] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:20:0)
[01:25:43.840] Build status: STARTED
[01:25:43.840] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:21:0) after 9m53s
[01:35:36.855] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:21:0)
[01:35:36.897] Build status: STARTED
[01:35:36.897] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:22:0) after 8m30s
[01:44:06.916] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:22:0)
[01:44:06.953] Build status: STARTED
[01:44:06.953] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:23:0) after 6m47s
[01:50:54.071] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:23:0)
[01:50:54.111] Build status: STARTED
[01:50:54.111] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:24:0) after 1m11s
[01:52:05.132] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:24:0)
[01:52:05.152] Build status: STARTED
[01:52:05.152] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:25:0) after 3m7s
[01:55:12.526] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:25:0)
[01:55:12.563] Build status: STARTED
[01:55:12.563] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:26:0) after 1m28s
[01:56:40.783] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:26:0)
[01:56:40.818] Build status: STARTED
[01:56:40.818] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:27:0) after 7m47s
[02:04:27.803] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:27:0)
[02:04:27.823] Build status: STARTED
[02:04:27.823] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:28:0) after 9m1s
[02:13:28.848] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:28:0)
[02:13:28.877] Build status: STARTED
[02:13:28.877] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:29:0) after 8m28s
[02:21:57.015] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:29:0)
[02:21:57.075] Build status: STARTED
[02:21:57.075] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:30:0) after 4m8s
[02:26:05.225] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:30:0)
[02:26:05.249] Build status: STARTED
[02:26:05.249] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:31:0) after 3m1s
[02:29:06.273] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:31:0)
[02:29:06.293] Build status: STARTED
[02:29:06.293] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:32:0) after 6m4s
[02:35:10.314] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:32:0)
[02:35:10.345] Build status: STARTED
[02:35:10.345] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:33:0) after 5m29s
[02:40:39.363] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:33:0)
[02:40:39.423] Build status: STARTED
[02:40:39.423] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:34:0) after 5m51s
[02:46:30.598] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:34:0)
[02:46:30.616] Build status: STARTED
[02:46:30.616] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:35:0) after 5m12s
[02:51:42.680] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:35:0)
[02:51:42.698] Build status: STARTED
[02:51:42.699] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:36:0) after 9m3s
[03:00:45.837] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:36:0)
[03:00:45.866] Build status: STARTED
[03:00:45.866] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:37:0) after 4m41s
[03:05:27.947] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:37:0)
[03:05:28.116] Build status: STARTED
[03:05:28.117] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:38:0) after 3m45s
[03:09:13.561] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:38:0)
[03:09:13.580] Build status: STARTED
[03:09:13.580] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:39:0) after 5m42s
[03:14:55.844] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:39:0)
[03:14:55.871] Build status: STARTED
[03:14:55.871] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:40:0) after 7m20s
[03:22:15.889] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:40:0)
[03:22:15.906] Build status: STARTED
[03:22:15.906] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:41:0) after 6m1s
[03:28:16.931] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:41:0)
[03:28:16.968] Build status: STARTED
[03:28:16.969] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:42:0) after 3m20s
[03:31:37.031] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:42:0)
[03:31:37.246] Build status: STARTED
[03:31:37.246] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:43:0) after 3m40s
[03:35:17.263] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:43:0)
[03:35:17.294] Build status: STARTED
[03:35:17.294] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:44:0) after 5m40s
[03:40:57.373] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:44:0)
[03:40:57.431] Build status: STARTED
[03:40:57.431] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:45:0) after 3m55s
[03:44:52.456] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:45:0)
[03:44:52.502] Build status: STARTED
[03:44:52.502] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:46:0) after 6m39s
[03:51:31.549] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:46:0)
[03:51:31.569] Build status: STARTED
[03:51:31.569] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:47:0) after 4m54s
[03:56:25.588] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:47:0)
[03:56:25.632] Build status: STARTED
[03:56:25.633] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:48:0) after 7m48s
[04:04:13.673] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:48:0)
[04:04:13.797] Build status: STARTED
[04:04:13.798] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:49:0) after 5m51s
[04:10:05.086] Handling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:49:0)
[04:10:05.121] Build status: STARTED
[04:10:05.121] Scheduling timer "check-buildbucket-build-status" (chromium-m124/win32-official:8913530060565547984:50:0) after 1m57s
[04:11:21.563] Received PubSub notification, asking Buildbucket for the build status
[04:11:21.607] Build:
{
"id": "8748099998614315217",
"builder": {
"project": "chromium-m124",
"bucket": "ci",
"builder": "win32-official"
},
"number": 259,
"createdBy": "project:chromium-m124",
"createTime": "2024-05-13T00:05:36.175957666Z",
"startTime": "2024-05-13T00:05:46.835944340Z",
"endTime": "2024-05-13T04:11:21.063668091Z",
"updateTime": "2024-05-13T04:11:21.063668091Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "0a67694c5d4b939e5ee8165790aea0073ea2f4cc",
"ref": "refs/branch-heads/6367"
}
}
}
[04:11:21.607] Invocation finished in 4h5m46.675909009s with status SUCCEEDED