[15:36:47.665] New invocation is queued and will start shortly
[15:36:48.747] Starting the invocation (attempt 1)
[15:36:48.783] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/5adfdb9c540f4b0b4d749423602ef25e7fb3913b"
[15:36:48.783] Popped gitiles commit info from properties and tags
[15:36:48.783] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:36:48.783] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:36:48.784] Buildbucket request:
{
"requestId": "8952881154146976752",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk11"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8952881154146976752",
"job": "r8/linux-jdk11",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "67af15f7d058c71b2cfb48b9b0c4e7777f06104a"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@67af15f7d058c71b2cfb48b9b0c4e7777f06104a",
"title": "67af15f7d058c71b2cfb48b9b0c4e7777f06104a",
"url": "https://r8.googlesource.com/r8/+/67af15f7d058c71b2cfb48b9b0c4e7777f06104a"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "75f448d37197ef3cd89ba8ff0892b918a24b389b"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@75f448d37197ef3cd89ba8ff0892b918a24b389b",
"title": "75f448d37197ef3cd89ba8ff0892b918a24b389b",
"url": "https://r8.googlesource.com/r8/+/75f448d37197ef3cd89ba8ff0892b918a24b389b"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "5adfdb9c540f4b0b4d749423602ef25e7fb3913b"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@5adfdb9c540f4b0b4d749423602ef25e7fb3913b",
"title": "5adfdb9c540f4b0b4d749423602ef25e7fb3913b",
"url": "https://r8.googlesource.com/r8/+/5adfdb9c540f4b0b4d749423602ef25e7fb3913b"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "5adfdb9c540f4b0b4d749423602ef25e7fb3913b",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8952881154146976752"
},
{
"key": "scheduler_job_id",
"value": "r8/linux-jdk11"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[15:36:49.285] Scheduled build:
{
"id": "8787451092183453137",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk11"
},
"number": 2617,
"createdBy": "project:r8",
"createTime": "2023-03-05T15:36:48.916542335Z",
"updateTime": "2023-03-05T15:36:48.916542335Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "5adfdb9c540f4b0b4d749423602ef25e7fb3913b",
"ref": "refs/heads/main"
}
}
}
[15:36:49.285] Task URL: https://cr-buildbucket.appspot.com/build/8787451092183453137
[15:36:49.285] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:2:0) after 7m47s
[15:44:36.830] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:2:0)
[15:44:36.847] Build status: SCHEDULED
[15:44:36.847] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:3:0) after 9m34s
[15:54:11.243] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:3:0)
[15:54:11.284] Build status: SCHEDULED
[15:54:11.284] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:4:0) after 8m2s
[16:02:13.853] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:4:0)
[16:02:13.910] Build status: SCHEDULED
[16:02:13.910] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:5:0) after 8m25s
[16:10:38.940] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:5:0)
[16:10:38.960] Build status: SCHEDULED
[16:10:38.960] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:6:0) after 2m19s
[16:12:57.975] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:6:0)
[16:12:57.996] Build status: SCHEDULED
[16:12:57.996] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:7:0) after 1m37s
[16:14:35.172] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:7:0)
[16:14:35.194] Build status: SCHEDULED
[16:14:35.194] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:8:0) after 5m1s
[16:19:36.253] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:8:0)
[16:19:36.292] Build status: SCHEDULED
[16:19:36.292] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:9:0) after 7m32s
[16:27:08.484] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:9:0)
[16:27:08.542] Build status: SCHEDULED
[16:27:08.542] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:10:0) after 1m43s
[16:28:51.759] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:10:0)
[16:28:51.779] Build status: SCHEDULED
[16:28:51.779] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:11:0) after 8m46s
[16:37:37.992] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:11:0)
[16:37:38.048] Build status: SCHEDULED
[16:37:38.048] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:12:0) after 9m56s
[16:47:34.069] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:12:0)
[16:47:34.096] Build status: SCHEDULED
[16:47:34.096] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:13:0) after 3m36s
[16:51:10.297] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:13:0)
[16:51:10.337] Build status: SCHEDULED
[16:51:10.337] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:14:0) after 2m32s
[16:53:42.353] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:14:0)
[16:53:42.378] Build status: SCHEDULED
[16:53:42.378] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:15:0) after 5m2s
[16:58:44.403] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:15:0)
[16:58:44.446] Build status: SCHEDULED
[16:58:44.446] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:16:0) after 2m6s
[17:00:50.593] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:16:0)
[17:00:50.645] Build status: SCHEDULED
[17:00:50.645] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:17:0) after 9m10s
[17:10:00.663] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:17:0)
[17:10:00.703] Build status: SCHEDULED
[17:10:00.703] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:18:0) after 9m36s
[17:19:37.038] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:18:0)
[17:19:37.070] Build status: SCHEDULED
[17:19:37.070] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:19:0) after 5m3s
[17:24:40.412] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:19:0)
[17:24:40.432] Build status: SCHEDULED
[17:24:40.432] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:20:0) after 6m34s
[17:31:14.549] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:20:0)
[17:31:14.588] Build status: SCHEDULED
[17:31:14.588] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:21:0) after 6m22s
[17:37:38.804] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:21:0)
[17:37:38.849] Build status: SCHEDULED
[17:37:38.849] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:22:0) after 4m57s
[17:42:36.231] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:22:0)
[17:42:36.247] Build status: SCHEDULED
[17:42:36.247] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:23:0) after 3m32s
[17:46:08.450] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:23:0)
[17:46:08.471] Build status: SCHEDULED
[17:46:08.471] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:24:0) after 6m22s
[17:52:30.528] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:24:0)
[17:52:30.547] Build status: SCHEDULED
[17:52:30.547] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:25:0) after 7m23s
[17:59:54.567] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:25:0)
[17:59:54.587] Build status: SCHEDULED
[17:59:54.587] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:26:0) after 7m19s
[18:04:21.223] Received PubSub notification, asking Buildbucket for the build status
[18:04:21.285] Build status: STARTED
[18:07:13.951] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:26:0)
[18:07:13.981] Build status: STARTED
[18:07:13.981] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:28:0) after 3m56s
[18:11:10.575] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:28:0)
[18:11:10.607] Build status: STARTED
[18:11:10.607] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:29:0) after 2m24s
[18:13:34.785] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:29:0)
[18:13:34.819] Build status: STARTED
[18:13:34.820] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:30:0) after 5m5s
[18:18:39.841] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:30:0)
[18:18:39.871] Build status: STARTED
[18:18:39.872] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:31:0) after 6m3s
[18:24:42.890] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:31:0)
[18:24:42.910] Build status: STARTED
[18:24:42.910] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:32:0) after 3m40s
[18:28:23.165] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:32:0)
[18:28:23.188] Build status: STARTED
[18:28:23.188] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:33:0) after 4m18s
[18:32:41.466] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:33:0)
[18:32:41.488] Build status: STARTED
[18:32:41.488] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:34:0) after 5m51s
[18:38:32.766] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:34:0)
[18:38:32.793] Build status: STARTED
[18:38:32.793] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:35:0) after 4m23s
[18:42:56.049] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:35:0)
[18:42:56.092] Build status: STARTED
[18:42:56.092] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:36:0) after 4m30s
[18:47:26.217] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:36:0)
[18:47:26.238] Build status: STARTED
[18:47:26.238] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:37:0) after 8m28s
[18:55:54.262] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:37:0)
[18:55:54.289] Build status: STARTED
[18:55:54.289] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:38:0) after 3m32s
[18:59:26.478] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:38:0)
[18:59:26.580] Build status: STARTED
[18:59:26.580] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:39:0) after 2m46s
[19:02:12.598] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:39:0)
[19:02:12.621] Build status: STARTED
[19:02:12.621] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:40:0) after 9m37s
[19:11:49.643] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:40:0)
[19:11:49.668] Build status: STARTED
[19:11:49.668] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:41:0) after 4m15s
[19:16:04.698] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:41:0)
[19:16:04.732] Build status: STARTED
[19:16:04.732] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:42:0) after 7m5s
[19:23:09.935] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:42:0)
[19:23:09.969] Build status: STARTED
[19:23:09.969] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:43:0) after 9m11s
[19:32:21.262] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:43:0)
[19:32:21.301] Build status: STARTED
[19:32:21.301] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:44:0) after 8m58s
[19:41:19.322] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:44:0)
[19:41:19.346] Build status: STARTED
[19:41:19.346] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:45:0) after 2m0s
[19:43:19.368] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:45:0)
[19:43:19.386] Build status: STARTED
[19:43:19.386] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:46:0) after 7m52s
[19:51:11.613] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:46:0)
[19:51:11.635] Build status: STARTED
[19:51:11.635] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:47:0) after 9m52s
[20:01:03.651] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:47:0)
[20:01:03.712] Build status: STARTED
[20:01:03.713] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:48:0) after 4m18s
[20:05:22.160] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:48:0)
[20:05:22.197] Build status: STARTED
[20:05:22.197] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:49:0) after 6m49s
[20:12:11.521] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:49:0)
[20:12:11.603] Build status: STARTED
[20:12:11.603] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:50:0) after 1m40s
[20:13:51.777] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:50:0)
[20:13:51.811] Build status: STARTED
[20:13:51.811] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:51:0) after 7m21s
[20:21:12.830] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:51:0)
[20:21:12.863] Build status: STARTED
[20:21:12.864] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:8952881154146976752:52:0) after 6m50s
[20:24:03.490] Received PubSub notification, asking Buildbucket for the build status
[20:24:03.508] Build:
{
"id": "8787451092183453137",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk11"
},
"number": 2617,
"createdBy": "project:r8",
"createTime": "2023-03-05T15:36:48.916542335Z",
"startTime": "2023-03-05T18:04:20.575397Z",
"endTime": "2023-03-05T20:24:03.134997199Z",
"updateTime": "2023-03-05T20:24:03.134997199Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "5adfdb9c540f4b0b4d749423602ef25e7fb3913b",
"ref": "refs/heads/main"
}
}
}
[20:24:03.508] Invocation finished in 4h47m15.848398892s with status SUCCEEDED