[10:28:44.339] New invocation is queued and will start shortly
[10:28:45.507] Starting the invocation (attempt 1)
[10:28:45.536] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/93c4a81282336275011f236f3db6a64fc8921acf"
[10:28:45.536] Popped gitiles commit info from properties and tags
[10:28:45.536] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[10:28:45.536] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[10:28:45.536] Buildbucket request:
{
"requestId": "8874805950291820560",
"builder": {
"project": "chromium-m139",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8874805950291820560",
"job": "chromium-m139/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "189586d9e5c37c182c92556684f71882ac147221"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@189586d9e5c37c182c92556684f71882ac147221",
"title": "189586d9e5c37c182c92556684f71882ac147221",
"url": "https://chromium.googlesource.com/chromium/src/+/189586d9e5c37c182c92556684f71882ac147221"
},
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "eab39b3dc7e671f38b2b1c68f5f9ab8aaa08a41f"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@eab39b3dc7e671f38b2b1c68f5f9ab8aaa08a41f",
"title": "eab39b3dc7e671f38b2b1c68f5f9ab8aaa08a41f",
"url": "https://chromium.googlesource.com/chromium/src/+/eab39b3dc7e671f38b2b1c68f5f9ab8aaa08a41f"
},
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ce44e9bf0e54bb5c742fc753777ab1ff8c363f09"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@ce44e9bf0e54bb5c742fc753777ab1ff8c363f09",
"title": "ce44e9bf0e54bb5c742fc753777ab1ff8c363f09",
"url": "https://chromium.googlesource.com/chromium/src/+/ce44e9bf0e54bb5c742fc753777ab1ff8c363f09"
},
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "aaf27d82460cd4cac54893a87ab7f3294d48154e"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@aaf27d82460cd4cac54893a87ab7f3294d48154e",
"title": "aaf27d82460cd4cac54893a87ab7f3294d48154e",
"url": "https://chromium.googlesource.com/chromium/src/+/aaf27d82460cd4cac54893a87ab7f3294d48154e"
},
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "7141cbbe29ac2b0a7e49b6529dcd7f14709bd703"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@7141cbbe29ac2b0a7e49b6529dcd7f14709bd703",
"title": "7141cbbe29ac2b0a7e49b6529dcd7f14709bd703",
"url": "https://chromium.googlesource.com/chromium/src/+/7141cbbe29ac2b0a7e49b6529dcd7f14709bd703"
},
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "fe4bb9f65dff2bb21284651eb7188bae3e017f3a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@fe4bb9f65dff2bb21284651eb7188bae3e017f3a",
"title": "fe4bb9f65dff2bb21284651eb7188bae3e017f3a",
"url": "https://chromium.googlesource.com/chromium/src/+/fe4bb9f65dff2bb21284651eb7188bae3e017f3a"
},
{
"gitiles": {
"ref": "refs/branch-heads/7258",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "93c4a81282336275011f236f3db6a64fc8921acf"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7258@93c4a81282336275011f236f3db6a64fc8921acf",
"title": "93c4a81282336275011f236f3db6a64fc8921acf",
"url": "https://chromium.googlesource.com/chromium/src/+/93c4a81282336275011f236f3db6a64fc8921acf"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "93c4a81282336275011f236f3db6a64fc8921acf",
"ref": "refs/branch-heads/7258"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8874805950291820560"
},
{
"key": "scheduler_job_id",
"value": "chromium-m139/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[10:28:46.068] Scheduled build:
{
"id": "8709375888311100993",
"builder": {
"project": "chromium-m139",
"bucket": "ci",
"builder": "win32-official"
},
"number": 135,
"createdBy": "project:chromium-m139",
"createTime": "2025-07-14T10:28:45.597165788Z",
"updateTime": "2025-07-14T10:28:45.597165788Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "93c4a81282336275011f236f3db6a64fc8921acf",
"ref": "refs/branch-heads/7258"
}
}
}
[10:28:46.068] Task URL: https://cr-buildbucket.appspot.com/build/8709375888311100993
[10:28:46.068] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:2:0) after 7m46s
[10:28:46.202] Received PubSub notification, asking Buildbucket for the build status
[10:28:46.269] Build status: SCHEDULED
[10:28:50.026] Received PubSub notification, asking Buildbucket for the build status
[10:28:50.070] Build status: STARTED
[10:36:32.084] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:2:0)
[10:36:32.116] Build status: STARTED
[10:36:32.116] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:5:0) after 4m2s
[10:40:34.132] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:5:0)
[10:40:34.163] Build status: STARTED
[10:40:34.163] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:6:0) after 2m9s
[10:42:43.336] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:6:0)
[10:42:43.375] Build status: STARTED
[10:42:43.375] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:7:0) after 5m46s
[10:48:29.440] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:7:0)
[10:48:29.458] Build status: STARTED
[10:48:29.458] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:8:0) after 6m36s
[10:55:05.473] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:8:0)
[10:55:05.517] Build status: STARTED
[10:55:05.517] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:9:0) after 4m43s
[10:59:48.638] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:9:0)
[10:59:48.662] Build status: STARTED
[10:59:48.663] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:10:0) after 1m54s
[11:01:43.807] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:10:0)
[11:01:44.034] Build status: STARTED
[11:01:44.034] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:11:0) after 1m43s
[11:03:27.007] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:11:0)
[11:03:27.093] Build status: STARTED
[11:03:27.093] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:12:0) after 5m5s
[11:08:32.109] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:12:0)
[11:08:32.150] Build status: STARTED
[11:08:32.150] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:13:0) after 5m41s
[11:14:13.268] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:13:0)
[11:14:13.286] Build status: STARTED
[11:14:13.286] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:14:0) after 7m3s
[11:21:16.308] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:14:0)
[11:21:16.361] Build status: STARTED
[11:21:16.361] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:15:0) after 2m1s
[11:23:17.402] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:15:0)
[11:23:17.497] Build status: STARTED
[11:23:17.497] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:16:0) after 4m56s
[11:28:13.936] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:16:0)
[11:28:13.956] Build status: STARTED
[11:28:13.956] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:17:0) after 8m34s
[11:36:48.020] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:17:0)
[11:36:48.042] Build status: STARTED
[11:36:48.042] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:18:0) after 2m0s
[11:38:48.197] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:18:0)
[11:38:48.218] Build status: STARTED
[11:38:48.218] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:19:0) after 9m31s
[11:48:19.859] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:19:0)
[11:48:19.884] Build status: STARTED
[11:48:19.884] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:20:0) after 6m37s
[11:54:56.990] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:20:0)
[11:54:57.066] Build status: STARTED
[11:54:57.066] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:21:0) after 5m3s
[12:00:00.087] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:21:0)
[12:00:00.122] Build status: STARTED
[12:00:00.122] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:22:0) after 2m27s
[12:02:27.153] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:22:0)
[12:02:27.176] Build status: STARTED
[12:02:27.176] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:23:0) after 6m45s
[12:09:12.306] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:23:0)
[12:09:12.328] Build status: STARTED
[12:09:12.328] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:24:0) after 4m53s
[12:14:05.364] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:24:0)
[12:14:05.414] Build status: STARTED
[12:14:05.414] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:25:0) after 3m0s
[12:17:05.486] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:25:0)
[12:17:05.504] Build status: STARTED
[12:17:05.504] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:26:0) after 4m38s
[12:21:43.534] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:26:0)
[12:21:43.552] Build status: STARTED
[12:21:43.552] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:27:0) after 1m49s
[12:23:32.579] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:27:0)
[12:23:32.608] Build status: STARTED
[12:23:32.608] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:28:0) after 2m45s
[12:26:17.645] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:28:0)
[12:26:17.664] Build status: STARTED
[12:26:17.664] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:29:0) after 4m12s
[12:30:29.688] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:29:0)
[12:30:29.723] Build status: STARTED
[12:30:29.723] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:30:0) after 1m5s
[12:31:34.744] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:30:0)
[12:31:34.783] Build status: STARTED
[12:31:34.783] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:31:0) after 5m7s
[12:36:41.805] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:31:0)
[12:36:41.822] Build status: STARTED
[12:36:41.822] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:32:0) after 6m15s
[12:42:56.847] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:32:0)
[12:42:56.864] Build status: STARTED
[12:42:56.864] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:33:0) after 6m32s
[12:49:28.934] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:33:0)
[12:49:28.955] Build status: STARTED
[12:49:28.956] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:34:0) after 9m17s
[12:58:45.981] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:34:0)
[12:58:46.013] Build status: STARTED
[12:58:46.013] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:35:0) after 2m29s
[13:01:15.037] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:35:0)
[13:01:15.054] Build status: STARTED
[13:01:15.054] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:36:0) after 1m19s
[13:02:34.170] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:36:0)
[13:02:34.249] Build status: STARTED
[13:02:34.249] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:37:0) after 5m24s
[13:07:58.276] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:37:0)
[13:07:58.307] Build status: STARTED
[13:07:58.307] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:38:0) after 9m1s
[13:16:59.386] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:38:0)
[13:16:59.471] Build status: STARTED
[13:16:59.471] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:39:0) after 6m29s
[13:23:28.567] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:39:0)
[13:23:28.589] Build status: STARTED
[13:23:28.589] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:40:0) after 7m27s
[13:30:55.641] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:40:0)
[13:30:55.666] Build status: STARTED
[13:30:55.666] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:41:0) after 6m13s
[13:37:08.716] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:41:0)
[13:37:08.753] Build status: STARTED
[13:37:08.753] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:42:0) after 1m45s
[13:38:53.930] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:42:0)
[13:38:53.949] Build status: STARTED
[13:38:53.949] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:43:0) after 6m42s
[13:45:35.975] Handling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:43:0)
[13:45:35.995] Build status: STARTED
[13:45:35.995] Scheduling timer "check-buildbucket-build-status" (chromium-m139/win32-official:8874805950291820560:44:0) after 5m57s
[13:50:04.326] Received PubSub notification, asking Buildbucket for the build status
[13:50:04.349] Build:
{
"id": "8709375888311100993",
"builder": {
"project": "chromium-m139",
"bucket": "ci",
"builder": "win32-official"
},
"number": 135,
"createdBy": "project:chromium-m139",
"createTime": "2025-07-14T10:28:45.597165788Z",
"startTime": "2025-07-14T10:28:49.817741378Z",
"endTime": "2025-07-14T13:50:04.044985583Z",
"updateTime": "2025-07-14T13:50:04.044985583Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "93c4a81282336275011f236f3db6a64fc8921acf",
"ref": "refs/branch-heads/7258"
}
}
}
[13:50:04.349] Invocation finished in 3h21m20.024410062s with status SUCCEEDED