[07:31:56.504] New invocation is queued and will start shortly
[07:31:57.662] Starting the invocation (attempt 1)
[07:31:57.686] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66"
[07:31:57.686] Popped gitiles commit info from properties and tags
[07:31:57.686] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[07:31:57.687] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[07:31:57.688] Buildbucket request:
{
  "requestId": "8865304391931047184",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-12_release"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8865304391931047184",
            "job": "r8/linux-android-12_release",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/9.0",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/9.0@d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66",
                        "title": "d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66",
                        "url": "https://r8.googlesource.com/r8/+/d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "r8.googlesource.com",
    "project": "r8",
    "id": "d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66",
    "ref": "refs/heads/9.0"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8865304391931047184"
    },
    {
      "key": "scheduler_job_id",
      "value": "r8/linux-android-12_release"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[07:31:58.081] Scheduled build:
{
  "id": "8699874329986540705",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-12_release"
  },
  "number": 374,
  "createdBy": "project:r8",
  "createTime": "2025-10-27T07:31:57.737168481Z",
  "updateTime": "2025-10-27T07:31:57.737168481Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66",
      "ref": "refs/heads/9.0"
    }
  }
}
[07:31:58.081] Task URL: https://cr-buildbucket.appspot.com/build/8699874329986540705
[07:31:58.081] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:2:0) after 9m11s
[07:32:13.598] Received PubSub notification, asking Buildbucket for the build status
[07:32:13.621] Build status: SCHEDULED
[07:41:09.555] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:2:0)
[07:41:09.589] Build status: SCHEDULED
[07:41:09.589] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:4:0) after 7m56s
[07:49:05.640] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:4:0)
[07:49:05.657] Build status: SCHEDULED
[07:49:05.657] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:5:0) after 7m28s
[07:56:33.925] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:5:0)
[07:56:33.944] Build status: SCHEDULED
[07:56:33.944] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:6:0) after 5m55s
[08:02:28.957] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:6:0)
[08:02:28.978] Build status: SCHEDULED
[08:02:28.978] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:7:0) after 9m11s
[08:11:39.992] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:7:0)
[08:11:40.028] Build status: SCHEDULED
[08:11:40.028] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:8:0) after 6m18s
[08:17:58.043] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:8:0)
[08:17:58.059] Build status: SCHEDULED
[08:17:58.059] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:9:0) after 1m14s
[08:19:12.101] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:9:0)
[08:19:12.191] Build status: SCHEDULED
[08:19:12.191] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:10:0) after 8m50s
[08:28:02.303] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:10:0)
[08:28:02.318] Build status: SCHEDULED
[08:28:02.318] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:11:0) after 3m18s
[08:31:20.334] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:11:0)
[08:31:20.351] Build status: SCHEDULED
[08:31:20.352] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:12:0) after 7m42s
[08:39:02.474] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:12:0)
[08:39:02.509] Build status: SCHEDULED
[08:39:02.509] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:13:0) after 8m40s
[08:47:42.499] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:13:0)
[08:47:42.515] Build status: SCHEDULED
[08:47:42.515] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:14:0) after 1m1s
[08:48:43.525] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:14:0)
[08:48:43.539] Build status: SCHEDULED
[08:48:43.539] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:15:0) after 3m10s
[08:51:53.608] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:15:0)
[08:51:53.632] Build status: SCHEDULED
[08:51:53.632] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:16:0) after 1m8s
[08:53:01.661] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:16:0)
[08:53:01.680] Build status: SCHEDULED
[08:53:01.680] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:17:0) after 9m33s
[09:02:34.741] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:17:0)
[09:02:34.802] Build status: SCHEDULED
[09:02:34.803] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:18:0) after 8m8s
[09:10:42.986] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:18:0)
[09:10:43.007] Build status: SCHEDULED
[09:10:43.007] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:19:0) after 8m50s
[09:19:33.396] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:19:0)
[09:19:33.419] Build status: SCHEDULED
[09:19:33.419] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:20:0) after 5m56s
[09:25:29.530] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:20:0)
[09:25:29.545] Build status: SCHEDULED
[09:25:29.545] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:21:0) after 2m50s
[09:28:19.557] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:21:0)
[09:28:19.615] Build status: SCHEDULED
[09:28:19.615] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:22:0) after 6m49s
[09:31:13.466] Received PubSub notification, asking Buildbucket for the build status
[09:31:13.484] Build status: STARTED
[09:35:08.771] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:22:0)
[09:35:08.790] Build status: STARTED
[09:35:08.790] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:24:0) after 8m28s
[09:43:37.536] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:24:0)
[09:43:37.557] Build status: STARTED
[09:43:37.557] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:25:0) after 1m56s
[09:45:33.620] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:25:0)
[09:45:33.636] Build status: STARTED
[09:45:33.636] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:26:0) after 6m44s
[09:52:17.654] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:26:0)
[09:52:17.703] Build status: STARTED
[09:52:17.703] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:27:0) after 6m18s
[09:58:36.239] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:27:0)
[09:58:36.259] Build status: STARTED
[09:58:36.259] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:28:0) after 7m7s
[10:05:43.343] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:28:0)
[10:05:43.357] Build status: STARTED
[10:05:43.357] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:29:0) after 8m5s
[10:13:48.369] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:29:0)
[10:13:48.406] Build status: STARTED
[10:13:48.406] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:30:0) after 3m53s
[10:17:41.421] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:30:0)
[10:17:41.436] Build status: STARTED
[10:17:41.436] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:31:0) after 5m50s
[10:23:31.553] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:31:0)
[10:23:31.571] Build status: STARTED
[10:23:31.571] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:32:0) after 6m38s
[10:30:09.586] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:32:0)
[10:30:09.602] Build status: STARTED
[10:30:09.602] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:33:0) after 1m58s
[10:32:07.614] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:33:0)
[10:32:07.699] Build status: STARTED
[10:32:07.699] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:34:0) after 6m52s
[10:38:59.759] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:34:0)
[10:38:59.780] Build status: STARTED
[10:38:59.780] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:35:0) after 6m10s
[10:45:09.764] Handling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:35:0)
[10:45:09.781] Build status: STARTED
[10:45:09.781] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-12_release:8865304391931047184:36:0) after 4m47s
[10:49:03.971] Received PubSub notification, asking Buildbucket for the build status
[10:49:03.985] Build:
{
  "id": "8699874329986540705",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-12_release"
  },
  "number": 374,
  "createdBy": "project:r8",
  "createTime": "2025-10-27T07:31:57.737168481Z",
  "startTime": "2025-10-27T09:31:13.313883640Z",
  "endTime": "2025-10-27T10:49:03.813949944Z",
  "updateTime": "2025-10-27T10:49:03.813949944Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "d979d76b8debaa19dba3d5f30bcc2d9bd5e01d66",
      "ref": "refs/heads/9.0"
    }
  }
}
[10:49:03.985] Invocation finished in 3h17m7.485910687s with status SUCCEEDED