[21:44:04.405] New invocation is queued and will start shortly
[21:44:05.577] Starting the invocation (attempt 1)
[21:44:05.610] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/f454f4ffd11089d1f896297ced148a92780d72f2"
[21:44:05.610] Popped gitiles commit info from properties and tags
[21:44:05.610] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:44:05.610] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:44:05.610] Buildbucket request:
{
"requestId": "8896687927852905360",
"builder": {
"project": "chromium-m130",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8896687927852905360",
"job": "chromium-m130/win32-official",
"triggers": [
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "5a2a455b823b5c7aacef69aa0672342a856aa918"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@5a2a455b823b5c7aacef69aa0672342a856aa918",
"title": "5a2a455b823b5c7aacef69aa0672342a856aa918",
"url": "https://chromium.googlesource.com/chromium/src/+/5a2a455b823b5c7aacef69aa0672342a856aa918"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "bd72c251f821ffa34f746affb355b8eeb6d3064a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@bd72c251f821ffa34f746affb355b8eeb6d3064a",
"title": "bd72c251f821ffa34f746affb355b8eeb6d3064a",
"url": "https://chromium.googlesource.com/chromium/src/+/bd72c251f821ffa34f746affb355b8eeb6d3064a"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "5a6032bb7cee181e9cef2c4dfdadfd6adba74b0f"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@5a6032bb7cee181e9cef2c4dfdadfd6adba74b0f",
"title": "5a6032bb7cee181e9cef2c4dfdadfd6adba74b0f",
"url": "https://chromium.googlesource.com/chromium/src/+/5a6032bb7cee181e9cef2c4dfdadfd6adba74b0f"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ac10c4d1efa06c3fcc5a5371b80cd55fdcf3453c"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@ac10c4d1efa06c3fcc5a5371b80cd55fdcf3453c",
"title": "ac10c4d1efa06c3fcc5a5371b80cd55fdcf3453c",
"url": "https://chromium.googlesource.com/chromium/src/+/ac10c4d1efa06c3fcc5a5371b80cd55fdcf3453c"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "16b51389b29c9c46cdab9a1318262594def1c2bf"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@16b51389b29c9c46cdab9a1318262594def1c2bf",
"title": "16b51389b29c9c46cdab9a1318262594def1c2bf",
"url": "https://chromium.googlesource.com/chromium/src/+/16b51389b29c9c46cdab9a1318262594def1c2bf"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "ba93c60620437d1acb97beeef15f70d84a31bc5a"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@ba93c60620437d1acb97beeef15f70d84a31bc5a",
"title": "ba93c60620437d1acb97beeef15f70d84a31bc5a",
"url": "https://chromium.googlesource.com/chromium/src/+/ba93c60620437d1acb97beeef15f70d84a31bc5a"
},
{
"gitiles": {
"ref": "refs/branch-heads/6723",
"repo": "https://chromium.googlesource.com/chromium/src",
"revision": "f454f4ffd11089d1f896297ced148a92780d72f2"
},
"id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/6723@f454f4ffd11089d1f896297ced148a92780d72f2",
"title": "f454f4ffd11089d1f896297ced148a92780d72f2",
"url": "https://chromium.googlesource.com/chromium/src/+/f454f4ffd11089d1f896297ced148a92780d72f2"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f454f4ffd11089d1f896297ced148a92780d72f2",
"ref": "refs/branch-heads/6723"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8896687927852905360"
},
{
"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"
}
}
[21:44:06.514] Scheduled build:
{
"id": "8731257865804541489",
"builder": {
"project": "chromium-m130",
"bucket": "ci",
"builder": "win32-official"
},
"number": 330,
"createdBy": "project:chromium-m130",
"createTime": "2024-11-14T21:44:05.670537359Z",
"updateTime": "2024-11-14T21:44:05.670537359Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f454f4ffd11089d1f896297ced148a92780d72f2",
"ref": "refs/branch-heads/6723"
}
}
}
[21:44:06.514] Task URL: https://cr-buildbucket.appspot.com/build/8731257865804541489
[21:44:06.514] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:2:0) after 7m26s
[21:44:23.821] Received PubSub notification, asking Buildbucket for the build status
[21:44:23.844] Build status: STARTED
[21:44:38.909] Received PubSub notification, asking Buildbucket for the build status
[21:44:38.928] Build status: STARTED
[21:51:32.532] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:2:0)
[21:51:32.548] Build status: STARTED
[21:51:32.548] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:5:0) after 1m56s
[21:53:28.580] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:5:0)
[21:53:28.599] Build status: STARTED
[21:53:28.599] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:6:0) after 8m34s
[22:02:02.613] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:6:0)
[22:02:02.649] Build status: STARTED
[22:02:02.649] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:7:0) after 1m54s
[22:03:56.673] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:7:0)
[22:03:56.745] Build status: STARTED
[22:03:56.745] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:8:0) after 1m52s
[22:05:48.744] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:8:0)
[22:05:48.769] Build status: STARTED
[22:05:48.769] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:9:0) after 8m39s
[22:14:27.861] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:9:0)
[22:14:27.882] Build status: STARTED
[22:14:27.882] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:10:0) after 9m35s
[22:24:02.898] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:10:0)
[22:24:02.929] Build status: STARTED
[22:24:02.929] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:11:0) after 3m37s
[22:27:39.925] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:11:0)
[22:27:39.957] Build status: STARTED
[22:27:39.957] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:12:0) after 7m51s
[22:35:31.022] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:12:0)
[22:35:31.052] Build status: STARTED
[22:35:31.052] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:13:0) after 1m28s
[22:36:59.066] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:13:0)
[22:36:59.169] Build status: STARTED
[22:36:59.169] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:14:0) after 1m29s
[22:38:28.138] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:14:0)
[22:38:28.158] Build status: STARTED
[22:38:28.158] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:15:0) after 4m42s
[22:43:10.211] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:15:0)
[22:43:10.229] Build status: STARTED
[22:43:10.229] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:16:0) after 5m25s
[22:48:35.298] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:16:0)
[22:48:35.318] Build status: STARTED
[22:48:35.318] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:17:0) after 4m31s
[22:53:06.340] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:17:0)
[22:53:06.365] Build status: STARTED
[22:53:06.365] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:18:0) after 7m13s
[23:00:19.535] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:18:0)
[23:00:19.557] Build status: STARTED
[23:00:19.557] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:19:0) after 2m6s
[23:02:25.602] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:19:0)
[23:02:25.621] Build status: STARTED
[23:02:25.621] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:20:0) after 6m40s
[23:09:05.653] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:20:0)
[23:09:05.684] Build status: STARTED
[23:09:05.684] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:21:0) after 7m9s
[23:16:14.756] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:21:0)
[23:16:14.776] Build status: STARTED
[23:16:14.776] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:22:0) after 4m46s
[23:21:00.755] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:22:0)
[23:21:00.781] Build status: STARTED
[23:21:00.781] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:23:0) after 7m31s
[23:28:31.847] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:23:0)
[23:28:31.867] Build status: STARTED
[23:28:31.867] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:24:0) after 4m11s
[23:32:42.861] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:24:0)
[23:32:42.881] Build status: STARTED
[23:32:42.881] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:25:0) after 8m25s
[23:41:08.239] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:25:0)
[23:41:08.282] Build status: STARTED
[23:41:08.282] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:26:0) after 1m19s
[23:42:27.261] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:26:0)
[23:42:27.287] Build status: STARTED
[23:42:27.287] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:27:0) after 6m23s
[23:48:50.295] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:27:0)
[23:48:50.314] Build status: STARTED
[23:48:50.314] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:28:0) after 9m44s
[23:58:34.483] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:28:0)
[23:58:34.501] Build status: STARTED
[23:58:34.501] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:29:0) after 9m17s
[00:07:51.625] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:29:0)
[00:07:51.643] Build status: STARTED
[00:07:51.643] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:30:0) after 3m48s
[00:11:39.677] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:30:0)
[00:11:39.696] Build status: STARTED
[00:11:39.696] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:31:0) after 5m59s
[00:17:38.721] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:31:0)
[00:17:38.742] Build status: STARTED
[00:17:38.742] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:32:0) after 3m27s
[00:21:05.785] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:32:0)
[00:21:05.805] Build status: STARTED
[00:21:05.806] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:33:0) after 2m59s
[00:24:04.880] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:33:0)
[00:24:04.913] Build status: STARTED
[00:24:04.913] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:34:0) after 3m18s
[00:27:22.951] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:34:0)
[00:27:23.070] Build status: STARTED
[00:27:23.070] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:35:0) after 1m47s
[00:29:10.127] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:35:0)
[00:29:10.159] Build status: STARTED
[00:29:10.159] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:36:0) after 8m21s
[00:37:31.179] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:36:0)
[00:37:31.196] Build status: STARTED
[00:37:31.196] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:37:0) after 5m5s
[00:42:36.246] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:37:0)
[00:42:36.263] Build status: STARTED
[00:42:36.263] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:38:0) after 1m53s
[00:44:29.366] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:38:0)
[00:44:29.387] Build status: STARTED
[00:44:29.387] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:39:0) after 1m25s
[00:45:54.425] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:39:0)
[00:45:54.444] Build status: STARTED
[00:45:54.444] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:40:0) after 8m31s
[00:54:25.463] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:40:0)
[00:54:25.512] Build status: STARTED
[00:54:25.512] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:41:0) after 3m51s
[00:58:16.532] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:41:0)
[00:58:16.838] Build status: STARTED
[00:58:16.838] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:42:0) after 1m41s
[00:59:57.854] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:42:0)
[00:59:57.874] Build status: STARTED
[00:59:57.874] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:43:0) after 2m40s
[01:02:37.944] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:43:0)
[01:02:37.966] Build status: STARTED
[01:02:37.966] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:44:0) after 8m58s
[01:11:35.991] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:44:0)
[01:11:36.018] Build status: STARTED
[01:11:36.018] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:45:0) after 3m29s
[01:15:05.035] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:45:0)
[01:15:05.053] Build status: STARTED
[01:15:05.053] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:46:0) after 5m4s
[01:20:09.121] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:46:0)
[01:20:09.146] Build status: STARTED
[01:20:09.146] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:47:0) after 1m45s
[01:21:54.173] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:47:0)
[01:21:54.191] Build status: STARTED
[01:21:54.191] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:48:0) after 3m54s
[01:25:48.228] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:48:0)
[01:25:48.248] Build status: STARTED
[01:25:48.248] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:49:0) after 2m21s
[01:28:09.475] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:49:0)
[01:28:09.499] Build status: STARTED
[01:28:09.499] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:50:0) after 9m27s
[01:37:36.520] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:50:0)
[01:37:36.537] Build status: STARTED
[01:37:36.537] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:51:0) after 9m36s
[01:47:12.609] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:51:0)
[01:47:12.848] Build status: STARTED
[01:47:12.848] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:52:0) after 5m1s
[01:52:13.920] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:52:0)
[01:52:14.008] Build status: STARTED
[01:52:14.008] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:53:0) after 2m58s
[01:55:12.043] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:53:0)
[01:55:12.061] Build status: STARTED
[01:55:12.061] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:54:0) after 8m13s
[02:03:25.090] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:54:0)
[02:03:25.111] Build status: STARTED
[02:03:25.111] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:55:0) after 1m28s
[02:04:53.127] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:55:0)
[02:04:53.148] Build status: STARTED
[02:04:53.148] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:56:0) after 9m44s
[02:14:37.213] Handling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:56:0)
[02:14:37.234] Build status: STARTED
[02:14:37.234] Scheduling timer "check-buildbucket-build-status" (chromium-m130/win32-official:8896687927852905360:57:0) after 9m15s
[02:16:40.093] Received PubSub notification, asking Buildbucket for the build status
[02:16:40.111] Build:
{
"id": "8731257865804541489",
"builder": {
"project": "chromium-m130",
"bucket": "ci",
"builder": "win32-official"
},
"number": 330,
"createdBy": "project:chromium-m130",
"createTime": "2024-11-14T21:44:05.670537359Z",
"startTime": "2024-11-14T21:44:18.834504898Z",
"endTime": "2024-11-15T02:16:39.740894600Z",
"updateTime": "2024-11-15T02:16:39.740894600Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f454f4ffd11089d1f896297ced148a92780d72f2",
"ref": "refs/branch-heads/6723"
}
}
}
[02:16:40.111] Invocation finished in 4h32m35.777486774s with status SUCCEEDED