[15:01:56.145] New invocation is queued and will start shortly
[15:01:57.226] Starting the invocation (attempt 1)
[15:01:57.255] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/e79188ca442a13600faa505c18d94369df3b956f"
[15:01:57.255] Popped gitiles commit info from properties and tags
[15:01:57.255] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[15:01:57.256] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[15:01:57.256] Buildbucket request:
{
  "requestId": "8865276080766771712",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-9"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8865276080766771712",
            "job": "r8/linux-android-9",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "b25dff16a91da033abfcf04d0f47e8f734341d34"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/main@b25dff16a91da033abfcf04d0f47e8f734341d34",
                        "title": "b25dff16a91da033abfcf04d0f47e8f734341d34",
                        "url": "https://r8.googlesource.com/r8/+/b25dff16a91da033abfcf04d0f47e8f734341d34"
                      },
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "e79188ca442a13600faa505c18d94369df3b956f"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/main@e79188ca442a13600faa505c18d94369df3b956f",
                        "title": "e79188ca442a13600faa505c18d94369df3b956f",
                        "url": "https://r8.googlesource.com/r8/+/e79188ca442a13600faa505c18d94369df3b956f"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "r8.googlesource.com",
    "project": "r8",
    "id": "e79188ca442a13600faa505c18d94369df3b956f",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8865276080766771712"
    },
    {
      "key": "scheduler_job_id",
      "value": "r8/linux-android-9"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[15:01:57.746] Scheduled build:
{
  "id": "8699846018891922033",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-9"
  },
  "number": 1115,
  "createdBy": "project:r8",
  "createTime": "2025-10-27T15:01:57.301023440Z",
  "updateTime": "2025-10-27T15:01:57.301023440Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "e79188ca442a13600faa505c18d94369df3b956f",
      "ref": "refs/heads/main"
    }
  }
}
[15:01:57.746] Task URL: https://cr-buildbucket.appspot.com/build/8699846018891922033
[15:01:57.746] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:2:0) after 4m19s
[15:01:57.878] Received PubSub notification, asking Buildbucket for the build status
[15:01:57.898] Build status: SCHEDULED
[15:06:16.767] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:2:0)
[15:06:16.856] Build status: SCHEDULED
[15:06:16.856] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:4:0) after 7m25s
[15:13:41.928] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:4:0)
[15:13:41.958] Build status: SCHEDULED
[15:13:41.958] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:5:0) after 4m54s
[15:18:35.968] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:5:0)
[15:18:35.991] Build status: SCHEDULED
[15:18:35.991] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:6:0) after 4m14s
[15:22:50.036] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:6:0)
[15:22:50.113] Build status: SCHEDULED
[15:22:50.113] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:7:0) after 2m57s
[15:25:47.147] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:7:0)
[15:25:47.207] Build status: SCHEDULED
[15:25:47.207] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:8:0) after 9m45s
[15:35:32.229] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:8:0)
[15:35:32.247] Build status: SCHEDULED
[15:35:32.247] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:9:0) after 9m20s
[15:44:52.213] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:9:0)
[15:44:52.284] Build status: SCHEDULED
[15:44:52.284] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:10:0) after 3m18s
[15:48:10.302] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:10:0)
[15:48:10.320] Build status: SCHEDULED
[15:48:10.320] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:11:0) after 2m13s
[15:50:23.339] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:11:0)
[15:50:23.362] Build status: SCHEDULED
[15:50:23.362] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:12:0) after 3m30s
[15:53:53.336] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:12:0)
[15:53:53.356] Build status: SCHEDULED
[15:53:53.356] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:13:0) after 2m13s
[15:56:06.405] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:13:0)
[15:56:06.432] Build status: SCHEDULED
[15:56:06.432] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:14:0) after 2m42s
[15:58:48.498] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:14:0)
[15:58:48.514] Build status: SCHEDULED
[15:58:48.515] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:15:0) after 2m54s
[15:59:16.145] Received PubSub notification, asking Buildbucket for the build status
[15:59:16.166] Build status: STARTED
[16:01:42.563] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:15:0)
[16:01:42.577] Build status: STARTED
[16:01:42.577] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:17:0) after 6m45s
[16:08:27.721] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:17:0)
[16:08:27.737] Build status: STARTED
[16:08:27.737] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:18:0) after 8m58s
[16:17:25.749] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:18:0)
[16:17:25.764] Build status: STARTED
[16:17:25.764] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:19:0) after 1m59s
[16:19:24.847] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:19:0)
[16:19:24.900] Build status: STARTED
[16:19:24.900] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:20:0) after 8m30s
[16:27:55.006] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:20:0)
[16:27:55.026] Build status: STARTED
[16:27:55.026] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:21:0) after 7m10s
[16:35:05.044] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:21:0)
[16:35:05.062] Build status: STARTED
[16:35:05.062] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:22:0) after 2m32s
[16:37:37.179] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:22:0)
[16:37:37.200] Build status: STARTED
[16:37:37.200] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:23:0) after 1m6s
[16:38:43.213] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:23:0)
[16:38:43.229] Build status: STARTED
[16:38:43.229] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:24:0) after 1m58s
[16:40:41.243] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:24:0)
[16:40:41.320] Build status: STARTED
[16:40:41.320] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:25:0) after 9m0s
[16:49:41.342] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:25:0)
[16:49:41.361] Build status: STARTED
[16:49:41.362] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:26:0) after 4m17s
[16:53:58.339] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:26:0)
[16:53:58.364] Build status: STARTED
[16:53:58.364] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:27:0) after 1m13s
[16:55:11.432] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:27:0)
[16:55:11.479] Build status: STARTED
[16:55:11.479] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:28:0) after 3m10s
[16:58:21.494] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:28:0)
[16:58:21.511] Build status: STARTED
[16:58:21.511] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:29:0) after 1m55s
[17:00:16.562] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:29:0)
[17:00:16.617] Build status: STARTED
[17:00:16.617] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:30:0) after 3m55s
[17:04:11.682] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:30:0)
[17:04:11.701] Build status: STARTED
[17:04:11.701] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:31:0) after 2m54s
[17:07:05.796] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:31:0)
[17:07:05.842] Build status: STARTED
[17:07:05.842] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:32:0) after 6m55s
[17:14:00.933] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:32:0)
[17:14:00.954] Build status: STARTED
[17:14:00.954] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:33:0) after 6m55s
[17:20:55.971] Handling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:33:0)
[17:20:56.005] Build status: STARTED
[17:20:56.005] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-9:8865276080766771712:34:0) after 3m57s
[17:20:59.554] Received PubSub notification, asking Buildbucket for the build status
[17:20:59.594] Build:
{
  "id": "8699846018891922033",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-9"
  },
  "number": 1115,
  "createdBy": "project:r8",
  "createTime": "2025-10-27T15:01:57.301023440Z",
  "startTime": "2025-10-27T15:59:15.945461147Z",
  "endTime": "2025-10-27T17:20:59.199109284Z",
  "updateTime": "2025-10-27T17:20:59.199109284Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "e79188ca442a13600faa505c18d94369df3b956f",
      "ref": "refs/heads/main"
    }
  }
}
[17:20:59.594] Invocation finished in 2h19m3.463500936s with status SUCCEEDED