[10:16:23.406] New invocation is queued and will start shortly
[10:16:27.398] Starting the invocation (attempt 1)
[10:16:27.462] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/eb757cd0a3a5345fb94c87aa8c45149f40b873c5"
[10:16:27.462] Popped gitiles commit info from properties and tags
[10:16:27.462] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[10:16:27.463] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[10:16:27.464] Buildbucket request:
{
"requestId": "8972107869140937728",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk8"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8972107869140937728",
"job": "r8/linux-jdk8",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "28a032118e05a3f0c6f9b1ecab3a64583aadbfb4"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@28a032118e05a3f0c6f9b1ecab3a64583aadbfb4",
"title": "28a032118e05a3f0c6f9b1ecab3a64583aadbfb4",
"url": "https://r8.googlesource.com/r8/+/28a032118e05a3f0c6f9b1ecab3a64583aadbfb4"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "eb757cd0a3a5345fb94c87aa8c45149f40b873c5"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@eb757cd0a3a5345fb94c87aa8c45149f40b873c5",
"title": "eb757cd0a3a5345fb94c87aa8c45149f40b873c5",
"url": "https://r8.googlesource.com/r8/+/eb757cd0a3a5345fb94c87aa8c45149f40b873c5"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "eb757cd0a3a5345fb94c87aa8c45149f40b873c5",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8972107869140937728"
},
{
"key": "scheduler_job_id",
"value": "r8/linux-jdk8"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[10:16:28.232] Scheduled build:
{
"id": "8806677804115429345",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk8"
},
"number": 2631,
"createdBy": "project:r8",
"createTime": "2022-08-05T10:16:27.558663320Z",
"updateTime": "2022-08-05T10:16:27.558663320Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "eb757cd0a3a5345fb94c87aa8c45149f40b873c5",
"ref": "refs/heads/main"
}
}
}
[10:16:28.232] Task URL: https://cr-buildbucket.appspot.com/build/8806677804115429345
[10:16:28.232] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:2:0) after 9m37s
[10:26:05.306] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:2:0)
[10:26:05.402] Build status: SCHEDULED
[10:26:05.402] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:3:0) after 6m29s
[10:32:34.781] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:3:0)
[10:32:34.815] Build status: SCHEDULED
[10:32:34.815] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:4:0) after 7m32s
[10:40:07.036] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:4:0)
[10:40:07.080] Build status: SCHEDULED
[10:40:07.080] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:5:0) after 2m26s
[10:42:33.132] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:5:0)
[10:42:33.161] Build status: SCHEDULED
[10:42:33.161] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:6:0) after 2m43s
[10:45:16.282] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:6:0)
[10:45:16.312] Build status: SCHEDULED
[10:45:16.313] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:7:0) after 9m28s
[10:54:44.323] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:7:0)
[10:54:44.343] Build status: SCHEDULED
[10:54:44.343] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:8:0) after 9m17s
[11:04:01.403] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:8:0)
[11:04:01.437] Build status: SCHEDULED
[11:04:01.437] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:9:0) after 4m23s
[11:08:24.661] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:9:0)
[11:08:24.691] Build status: SCHEDULED
[11:08:24.691] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:10:0) after 3m16s
[11:11:40.903] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:10:0)
[11:11:40.933] Build status: SCHEDULED
[11:11:40.933] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:11:0) after 6m50s
[11:18:31.107] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:11:0)
[11:18:31.132] Build status: SCHEDULED
[11:18:31.132] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:12:0) after 1m9s
[11:19:40.214] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:12:0)
[11:19:40.254] Build status: SCHEDULED
[11:19:40.254] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:13:0) after 7m9s
[11:26:49.339] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:13:0)
[11:26:49.374] Build status: SCHEDULED
[11:26:49.375] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:14:0) after 9m13s
[11:36:02.505] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:14:0)
[11:36:02.550] Build status: SCHEDULED
[11:36:02.550] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:15:0) after 3m58s
[11:40:00.700] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:15:0)
[11:40:00.733] Build status: SCHEDULED
[11:40:00.733] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:16:0) after 9m27s
[11:49:27.751] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:16:0)
[11:49:27.784] Build status: SCHEDULED
[11:49:27.784] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:17:0) after 9m44s
[11:59:11.801] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:17:0)
[11:59:11.855] Build status: SCHEDULED
[11:59:11.855] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:18:0) after 1m36s
[12:00:47.884] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:18:0)
[12:00:47.988] Build status: SCHEDULED
[12:00:47.988] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:19:0) after 3m37s
[12:04:24.972] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:19:0)
[12:04:25.086] Build status: SCHEDULED
[12:04:25.086] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:20:0) after 3m43s
[12:08:08.105] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:20:0)
[12:08:08.138] Build status: SCHEDULED
[12:08:08.138] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:21:0) after 5m31s
[12:13:39.156] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:21:0)
[12:13:39.188] Build status: SCHEDULED
[12:13:39.189] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:22:0) after 1m52s
[12:15:31.293] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:22:0)
[12:15:31.327] Build status: SCHEDULED
[12:15:31.327] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:23:0) after 6m38s
[12:22:09.344] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:23:0)
[12:22:09.379] Build status: SCHEDULED
[12:22:09.379] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:24:0) after 9m9s
[12:30:55.311] Received PubSub notification, asking Buildbucket for the build status
[12:30:55.347] Build status: STARTED
[12:31:18.608] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:24:0)
[12:31:18.638] Build status: STARTED
[12:31:18.638] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:26:0) after 3m0s
[12:34:18.790] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:26:0)
[12:34:18.821] Build status: STARTED
[12:34:18.821] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:27:0) after 6m27s
[12:40:46.027] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:27:0)
[12:40:46.076] Build status: STARTED
[12:40:46.076] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:28:0) after 6m22s
[12:47:08.305] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:28:0)
[12:47:08.335] Build status: STARTED
[12:47:08.335] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:29:0) after 2m40s
[12:49:48.383] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:29:0)
[12:49:48.413] Build status: STARTED
[12:49:48.413] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:30:0) after 6m41s
[12:56:29.466] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:30:0)
[12:56:29.546] Build status: STARTED
[12:56:29.546] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:31:0) after 9m35s
[13:06:04.565] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:31:0)
[13:06:04.604] Build status: STARTED
[13:06:04.604] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:32:0) after 1m16s
[13:07:20.715] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:32:0)
[13:07:20.746] Build status: STARTED
[13:07:20.746] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:33:0) after 3m52s
[13:11:12.861] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:33:0)
[13:11:12.897] Build status: STARTED
[13:11:12.897] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:34:0) after 6m45s
[13:17:57.919] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:34:0)
[13:17:57.961] Build status: STARTED
[13:17:57.961] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:35:0) after 7m10s
[13:25:08.038] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:35:0)
[13:25:08.076] Build status: STARTED
[13:25:08.076] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:36:0) after 1m37s
[13:26:45.097] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:36:0)
[13:26:45.128] Build status: STARTED
[13:26:45.128] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:37:0) after 9m7s
[13:35:52.145] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:37:0)
[13:35:52.180] Build status: STARTED
[13:35:52.180] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:38:0) after 2m45s
[13:38:37.287] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:38:0)
[13:38:37.309] Build status: STARTED
[13:38:37.309] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:39:0) after 9m38s
[13:48:15.646] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:39:0)
[13:48:15.677] Build status: STARTED
[13:48:15.677] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:40:0) after 7m18s
[13:55:33.961] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:40:0)
[13:55:33.982] Build status: STARTED
[13:55:33.982] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:41:0) after 4m48s
[14:00:22.002] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:41:0)
[14:00:22.044] Build status: STARTED
[14:00:22.045] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:42:0) after 7m38s
[14:08:00.158] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:42:0)
[14:08:00.251] Build status: STARTED
[14:08:00.251] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:43:0) after 5m56s
[14:13:56.328] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:43:0)
[14:13:56.359] Build status: STARTED
[14:13:56.359] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:44:0) after 6m35s
[14:20:31.379] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:44:0)
[14:20:31.411] Build status: STARTED
[14:20:31.411] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:45:0) after 3m50s
[14:24:21.595] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:45:0)
[14:24:21.627] Build status: STARTED
[14:24:21.627] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:46:0) after 2m41s
[14:27:02.818] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:46:0)
[14:27:02.852] Build status: STARTED
[14:27:02.852] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:47:0) after 5m21s
[14:32:24.120] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:47:0)
[14:32:24.147] Build status: STARTED
[14:32:24.147] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:48:0) after 6m38s
[14:39:02.367] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:48:0)
[14:39:02.397] Build status: STARTED
[14:39:02.397] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8972107869140937728:49:0) after 4m45s
[14:39:28.472] Received PubSub notification, asking Buildbucket for the build status
[14:39:28.501] Build:
{
"id": "8806677804115429345",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk8"
},
"number": 2631,
"createdBy": "project:r8",
"createTime": "2022-08-05T10:16:27.558663320Z",
"startTime": "2022-08-05T12:30:53.856136Z",
"endTime": "2022-08-05T14:39:28.208832533Z",
"updateTime": "2022-08-05T14:39:28.208832533Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "eb757cd0a3a5345fb94c87aa8c45149f40b873c5",
"ref": "refs/heads/main"
}
}
}
[14:39:28.501] Invocation finished in 4h23m5.120670188s with status SUCCEEDED