[05:16:26.103] New invocation is queued and will start shortly
[05:16:27.224] Starting the invocation (attempt 1)
[05:16:27.256] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/aa17965b9f0ceeaf0d7644af1647b282819aadd4"
[05:16:27.256] Popped gitiles commit info from properties and tags
[05:16:27.256] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[05:16:27.257] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[05:16:27.258] Buildbucket request:
{
"requestId": "9014707314879214416",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-run-on-app-dump"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "80d5e48467c2ee94d4ec8d75b096b0dc55770b09"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@80d5e48467c2ee94d4ec8d75b096b0dc55770b09",
"title": "80d5e48467c2ee94d4ec8d75b096b0dc55770b09",
"url": "https://r8.googlesource.com/r8/+/80d5e48467c2ee94d4ec8d75b096b0dc55770b09"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://r8.googlesource.com/r8",
"revision": "aa17965b9f0ceeaf0d7644af1647b282819aadd4"
},
"id": "https://r8.googlesource.com/r8/+/refs/heads/main@aa17965b9f0ceeaf0d7644af1647b282819aadd4",
"title": "aa17965b9f0ceeaf0d7644af1647b282819aadd4",
"url": "https://r8.googlesource.com/r8/+/aa17965b9f0ceeaf0d7644af1647b282819aadd4"
}
]
}
},
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "aa17965b9f0ceeaf0d7644af1647b282819aadd4",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "9014707314879214416"
},
{
"key": "scheduler_job_id",
"value": "r8/linux-run-on-app-dump"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[05:16:27.769] Scheduled build:
{
"id": "8849277252908634896",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-run-on-app-dump"
},
"number": 738,
"createdBy": "project:r8",
"createTime": "2021-04-22T05:16:27.350658Z",
"updateTime": "2021-04-22T05:16:27.706816Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "aa17965b9f0ceeaf0d7644af1647b282819aadd4",
"ref": "refs/heads/main"
}
}
}
[05:16:27.769] Task URL: https://cr-buildbucket.appspot.com/build/8849277252908634896
[05:16:27.769] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:2:0) after 6m11s
[05:21:12.581] Received PubSub notification, asking Buildbucket for the build status
[05:21:12.613] Build status: STARTED
[05:22:38.746] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:2:0)
[05:22:38.770] Build status: STARTED
[05:22:38.770] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:4:0) after 2m20s
[05:24:59.197] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:4:0)
[05:24:59.227] Build status: STARTED
[05:24:59.227] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:5:0) after 2m26s
[05:27:25.318] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:5:0)
[05:27:25.354] Build status: STARTED
[05:27:25.354] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:6:0) after 5m3s
[05:32:28.385] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:6:0)
[05:32:28.447] Build status: STARTED
[05:32:28.447] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:7:0) after 1m10s
[05:33:38.511] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:7:0)
[05:33:38.539] Build status: STARTED
[05:33:38.539] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:8:0) after 4m24s
[05:38:02.555] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:8:0)
[05:38:02.610] Build status: STARTED
[05:38:02.610] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:9:0) after 4m0s
[05:42:02.721] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:9:0)
[05:42:02.749] Build status: STARTED
[05:42:02.749] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:10:0) after 3m10s
[05:45:12.893] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:10:0)
[05:45:12.920] Build status: STARTED
[05:45:12.920] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:11:0) after 3m9s
[05:48:21.978] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:11:0)
[05:48:22.003] Build status: STARTED
[05:48:22.003] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:12:0) after 6m8s
[05:54:30.097] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:12:0)
[05:54:30.133] Build status: STARTED
[05:54:30.133] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:13:0) after 9m27s
[06:03:57.466] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:13:0)
[06:03:57.496] Build status: STARTED
[06:03:57.496] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:14:0) after 1m20s
[06:05:17.579] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:14:0)
[06:05:17.611] Build status: STARTED
[06:05:17.611] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:15:0) after 2m26s
[06:07:43.628] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:15:0)
[06:07:43.663] Build status: STARTED
[06:07:43.663] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:16:0) after 1m20s
[06:09:03.718] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:16:0)
[06:09:03.751] Build status: STARTED
[06:09:03.751] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:17:0) after 4m11s
[06:13:14.766] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:17:0)
[06:13:14.823] Build status: STARTED
[06:13:14.823] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:18:0) after 2m13s
[06:15:28.181] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:18:0)
[06:15:28.209] Build status: STARTED
[06:15:28.209] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:19:0) after 4m8s
[06:19:36.512] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:19:0)
[06:19:36.544] Build status: STARTED
[06:19:36.544] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:20:0) after 6m18s
[06:25:54.723] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:20:0)
[06:25:54.747] Build status: STARTED
[06:25:54.747] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:21:0) after 3m30s
[06:29:24.733] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:21:0)
[06:29:24.760] Build status: STARTED
[06:29:24.760] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:22:0) after 7m44s
[06:37:08.776] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:22:0)
[06:37:08.803] Build status: STARTED
[06:37:08.803] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:23:0) after 3m57s
[06:41:06.190] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:23:0)
[06:41:06.232] Build status: STARTED
[06:41:06.232] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:24:0) after 7m27s
[06:48:33.279] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:24:0)
[06:48:33.307] Build status: STARTED
[06:48:33.307] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:25:0) after 3m27s
[06:52:00.333] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:25:0)
[06:52:00.367] Build status: STARTED
[06:52:00.367] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:26:0) after 3m22s
[06:55:22.384] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:26:0)
[06:55:22.412] Build status: STARTED
[06:55:22.412] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:27:0) after 7m39s
[07:03:01.501] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:27:0)
[07:03:01.528] Build status: STARTED
[07:03:01.528] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:28:0) after 5m18s
[07:08:19.550] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:28:0)
[07:08:19.593] Build status: STARTED
[07:08:19.593] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:29:0) after 1m27s
[07:09:46.609] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:29:0)
[07:09:46.711] Build status: STARTED
[07:09:46.711] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:30:0) after 5m23s
[07:15:09.741] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:30:0)
[07:15:09.771] Build status: STARTED
[07:15:09.771] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:31:0) after 5m3s
[07:20:13.029] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:31:0)
[07:20:13.055] Build status: STARTED
[07:20:13.055] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:32:0) after 8m13s
[07:28:26.148] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:32:0)
[07:28:26.178] Build status: STARTED
[07:28:26.178] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:33:0) after 6m8s
[07:34:34.349] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:33:0)
[07:34:34.395] Build status: STARTED
[07:34:34.395] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:34:0) after 4m11s
[07:38:45.403] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:34:0)
[07:38:45.432] Build status: STARTED
[07:38:45.432] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:35:0) after 1m31s
[07:40:16.506] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:35:0)
[07:40:16.538] Build status: STARTED
[07:40:16.538] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:36:0) after 9m0s
[07:49:16.599] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:36:0)
[07:49:16.633] Build status: STARTED
[07:49:16.633] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:37:0) after 9m58s
[07:59:14.675] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:37:0)
[07:59:14.705] Build status: STARTED
[07:59:14.705] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:38:0) after 2m6s
[08:01:20.811] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:38:0)
[08:01:20.852] Build status: STARTED
[08:01:20.852] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:39:0) after 2m48s
[08:04:08.897] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:39:0)
[08:04:08.944] Build status: STARTED
[08:04:08.944] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:40:0) after 9m35s
[08:13:44.032] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:40:0)
[08:13:44.061] Build status: STARTED
[08:13:44.061] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:41:0) after 7m4s
[08:20:48.078] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:41:0)
[08:20:48.106] Build status: STARTED
[08:20:48.106] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:42:0) after 7m38s
[08:28:26.341] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:42:0)
[08:28:26.389] Build status: STARTED
[08:28:26.389] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:43:0) after 4m37s
[08:33:03.393] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:43:0)
[08:33:03.421] Build status: STARTED
[08:33:03.421] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:44:0) after 7m44s
[08:40:47.413] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:44:0)
[08:40:47.438] Build status: STARTED
[08:40:47.438] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:45:0) after 7m0s
[08:47:47.548] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:45:0)
[08:47:47.574] Build status: STARTED
[08:47:47.574] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:46:0) after 4m9s
[08:51:56.651] Handling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:46:0)
[08:51:56.680] Build status: STARTED
[08:51:56.680] Scheduling timer "check-buildbucket-build-status" (r8/linux-run-on-app-dump:9014707314879214416:47:0) after 3m34s
[08:53:22.131] Received PubSub notification, asking Buildbucket for the build status
[08:53:22.154] Build:
{
"id": "8849277252908634896",
"builder": {
"project": "r8",
"bucket": "ci",
"builder": "linux-run-on-app-dump"
},
"number": 738,
"createdBy": "project:r8",
"createTime": "2021-04-22T05:16:27.350658Z",
"startTime": "2021-04-22T05:21:12.043055Z",
"endTime": "2021-04-22T08:53:21.642954Z",
"updateTime": "2021-04-22T08:53:21.956489Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "r8.googlesource.com",
"project": "r8",
"id": "aa17965b9f0ceeaf0d7644af1647b282819aadd4",
"ref": "refs/heads/main"
}
}
}
[08:53:22.154] Invocation finished in 3h36m56.06583053s with status SUCCEEDED