[10:46:45.740] New invocation is queued and will start shortly
[10:46:47.419] Starting the invocation (attempt 1)
[10:46:47.451] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/ef978ffab646b8d317ea38f34d86175b280d18c2"
[10:46:47.451] Popped gitiles commit info from properties and tags
[10:46:47.451] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[10:46:47.451] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[10:46:47.452] Buildbucket request:
{
"requestId": "8999103854362858032",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk8"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "ef978ffab646b8d317ea38f34d86175b280d18c2"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@ef978ffab646b8d317ea38f34d86175b280d18c2",
"title": "ef978ffab646b8d317ea38f34d86175b280d18c2",
"url": "https://r8.googlesource.com/r8/+/ef978ffab646b8d317ea38f34d86175b280d18c2"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "ef978ffab646b8d317ea38f34d86175b280d18c2",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8999103854362858032"
},
{
"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:46:47.900] Scheduled build:
{
"id": "8833673791701858145",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk8"
},
"number": 1391,
"createdBy": "project:r8",
"createTime": "2021-10-11T10:46:47.550647370Z",
"updateTime": "2021-10-11T10:46:47.743562341Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "ef978ffab646b8d317ea38f34d86175b280d18c2",
"ref": "refs/heads/main"
}
}
}
[10:46:47.900] Task URL: https://cr-buildbucket.appspot.com/build/8833673791701858145
[10:46:47.900] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:2:0) after 6m22s
[10:53:09.927] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:2:0)
[10:53:09.963] Build status: SCHEDULED
[10:53:09.964] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:3:0) after 9m3s
[11:02:12.980] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:3:0)
[11:02:13.006] Build status: SCHEDULED
[11:02:13.006] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:4:0) after 8m2s
[11:10:15.214] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:4:0)
[11:10:15.243] Build status: SCHEDULED
[11:10:15.243] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:5:0) after 7m41s
[11:17:56.258] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:5:0)
[11:17:56.281] Build status: SCHEDULED
[11:17:56.281] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:6:0) after 4m3s
[11:21:59.440] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:6:0)
[11:21:59.488] Build status: SCHEDULED
[11:21:59.488] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:7:0) after 1m21s
[11:23:20.504] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:7:0)
[11:23:20.537] Build status: SCHEDULED
[11:23:20.537] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:8:0) after 1m43s
[11:25:03.832] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:8:0)
[11:25:03.894] Build status: SCHEDULED
[11:25:03.894] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:9:0) after 4m12s
[11:29:16.111] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:9:0)
[11:29:16.148] Build status: SCHEDULED
[11:29:16.149] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:10:0) after 4m40s
[11:33:14.408] Received PubSub notification, asking Buildbucket for the build status
[11:33:14.469] Build status: STARTED
[11:33:56.265] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:10:0)
[11:33:56.462] Build status: STARTED
[11:33:56.462] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:12:0) after 2m56s
[11:36:52.477] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:12:0)
[11:36:52.523] Build status: STARTED
[11:36:52.523] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:13:0) after 5m24s
[11:42:16.684] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:13:0)
[11:42:16.957] Build status: STARTED
[11:42:16.957] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:14:0) after 5m49s
[11:48:05.971] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:14:0)
[11:48:05.998] Build status: STARTED
[11:48:05.998] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:15:0) after 9m5s
[11:57:11.016] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:15:0)
[11:57:11.072] Build status: STARTED
[11:57:11.072] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:16:0) after 3m46s
[12:00:57.196] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:16:0)
[12:00:57.261] Build status: STARTED
[12:00:57.261] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:17:0) after 9m54s
[12:10:51.282] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:17:0)
[12:10:51.395] Build status: STARTED
[12:10:51.395] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:18:0) after 2m23s
[12:13:14.481] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:18:0)
[12:13:14.506] Build status: STARTED
[12:13:14.506] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:19:0) after 3m3s
[12:16:17.610] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:19:0)
[12:16:17.668] Build status: STARTED
[12:16:17.668] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:20:0) after 3m33s
[12:19:50.683] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:20:0)
[12:19:50.717] Build status: STARTED
[12:19:50.717] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:21:0) after 7m22s
[12:27:12.866] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:21:0)
[12:27:12.926] Build status: STARTED
[12:27:12.926] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:22:0) after 1m10s
[12:28:23.215] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:22:0)
[12:28:23.245] Build status: STARTED
[12:28:23.245] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:23:0) after 3m37s
[12:32:00.278] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:23:0)
[12:32:00.323] Build status: STARTED
[12:32:00.323] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:24:0) after 8m36s
[12:40:36.302] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:24:0)
[12:40:36.334] Build status: STARTED
[12:40:36.334] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:25:0) after 9m23s
[12:49:59.348] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:25:0)
[12:49:59.390] Build status: STARTED
[12:49:59.390] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:26:0) after 1m10s
[12:51:09.508] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:26:0)
[12:51:09.551] Build status: STARTED
[12:51:09.551] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:27:0) after 4m50s
[12:55:59.570] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:27:0)
[12:55:59.597] Build status: STARTED
[12:55:59.597] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:28:0) after 2m29s
[12:58:28.616] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:28:0)
[12:58:28.649] Build status: STARTED
[12:58:28.649] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:29:0) after 7m32s
[13:06:00.666] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:29:0)
[13:06:00.748] Build status: STARTED
[13:06:00.748] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:30:0) after 1m52s
[13:07:52.879] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:30:0)
[13:07:52.913] Build status: STARTED
[13:07:52.913] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:31:0) after 7m52s
[13:15:44.918] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:31:0)
[13:15:44.945] Build status: STARTED
[13:15:44.945] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:32:0) after 3m5s
[13:18:50.024] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:32:0)
[13:18:50.078] Build status: STARTED
[13:18:50.079] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:33:0) after 9m24s
[13:28:14.110] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:33:0)
[13:28:14.163] Build status: STARTED
[13:28:14.163] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:34:0) after 6m32s
[13:34:46.208] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:34:0)
[13:34:46.267] Build status: STARTED
[13:34:46.267] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:35:0) after 2m50s
[13:37:36.360] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:35:0)
[13:37:36.410] Build status: STARTED
[13:37:36.410] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:36:0) after 1m12s
[13:38:48.631] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:36:0)
[13:38:48.689] Build status: STARTED
[13:38:48.689] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:37:0) after 7m55s
[13:46:43.807] Handling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:37:0)
[13:46:43.837] Build status: STARTED
[13:46:43.837] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk8:8999103854362858032:38:0) after 3m24s
[13:47:03.531] Received PubSub notification, asking Buildbucket for the build status
[13:47:03.559] Build:
{
"id": "8833673791701858145",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-jdk8"
},
"number": 1391,
"createdBy": "project:r8",
"createTime": "2021-10-11T10:46:47.550647370Z",
"startTime": "2021-10-11T11:33:13.658935Z",
"endTime": "2021-10-11T13:47:02.735130Z",
"updateTime": "2021-10-11T13:47:03.243569Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "ef978ffab646b8d317ea38f34d86175b280d18c2",
"ref": "refs/heads/main"
}
}
}
[13:47:03.559] Invocation finished in 3h0m17.929951122s with status SUCCEEDED