[13:02:53.030] New invocation is queued and will start shortly
[13:02:54.189] Starting the invocation (attempt 1)
[13:02:54.212] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/4cc3932116d0d2f6f175305f3db02e05af7529c6"
[13:02:54.212] Popped gitiles commit info from properties and tags
[13:02:54.212] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[13:02:54.212] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[13:02:54.213] Buildbucket request:
{
  "requestId": "8864649392100509008",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-5"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8864649392100509008",
            "job": "r8/linux-android-5",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "4cc3932116d0d2f6f175305f3db02e05af7529c6"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/main@4cc3932116d0d2f6f175305f3db02e05af7529c6",
                        "title": "4cc3932116d0d2f6f175305f3db02e05af7529c6",
                        "url": "https://r8.googlesource.com/r8/+/4cc3932116d0d2f6f175305f3db02e05af7529c6"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "r8.googlesource.com",
    "project": "r8",
    "id": "4cc3932116d0d2f6f175305f3db02e05af7529c6",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8864649392100509008"
    },
    {
      "key": "scheduler_job_id",
      "value": "r8/linux-android-5"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[13:02:54.767] Scheduled build:
{
  "id": "8699219330091107361",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-5"
  },
  "number": 1072,
  "createdBy": "project:r8",
  "createTime": "2025-11-03T13:02:54.315375122Z",
  "updateTime": "2025-11-03T13:02:54.315375122Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "4cc3932116d0d2f6f175305f3db02e05af7529c6",
      "ref": "refs/heads/main"
    }
  }
}
[13:02:54.767] Task URL: https://cr-buildbucket.appspot.com/build/8699219330091107361
[13:02:54.767] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:2:0) after 4m14s
[13:02:55.079] Received PubSub notification, asking Buildbucket for the build status
[13:02:55.102] Build status: SCHEDULED
[13:07:08.853] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:2:0)
[13:07:08.888] Build status: SCHEDULED
[13:07:08.888] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:4:0) after 9m28s
[13:16:36.951] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:4:0)
[13:16:36.976] Build status: SCHEDULED
[13:16:36.976] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:5:0) after 8m57s
[13:25:33.989] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:5:0)
[13:25:34.014] Build status: SCHEDULED
[13:25:34.014] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:6:0) after 1m35s
[13:27:09.056] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:6:0)
[13:27:09.074] Build status: SCHEDULED
[13:27:09.074] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:7:0) after 3m4s
[13:30:13.222] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:7:0)
[13:30:13.257] Build status: SCHEDULED
[13:30:13.257] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:8:0) after 8m15s
[13:38:28.437] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:8:0)
[13:38:28.495] Build status: SCHEDULED
[13:38:28.495] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:9:0) after 4m20s
[13:42:48.510] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:9:0)
[13:42:48.541] Build status: SCHEDULED
[13:42:48.541] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:10:0) after 5m25s
[13:48:13.557] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:10:0)
[13:48:13.582] Build status: SCHEDULED
[13:48:13.582] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:11:0) after 6m59s
[13:55:12.658] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:11:0)
[13:55:12.673] Build status: SCHEDULED
[13:55:12.673] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:12:0) after 5m45s
[14:00:57.689] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:12:0)
[14:00:57.706] Build status: SCHEDULED
[14:00:57.706] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:13:0) after 3m26s
[14:04:24.024] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:13:0)
[14:04:24.041] Build status: SCHEDULED
[14:04:24.041] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:14:0) after 9m16s
[14:13:40.122] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:14:0)
[14:13:40.147] Build status: SCHEDULED
[14:13:40.147] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:15:0) after 4m59s
[14:18:39.193] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:15:0)
[14:18:39.213] Build status: SCHEDULED
[14:18:39.213] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:16:0) after 1m13s
[14:19:52.282] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:16:0)
[14:19:52.300] Build status: SCHEDULED
[14:19:52.300] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:17:0) after 2m24s
[14:22:16.312] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:17:0)
[14:22:16.330] Build status: SCHEDULED
[14:22:16.330] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:18:0) after 8m47s
[14:31:03.337] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:18:0)
[14:31:03.378] Build status: SCHEDULED
[14:31:03.378] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:19:0) after 3m0s
[14:34:03.393] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:19:0)
[14:34:03.409] Build status: SCHEDULED
[14:34:03.409] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:20:0) after 2m22s
[14:36:25.442] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:20:0)
[14:36:25.543] Build status: SCHEDULED
[14:36:25.543] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:21:0) after 4m42s
[14:41:07.590] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:21:0)
[14:41:07.617] Build status: SCHEDULED
[14:41:07.617] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:22:0) after 1m18s
[14:42:25.636] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:22:0)
[14:42:25.652] Build status: SCHEDULED
[14:42:25.652] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:23:0) after 5m44s
[14:48:10.113] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:23:0)
[14:48:10.143] Build status: SCHEDULED
[14:48:10.143] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:24:0) after 9m9s
[14:57:19.318] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:24:0)
[14:57:19.348] Build status: SCHEDULED
[14:57:19.349] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:25:0) after 7m5s
[14:57:29.258] Received PubSub notification, asking Buildbucket for the build status
[14:57:29.275] Build status: STARTED
[15:04:24.455] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:25:0)
[15:04:24.676] Build status: STARTED
[15:04:24.676] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:27:0) after 2m33s
[15:06:57.690] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:27:0)
[15:06:57.752] Build status: STARTED
[15:06:57.752] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:28:0) after 2m34s
[15:09:31.829] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:28:0)
[15:09:31.857] Build status: STARTED
[15:09:31.858] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:29:0) after 4m50s
[15:14:21.874] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:29:0)
[15:14:21.919] Build status: STARTED
[15:14:21.919] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:30:0) after 1m11s
[15:15:33.503] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:30:0)
[15:15:33.582] Build status: STARTED
[15:15:33.582] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:31:0) after 7m31s
[15:23:04.601] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:31:0)
[15:23:04.618] Build status: STARTED
[15:23:04.618] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:32:0) after 6m3s
[15:29:07.633] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:32:0)
[15:29:07.655] Build status: STARTED
[15:29:07.655] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:33:0) after 4m13s
[15:33:20.727] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:33:0)
[15:33:20.753] Build status: STARTED
[15:33:20.753] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:34:0) after 9m46s
[15:43:07.493] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:34:0)
[15:43:07.510] Build status: STARTED
[15:43:07.510] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:35:0) after 8m18s
[15:51:25.525] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:35:0)
[15:51:25.606] Build status: STARTED
[15:51:25.606] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:36:0) after 5m22s
[15:56:47.599] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:36:0)
[15:56:47.635] Build status: STARTED
[15:56:47.635] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:37:0) after 9m20s
[16:06:07.653] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:37:0)
[16:06:07.674] Build status: STARTED
[16:06:07.674] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:38:0) after 4m18s
[16:10:25.723] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:38:0)
[16:10:25.740] Build status: STARTED
[16:10:25.740] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:39:0) after 9m35s
[16:20:00.756] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:39:0)
[16:20:00.792] Build status: STARTED
[16:20:00.792] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:40:0) after 6m50s
[16:26:50.807] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:40:0)
[16:26:50.822] Build status: STARTED
[16:26:50.822] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:41:0) after 8m0s
[16:34:50.890] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:41:0)
[16:34:50.908] Build status: STARTED
[16:34:50.908] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:42:0) after 1m6s
[16:35:56.921] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:42:0)
[16:35:56.936] Build status: STARTED
[16:35:56.936] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:43:0) after 4m18s
[16:40:14.953] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:43:0)
[16:40:14.971] Build status: STARTED
[16:40:14.971] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:44:0) after 6m49s
[16:47:04.047] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:44:0)
[16:47:04.062] Build status: STARTED
[16:47:04.062] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:45:0) after 3m9s
[16:50:13.127] Handling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:45:0)
[16:50:13.143] Build status: STARTED
[16:50:13.143] Scheduling timer "check-buildbucket-build-status" (r8/linux-android-5:8864649392100509008:46:0) after 6m49s
[16:56:08.900] Received PubSub notification, asking Buildbucket for the build status
[16:56:09.036] Build:
{
  "id": "8699219330091107361",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-android-5"
  },
  "number": 1072,
  "createdBy": "project:r8",
  "createTime": "2025-11-03T13:02:54.315375122Z",
  "startTime": "2025-11-03T14:57:29.077664249Z",
  "endTime": "2025-11-03T16:56:08.542358225Z",
  "updateTime": "2025-11-03T16:56:08.542358225Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "4cc3932116d0d2f6f175305f3db02e05af7529c6",
      "ref": "refs/heads/main"
    }
  }
}
[16:56:09.036] Invocation finished in 3h53m16.021249495s with status SUCCEEDED