[11:48:03.110] New invocation is queued and will start shortly
[11:48:04.479] Starting the invocation (attempt 1)
[11:48:04.502] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/8ebdcf37652f6a34a282ed6a86d8f90d2dd27525"
[11:48:04.502] Popped gitiles commit info from properties and tags
[11:48:04.502] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[11:48:04.502] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[11:48:04.502] Buildbucket request:
{
  "requestId": "8866194248544456752",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-13"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8866194248544456752",
            "job": "r8/linux-android-13",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "8ebdcf37652f6a34a282ed6a86d8f90d2dd27525"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/main@8ebdcf37652f6a34a282ed6a86d8f90d2dd27525",
                        "title": "8ebdcf37652f6a34a282ed6a86d8f90d2dd27525",
                        "url": "https://r8.googlesource.com/r8/+/8ebdcf37652f6a34a282ed6a86d8f90d2dd27525"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "r8.googlesource.com",
    "project": "r8",
    "id": "8ebdcf37652f6a34a282ed6a86d8f90d2dd27525",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8866194248544456752"
    },
    {
      "key": "scheduler_job_id",
      "value": "r8/linux-android-13"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[11:48:05.021] Scheduled build:
{
  "id": "8700764186276990225",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-13"
  },
  "number": 1084,
  "createdBy": "project:r8",
  "createTime": "2025-10-17T11:48:04.648503184Z",
  "updateTime": "2025-10-17T11:48:04.648503184Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "8ebdcf37652f6a34a282ed6a86d8f90d2dd27525",
      "ref": "refs/heads/main"
    }
  },
  "canary": true
}
[11:48:05.021] Task URL: https://cr-buildbucket.appspot.com/build/8700764186276990225
[11:48:05.021] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:2:0) after 1m53s
[11:48:06.012] Received PubSub notification, asking Buildbucket for the build status
[11:48:06.039] Build status: SCHEDULED
[11:49:57.998] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:2:0)
[11:49:58.041] Build status: SCHEDULED
[11:49:58.041] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:4:0) after 2m51s
[11:52:49.084] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:4:0)
[11:52:49.109] Build status: SCHEDULED
[11:52:49.109] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:5:0) after 7m58s
[12:00:47.126] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:5:0)
[12:00:47.149] Build status: SCHEDULED
[12:00:47.149] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:6:0) after 2m11s
[12:02:58.379] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:6:0)
[12:02:58.401] Build status: SCHEDULED
[12:02:58.401] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:7:0) after 3m3s
[12:06:01.398] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:7:0)
[12:06:01.445] Build status: SCHEDULED
[12:06:01.445] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:8:0) after 9m26s
[12:15:27.458] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:8:0)
[12:15:27.475] Build status: SCHEDULED
[12:15:27.475] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:9:0) after 1m22s
[12:16:49.504] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:9:0)
[12:16:49.591] Build status: SCHEDULED
[12:16:49.591] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:10:0) after 1m50s
[12:18:39.603] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:10:0)
[12:18:39.637] Build status: SCHEDULED
[12:18:39.637] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:11:0) after 4m3s
[12:22:42.656] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:11:0)
[12:22:42.673] Build status: SCHEDULED
[12:22:42.673] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:12:0) after 6m35s
[12:29:18.126] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:12:0)
[12:29:18.144] Build status: SCHEDULED
[12:29:18.144] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:13:0) after 1m55s
[12:31:13.250] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:13:0)
[12:31:13.287] Build status: SCHEDULED
[12:31:13.287] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:14:0) after 3m11s
[12:34:24.540] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:14:0)
[12:34:24.565] Build status: SCHEDULED
[12:34:24.565] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:15:0) after 3m31s
[12:37:55.743] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:15:0)
[12:37:55.758] Build status: SCHEDULED
[12:37:55.758] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:16:0) after 4m16s
[12:42:12.041] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:16:0)
[12:42:12.061] Build status: SCHEDULED
[12:42:12.061] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:17:0) after 8m35s
[12:50:47.287] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:17:0)
[12:50:47.304] Build status: SCHEDULED
[12:50:47.304] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:18:0) after 8m33s
[12:59:20.622] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:18:0)
[12:59:20.826] Build status: SCHEDULED
[12:59:20.826] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:19:0) after 5m17s
[13:04:37.844] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:19:0)
[13:04:37.861] Build status: SCHEDULED
[13:04:37.861] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:20:0) after 4m58s
[13:09:35.879] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:20:0)
[13:09:35.896] Build status: SCHEDULED
[13:09:35.897] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:21:0) after 2m44s
[13:12:19.872] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:21:0)
[13:12:19.889] Build status: SCHEDULED
[13:12:19.890] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:22:0) after 2m33s
[13:14:52.900] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:22:0)
[13:14:52.932] Build status: SCHEDULED
[13:14:52.932] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:23:0) after 8m8s
[13:23:01.018] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:23:0)
[13:23:01.042] Build status: SCHEDULED
[13:23:01.042] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:24:0) after 9m13s
[13:32:14.103] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:24:0)
[13:32:14.121] Build status: SCHEDULED
[13:32:14.121] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:25:0) after 7m29s
[13:38:37.836] Received PubSub notification, asking Buildbucket for the build status
[13:38:37.860] Build status: STARTED
[13:39:43.099] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:25:0)
[13:39:43.122] Build status: STARTED
[13:39:43.122] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:27:0) after 3m4s
[13:42:47.192] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:27:0)
[13:42:47.209] Build status: STARTED
[13:42:47.209] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:28:0) after 8m29s
[13:51:16.237] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:28:0)
[13:51:16.259] Build status: STARTED
[13:51:16.259] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:29:0) after 7m37s
[13:58:53.747] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:29:0)
[13:58:53.763] Build status: STARTED
[13:58:53.763] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:30:0) after 9m26s
[14:08:19.784] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:30:0)
[14:08:19.799] Build status: STARTED
[14:08:19.799] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:31:0) after 4m39s
[14:12:58.813] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:31:0)
[14:12:58.828] Build status: STARTED
[14:12:58.828] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:32:0) after 1m47s
[14:14:45.884] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:32:0)
[14:14:45.970] Build status: STARTED
[14:14:45.970] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:33:0) after 8m46s
[14:23:31.988] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:33:0)
[14:23:32.007] Build status: STARTED
[14:23:32.007] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:34:0) after 5m20s
[14:28:52.065] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:34:0)
[14:28:52.092] Build status: STARTED
[14:28:52.092] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:35:0) after 8m50s
[14:37:42.087] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:35:0)
[14:37:42.106] Build status: STARTED
[14:37:42.106] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:36:0) after 5m50s
[14:43:32.144] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:36:0)
[14:43:32.163] Build status: STARTED
[14:43:32.163] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:37:0) after 2m58s
[14:46:30.176] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:37:0)
[14:46:30.224] Build status: STARTED
[14:46:30.225] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:38:0) after 1m38s
[14:48:08.292] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:38:0)
[14:48:08.311] Build status: STARTED
[14:48:08.311] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:39:0) after 2m6s
[14:50:14.399] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:39:0)
[14:50:14.421] Build status: STARTED
[14:50:14.421] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:40:0) after 4m27s
[14:54:41.485] Handling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:40:0)
[14:54:41.567] Build status: STARTED
[14:54:41.567] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-13:8866194248544456752:41:0) after 6m22s
[14:55:34.961] Received PubSub notification, asking Buildbucket for the build status
[14:55:34.977] Build:
{
  "id": "8700764186276990225",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-13"
  },
  "number": 1084,
  "createdBy": "project:r8",
  "createTime": "2025-10-17T11:48:04.648503184Z",
  "startTime": "2025-10-17T13:38:37.443217364Z",
  "endTime": "2025-10-17T14:55:34.763419581Z",
  "updateTime": "2025-10-17T14:55:34.763419581Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "8ebdcf37652f6a34a282ed6a86d8f90d2dd27525",
      "ref": "refs/heads/main"
    }
  },
  "canary": true
}
[14:55:34.977] Invocation finished in 3h7m31.874764387s with status SUCCEEDED