[14:40:16.796] New invocation is queued and will start shortly
[14:40:17.911] Starting the invocation (attempt 1)
[14:40:17.940] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/f3421b579a32dd06270d81c6880682dba6193781"
[14:40:17.940] Popped gitiles commit info from properties and tags
[14:40:17.940] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[14:40:17.941] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[14:40:17.941] Buildbucket request:
{
"requestId": "9001082295922379456",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk11"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "f3421b579a32dd06270d81c6880682dba6193781"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@f3421b579a32dd06270d81c6880682dba6193781",
"title": "f3421b579a32dd06270d81c6880682dba6193781",
"url": "https://r8.googlesource.com/r8/+/f3421b579a32dd06270d81c6880682dba6193781"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "f3421b579a32dd06270d81c6880682dba6193781",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "9001082295922379456"
},
{
"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"
}
}
[14:40:18.420] Scheduled build:
{
"id": "8835652233936573649",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk11"
},
"number": 503,
"createdBy": "project:r8",
"createTime": "2021-09-19T14:40:18.005967619Z",
"updateTime": "2021-09-19T14:40:18.215709014Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "f3421b579a32dd06270d81c6880682dba6193781",
"ref": "refs/heads/main"
}
},
"canary": true
}
[14:40:18.420] Task URL: https://cr-buildbucket.appspot.com/build/8835652233936573649
[14:40:18.420] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:2:0) after 7m52s
[14:48:10.441] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:2:0)
[14:48:10.482] Build status: SCHEDULED
[14:48:10.482] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:3:0) after 2m24s
[14:50:34.499] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:3:0)
[14:50:34.528] Build status: SCHEDULED
[14:50:34.528] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:4:0) after 5m53s
[14:56:27.547] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:4:0)
[14:56:27.579] Build status: SCHEDULED
[14:56:27.579] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:5:0) after 7m46s
[15:04:13.724] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:5:0)
[15:04:13.760] Build status: SCHEDULED
[15:04:13.760] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:6:0) after 4m32s
[15:08:45.819] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:6:0)
[15:08:45.868] Build status: SCHEDULED
[15:08:45.868] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:7:0) after 4m18s
[15:13:03.909] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:7:0)
[15:13:03.935] Build status: SCHEDULED
[15:13:03.935] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:8:0) after 3m52s
[15:16:55.954] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:8:0)
[15:16:55.986] Build status: SCHEDULED
[15:16:55.986] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:9:0) after 8m28s
[15:25:23.981] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:9:0)
[15:25:24.011] Build status: SCHEDULED
[15:25:24.011] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:10:0) after 9m16s
[15:34:40.032] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:10:0)
[15:34:40.081] Build status: SCHEDULED
[15:34:40.081] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:11:0) after 5m38s
[15:40:18.309] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:11:0)
[15:40:18.363] Build status: SCHEDULED
[15:40:18.363] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:12:0) after 5m16s
[15:45:34.485] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:12:0)
[15:45:34.514] Build status: SCHEDULED
[15:45:34.514] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:13:0) after 9m10s
[15:54:44.498] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:13:0)
[15:54:44.552] Build status: SCHEDULED
[15:54:44.552] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:14:0) after 8m14s
[16:02:58.570] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:14:0)
[16:02:58.602] Build status: SCHEDULED
[16:02:58.602] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:15:0) after 4m59s
[16:07:57.621] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:15:0)
[16:07:57.678] Build status: SCHEDULED
[16:07:57.678] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:16:0) after 8m0s
[16:15:57.694] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:16:0)
[16:15:57.722] Build status: SCHEDULED
[16:15:57.722] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:17:0) after 4m24s
[16:20:21.746] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:17:0)
[16:20:21.777] Build status: SCHEDULED
[16:20:21.777] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:18:0) after 6m31s
[16:26:52.794] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:18:0)
[16:26:52.830] Build status: SCHEDULED
[16:26:52.830] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:19:0) after 7m38s
[16:34:30.845] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:19:0)
[16:34:30.889] Build status: SCHEDULED
[16:34:30.889] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:20:0) after 6m28s
[16:40:58.920] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:20:0)
[16:40:58.966] Build status: SCHEDULED
[16:40:58.966] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:21:0) after 8m40s
[16:49:38.983] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:21:0)
[16:49:39.014] Build status: SCHEDULED
[16:49:39.014] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:22:0) after 4m50s
[16:54:29.053] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:22:0)
[16:54:29.080] Build status: SCHEDULED
[16:54:29.080] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:23:0) after 1m21s
[16:55:50.142] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:23:0)
[16:55:50.184] Build status: SCHEDULED
[16:55:50.184] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:24:0) after 1m39s
[16:57:29.202] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:24:0)
[16:57:29.235] Build status: SCHEDULED
[16:57:29.235] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:25:0) after 6m11s
[17:03:40.257] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:25:0)
[17:03:40.294] Build status: SCHEDULED
[17:03:40.294] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:26:0) after 4m8s
[17:07:48.310] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:26:0)
[17:07:48.380] Build status: SCHEDULED
[17:07:48.380] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:27:0) after 5m41s
[17:13:29.544] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:27:0)
[17:13:29.586] Build status: SCHEDULED
[17:13:29.586] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:28:0) after 7m17s
[17:20:46.602] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:28:0)
[17:20:46.660] Build status: SCHEDULED
[17:20:46.660] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:29:0) after 9m0s
[17:29:46.682] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:29:0)
[17:29:46.725] Build status: SCHEDULED
[17:29:46.726] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:30:0) after 7m21s
[17:37:07.751] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:30:0)
[17:37:07.789] Build status: SCHEDULED
[17:37:07.789] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:31:0) after 1m6s
[17:38:13.808] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:31:0)
[17:38:13.836] Build status: SCHEDULED
[17:38:13.836] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:32:0) after 6m17s
[17:44:30.854] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:32:0)
[17:44:30.894] Build status: SCHEDULED
[17:44:30.894] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:33:0) after 5m1s
[17:49:32.114] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:33:0)
[17:49:32.142] Build status: SCHEDULED
[17:49:32.142] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:34:0) after 9m40s
[17:51:12.494] Received PubSub notification, asking Buildbucket for the build status
[17:51:12.531] Build status: STARTED
[17:59:12.159] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:34:0)
[17:59:12.226] Build status: STARTED
[17:59:12.226] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:36:0) after 3m40s
[18:02:52.245] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:36:0)
[18:02:52.279] Build status: STARTED
[18:02:52.279] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:37:0) after 3m50s
[18:06:42.298] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:37:0)
[18:06:42.344] Build status: STARTED
[18:06:42.344] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:38:0) after 1m43s
[18:08:25.724] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:38:0)
[18:08:25.756] Build status: STARTED
[18:08:25.756] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:39:0) after 7m44s
[18:16:09.779] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:39:0)
[18:16:09.813] Build status: STARTED
[18:16:09.813] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:40:0) after 7m32s
[18:23:42.022] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:40:0)
[18:23:42.057] Build status: STARTED
[18:23:42.057] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:41:0) after 3m45s
[18:27:27.120] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:41:0)
[18:27:27.150] Build status: STARTED
[18:27:27.150] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:42:0) after 6m45s
[18:34:12.170] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:42:0)
[18:34:12.200] Build status: STARTED
[18:34:12.200] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:43:0) after 5m6s
[18:39:18.319] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:43:0)
[18:39:18.361] Build status: STARTED
[18:39:18.362] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:44:0) after 4m25s
[18:43:43.391] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:44:0)
[18:43:43.419] Build status: STARTED
[18:43:43.419] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:45:0) after 9m24s
[18:53:07.630] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:45:0)
[18:53:07.673] Build status: STARTED
[18:53:07.673] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:46:0) after 1m12s
[18:54:19.918] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:46:0)
[18:54:19.975] Build status: STARTED
[18:54:19.975] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:47:0) after 6m30s
[19:00:50.261] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:47:0)
[19:00:50.326] Build status: STARTED
[19:00:50.326] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:48:0) after 3m9s
[19:03:59.735] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:48:0)
[19:03:59.769] Build status: STARTED
[19:03:59.769] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:49:0) after 7m10s
[19:11:09.996] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:49:0)
[19:11:10.073] Build status: STARTED
[19:11:10.073] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:50:0) after 2m56s
[19:14:06.118] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:50:0)
[19:14:06.155] Build status: STARTED
[19:14:06.155] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:51:0) after 2m9s
[19:16:15.416] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:51:0)
[19:16:15.452] Build status: STARTED
[19:16:15.452] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:52:0) after 6m10s
[19:22:25.497] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:52:0)
[19:22:25.543] Build status: STARTED
[19:22:25.543] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:53:0) after 4m0s
[19:26:25.567] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:53:0)
[19:26:25.686] Build status: STARTED
[19:26:25.686] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:54:0) after 3m29s
[19:29:54.706] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:54:0)
[19:29:54.818] Build status: STARTED
[19:29:54.818] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:55:0) after 1m8s
[19:31:03.026] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:55:0)
[19:31:03.063] Build status: STARTED
[19:31:03.063] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:56:0) after 3m29s
[19:34:32.109] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:56:0)
[19:34:32.145] Build status: STARTED
[19:34:32.145] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:57:0) after 7m29s
[19:42:01.165] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:57:0)
[19:42:01.195] Build status: STARTED
[19:42:01.195] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:58:0) after 3m7s
[19:45:08.212] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:58:0)
[19:45:08.273] Build status: STARTED
[19:45:08.273] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:59:0) after 8m2s
[19:53:10.292] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:59:0)
[19:53:10.341] Build status: STARTED
[19:53:10.341] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:60:0) after 5m45s
[19:58:55.487] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:60:0)
[19:58:55.523] Build status: STARTED
[19:58:55.523] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:61:0) after 6m26s
[20:05:21.544] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:61:0)
[20:05:21.592] Build status: STARTED
[20:05:21.592] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:62:0) after 4m38s
[20:09:59.827] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:62:0)
[20:09:59.864] Build status: STARTED
[20:09:59.864] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:63:0) after 7m40s
[20:17:39.898] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:63:0)
[20:17:39.926] Build status: STARTED
[20:17:39.926] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:64:0) after 9m39s
[20:27:19.213] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:64:0)
[20:27:19.262] Build status: STARTED
[20:27:19.262] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:65:0) after 1m21s
[20:28:40.270] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:65:0)
[20:28:40.304] Build status: STARTED
[20:28:40.304] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:66:0) after 6m30s
[20:35:10.327] Handling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:66:0)
[20:35:10.360] Build status: STARTED
[20:35:10.360] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk11:9001082295922379456:67:0) after 7m30s
[20:40:44.358] Received PubSub notification, asking Buildbucket for the build status
[20:40:44.388] Build:
{
"id": "8835652233936573649",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk11"
},
"number": 503,
"createdBy": "project:r8",
"createTime": "2021-09-19T14:40:18.005967619Z",
"startTime": "2021-09-19T17:50:43.992773Z",
"endTime": "2021-09-19T20:40:43.502418Z",
"updateTime": "2021-09-19T20:40:43.795142Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "f3421b579a32dd06270d81c6880682dba6193781",
"ref": "refs/heads/main"
}
},
"canary": true
}
[20:40:44.388] Invocation finished in 6h0m27.661306384s with status SUCCEEDED