[16:40:46.677] New invocation is queued and will start shortly
[16:40:47.839] Starting the invocation (attempt 1)
[16:40:47.867] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/ca0838f00c72c544e7156cb1769c5cab4c710ce4"
[16:40:47.867] Popped gitiles commit info from properties and tags
[16:40:47.867] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[16:40:47.868] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[16:40:47.868] Buildbucket request:
{
"requestId": "8902686409273851072",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-old"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8902686409273851072",
"job": "r8/linux-old",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "c45fc471aa72ecae0cf28832805faccaef45c025"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@c45fc471aa72ecae0cf28832805faccaef45c025",
"title": "c45fc471aa72ecae0cf28832805faccaef45c025",
"url": "https://r8.googlesource.com/r8/+/c45fc471aa72ecae0cf28832805faccaef45c025"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "aeaaf7bf934a650423f8aa0af055f011f9291f17"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@aeaaf7bf934a650423f8aa0af055f011f9291f17",
"title": "aeaaf7bf934a650423f8aa0af055f011f9291f17",
"url": "https://r8.googlesource.com/r8/+/aeaaf7bf934a650423f8aa0af055f011f9291f17"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "c6197cba8c46fb6e048b2c38231700f3cb099e27"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@c6197cba8c46fb6e048b2c38231700f3cb099e27",
"title": "c6197cba8c46fb6e048b2c38231700f3cb099e27",
"url": "https://r8.googlesource.com/r8/+/c6197cba8c46fb6e048b2c38231700f3cb099e27"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "9ce7e6f1f0539141911ccfa83b108d35f331e251"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@9ce7e6f1f0539141911ccfa83b108d35f331e251",
"title": "9ce7e6f1f0539141911ccfa83b108d35f331e251",
"url": "https://r8.googlesource.com/r8/+/9ce7e6f1f0539141911ccfa83b108d35f331e251"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "791fefe834aece2aa5ea915b73b310a25c96679e"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@791fefe834aece2aa5ea915b73b310a25c96679e",
"title": "791fefe834aece2aa5ea915b73b310a25c96679e",
"url": "https://r8.googlesource.com/r8/+/791fefe834aece2aa5ea915b73b310a25c96679e"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "d0804fd1926db0699ebf920fa3f83f24d3592fa3"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@d0804fd1926db0699ebf920fa3f83f24d3592fa3",
"title": "d0804fd1926db0699ebf920fa3f83f24d3592fa3",
"url": "https://r8.googlesource.com/r8/+/d0804fd1926db0699ebf920fa3f83f24d3592fa3"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "9f325cf2c2e9a131afc7cdd48623472506dc3d2f"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@9f325cf2c2e9a131afc7cdd48623472506dc3d2f",
"title": "9f325cf2c2e9a131afc7cdd48623472506dc3d2f",
"url": "https://r8.googlesource.com/r8/+/9f325cf2c2e9a131afc7cdd48623472506dc3d2f"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "ca0838f00c72c544e7156cb1769c5cab4c710ce4"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@ca0838f00c72c544e7156cb1769c5cab4c710ce4",
"title": "ca0838f00c72c544e7156cb1769c5cab4c710ce4",
"url": "https://r8.googlesource.com/r8/+/ca0838f00c72c544e7156cb1769c5cab4c710ce4"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "ca0838f00c72c544e7156cb1769c5cab4c710ce4",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8902686409273851072"
},
{
"key": "scheduler_job_id",
"value": "r8/linux-old"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[16:40:48.439] Scheduled build:
{
"id": "8737256347307242913",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-old"
},
"number": 157,
"createdBy": "project:r8",
"createTime": "2024-09-09T16:40:47.923768836Z",
"updateTime": "2024-09-09T16:40:47.923768836Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "ca0838f00c72c544e7156cb1769c5cab4c710ce4",
"ref": "refs/heads/main"
}
}
}
[16:40:48.439] Task URL: https://cr-buildbucket.appspot.com/build/8737256347307242913
[16:40:48.439] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:2:0) after 1m45s
[16:40:49.319] Received PubSub notification, asking Buildbucket for the build status
[16:40:49.357] Build status: SCHEDULED
[16:42:33.506] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:2:0)
[16:42:33.524] Build status: SCHEDULED
[16:42:33.524] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:4:0) after 1m11s
[16:43:44.570] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:4:0)
[16:43:44.619] Build status: SCHEDULED
[16:43:44.620] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:5:0) after 7m14s
[16:44:24.296] Received PubSub notification, asking Buildbucket for the build status
[16:44:24.321] Build status: STARTED
[16:50:58.617] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:5:0)
[16:50:58.647] Build status: STARTED
[16:50:58.647] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:7:0) after 6m36s
[16:57:34.665] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:7:0)
[16:57:34.682] Build status: STARTED
[16:57:34.682] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:8:0) after 1m28s
[16:59:02.679] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:8:0)
[16:59:02.698] Build status: STARTED
[16:59:02.698] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:9:0) after 2m7s
[17:01:09.765] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:9:0)
[17:01:09.835] Build status: STARTED
[17:01:09.836] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:10:0) after 4m38s
[17:05:47.886] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:10:0)
[17:05:47.913] Build status: STARTED
[17:05:47.913] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:11:0) after 9m2s
[17:14:50.043] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:11:0)
[17:14:50.060] Build status: STARTED
[17:14:50.060] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:12:0) after 3m31s
[17:18:21.086] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:12:0)
[17:18:21.180] Build status: STARTED
[17:18:21.180] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:13:0) after 9m14s
[17:27:35.247] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:13:0)
[17:27:35.274] Build status: STARTED
[17:27:35.274] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:14:0) after 6m12s
[17:33:47.292] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:14:0)
[17:33:47.311] Build status: STARTED
[17:33:47.311] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:15:0) after 7m10s
[17:40:57.332] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:15:0)
[17:40:57.350] Build status: STARTED
[17:40:57.350] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:16:0) after 2m42s
[17:43:39.445] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:16:0)
[17:43:39.478] Build status: STARTED
[17:43:39.478] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:17:0) after 2m35s
[17:46:14.608] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:17:0)
[17:46:14.630] Build status: STARTED
[17:46:14.630] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:18:0) after 7m44s
[17:53:58.711] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:18:0)
[17:53:59.244] Build status: STARTED
[17:53:59.244] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:19:0) after 7m32s
[18:01:31.346] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:19:0)
[18:01:31.363] Build status: STARTED
[18:01:31.363] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:20:0) after 3m19s
[18:04:50.395] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:20:0)
[18:04:50.427] Build status: STARTED
[18:04:50.427] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:21:0) after 9m14s
[18:14:04.548] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:21:0)
[18:14:04.564] Build status: STARTED
[18:14:04.564] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:22:0) after 5m48s
[18:19:52.588] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:22:0)
[18:19:52.608] Build status: STARTED
[18:19:52.608] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:23:0) after 9m9s
[18:29:01.747] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:23:0)
[18:29:01.825] Build status: STARTED
[18:29:01.825] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:24:0) after 5m50s
[18:34:51.890] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:24:0)
[18:34:51.911] Build status: STARTED
[18:34:51.911] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:25:0) after 7m48s
[18:42:40.003] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:25:0)
[18:42:40.068] Build status: STARTED
[18:42:40.068] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:26:0) after 8m13s
[18:50:53.147] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:26:0)
[18:50:53.170] Build status: STARTED
[18:50:53.170] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:27:0) after 8m7s
[18:59:00.187] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:27:0)
[18:59:00.212] Build status: STARTED
[18:59:00.212] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:28:0) after 3m57s
[19:02:57.279] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:28:0)
[19:02:57.442] Build status: STARTED
[19:02:57.443] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:29:0) after 3m39s
[19:06:36.536] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:29:0)
[19:06:36.554] Build status: STARTED
[19:06:36.554] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:30:0) after 5m43s
[19:12:19.583] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:30:0)
[19:12:19.605] Build status: STARTED
[19:12:19.605] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:31:0) after 7m19s
[19:19:38.634] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:31:0)
[19:19:38.650] Build status: STARTED
[19:19:38.650] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:32:0) after 9m1s
[19:28:39.721] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:32:0)
[19:28:39.752] Build status: STARTED
[19:28:39.752] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:33:0) after 2m52s
[19:31:31.778] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:33:0)
[19:31:31.838] Build status: STARTED
[19:31:31.838] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:34:0) after 5m4s
[19:36:35.905] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:34:0)
[19:36:35.935] Build status: STARTED
[19:36:35.935] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:35:0) after 8m57s
[19:45:33.053] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:35:0)
[19:45:33.071] Build status: STARTED
[19:45:33.071] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:36:0) after 2m33s
[19:48:06.088] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:36:0)
[19:48:06.117] Build status: STARTED
[19:48:06.117] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:37:0) after 4m40s
[19:52:46.160] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:37:0)
[19:52:46.184] Build status: STARTED
[19:52:46.184] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:38:0) after 1m35s
[19:54:21.253] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:38:0)
[19:54:21.299] Build status: STARTED
[19:54:21.299] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:39:0) after 1m59s
[19:56:20.363] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:39:0)
[19:56:20.378] Build status: STARTED
[19:56:20.379] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:40:0) after 6m2s
[20:02:22.397] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:40:0)
[20:02:22.430] Build status: STARTED
[20:02:22.430] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:41:0) after 9m13s
[20:11:35.454] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:41:0)
[20:11:35.490] Build status: STARTED
[20:11:35.490] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:42:0) after 7m35s
[20:19:10.560] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:42:0)
[20:19:10.591] Build status: STARTED
[20:19:10.591] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:43:0) after 9m43s
[20:28:53.729] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:43:0)
[20:28:53.746] Build status: STARTED
[20:28:53.746] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:44:0) after 9m48s
[20:38:41.859] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:44:0)
[20:38:41.890] Build status: STARTED
[20:38:41.890] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:45:0) after 7m20s
[20:46:01.921] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:45:0)
[20:46:01.944] Build status: STARTED
[20:46:01.944] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:46:0) after 5m44s
[20:51:45.967] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:46:0)
[20:51:45.985] Build status: STARTED
[20:51:45.985] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:47:0) after 1m48s
[20:53:34.071] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:47:0)
[20:53:34.092] Build status: STARTED
[20:53:34.092] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:48:0) after 9m52s
[21:03:26.147] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:48:0)
[21:03:26.173] Build status: STARTED
[21:03:26.173] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:49:0) after 6m48s
[21:10:14.246] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:49:0)
[21:10:14.263] Build status: STARTED
[21:10:14.263] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:50:0) after 1m46s
[21:12:00.386] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:50:0)
[21:12:00.425] Build status: STARTED
[21:12:00.425] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:51:0) after 6m34s
[21:18:34.464] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:51:0)
[21:18:34.484] Build status: STARTED
[21:18:34.484] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:52:0) after 6m24s
[21:24:58.502] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:52:0)
[21:24:58.544] Build status: STARTED
[21:24:58.544] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:53:0) after 7m23s
[21:32:21.565] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:53:0)
[21:32:21.630] Build status: STARTED
[21:32:21.630] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:54:0) after 5m6s
[21:37:27.696] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:54:0)
[21:37:27.715] Build status: STARTED
[21:37:27.715] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:55:0) after 1m48s
[21:39:15.697] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:55:0)
[21:39:15.739] Build status: STARTED
[21:39:15.740] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:56:0) after 6m24s
[21:45:39.784] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:56:0)
[21:45:39.802] Build status: STARTED
[21:45:39.802] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:57:0) after 6m57s
[21:52:36.836] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:57:0)
[21:52:36.901] Build status: STARTED
[21:52:36.901] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:58:0) after 4m32s
[21:57:08.918] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:58:0)
[21:57:08.954] Build status: STARTED
[21:57:08.954] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:59:0) after 6m44s
[22:03:52.984] Handling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:59:0)
[22:03:53.012] Build status: STARTED
[22:03:53.012] Scheduling timer "check-buildbucket-build-status" (r8/linux-old:8902686409273851072:60:0) after 5m6s
[22:05:22.984] Received PubSub notification, asking Buildbucket for the build status
[22:05:23.010] Build:
{
"id": "8737256347307242913",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-old"
},
"number": 157,
"createdBy": "project:r8",
"createTime": "2024-09-09T16:40:47.923768836Z",
"startTime": "2024-09-09T16:44:23.939027835Z",
"endTime": "2024-09-09T22:05:20.574973768Z",
"updateTime": "2024-09-09T22:05:20.574973768Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "ca0838f00c72c544e7156cb1769c5cab4c710ce4",
"ref": "refs/heads/main"
}
}
}
[22:05:23.010] Invocation finished in 5h24m36.346853154s with status FAILED