[10:06:17.029] New invocation is queued and will start shortly
[10:06:18.191] Starting the invocation (attempt 1)
[10:06:18.257] Popped buildset tag "buildset:commit/gitiles/r8.googlesource.com/r8/+/3c90b33f61f2266dee763d7ba4096c0c4c99ef1f"
[10:06:18.257] Popped gitiles commit info from properties and tags
[10:06:18.257] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[10:06:18.258] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[10:06:18.258] Buildbucket request:
{
  "requestId": "8865204084604542464",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-jdk17"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8865204084604542464",
            "job": "r8/linux-jdk17",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "c84429efe23a6d8d38aeca82591f27cb7a32ea7e"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/main@c84429efe23a6d8d38aeca82591f27cb7a32ea7e",
                        "title": "c84429efe23a6d8d38aeca82591f27cb7a32ea7e",
                        "url": "https://r8.googlesource.com/r8/+/c84429efe23a6d8d38aeca82591f27cb7a32ea7e"
                      },
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://r8.googlesource.com/r8",
                              "revision": "3c90b33f61f2266dee763d7ba4096c0c4c99ef1f"
                            },
                        "id": "https://r8.googlesource.com/r8/+/refs/heads/main@3c90b33f61f2266dee763d7ba4096c0c4c99ef1f",
                        "title": "3c90b33f61f2266dee763d7ba4096c0c4c99ef1f",
                        "url": "https://r8.googlesource.com/r8/+/3c90b33f61f2266dee763d7ba4096c0c4c99ef1f"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "r8.googlesource.com",
    "project": "r8",
    "id": "3c90b33f61f2266dee763d7ba4096c0c4c99ef1f",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8865204084604542464"
    },
    {
      "key": "scheduler_job_id",
      "value": "r8/linux-jdk17"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[10:06:19.104] Scheduled build:
{
  "id": "8699774022537828177",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-jdk17"
  },
  "number": 3935,
  "createdBy": "project:r8",
  "createTime": "2025-10-28T10:06:18.375922412Z",
  "updateTime": "2025-10-28T10:06:18.375922412Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "3c90b33f61f2266dee763d7ba4096c0c4c99ef1f",
      "ref": "refs/heads/main"
    }
  }
}
[10:06:19.104] Task URL: https://cr-buildbucket.appspot.com/build/8699774022537828177
[10:06:19.104] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:2:0) after 9m38s
[10:06:19.935] Received PubSub notification, asking Buildbucket for the build status
[10:06:20.011] Build status: SCHEDULED
[10:15:57.203] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:2:0)
[10:15:57.228] Build status: SCHEDULED
[10:15:57.228] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:4:0) after 1m11s
[10:17:08.240] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:4:0)
[10:17:08.256] Build status: SCHEDULED
[10:17:08.256] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:5:0) after 5m49s
[10:22:57.271] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:5:0)
[10:22:57.293] Build status: SCHEDULED
[10:22:57.293] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:6:0) after 4m44s
[10:27:41.326] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:6:0)
[10:27:41.351] Build status: SCHEDULED
[10:27:41.351] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:7:0) after 5m12s
[10:32:53.365] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:7:0)
[10:32:53.381] Build status: SCHEDULED
[10:32:53.381] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:8:0) after 8m17s
[10:41:10.393] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:8:0)
[10:41:10.420] Build status: SCHEDULED
[10:41:10.420] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:9:0) after 3m21s
[10:44:31.434] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:9:0)
[10:44:31.460] Build status: SCHEDULED
[10:44:31.460] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:10:0) after 5m41s
[10:50:12.474] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:10:0)
[10:50:12.489] Build status: SCHEDULED
[10:50:12.489] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:11:0) after 5m24s
[10:55:36.555] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:11:0)
[10:55:36.585] Build status: SCHEDULED
[10:55:36.585] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:12:0) after 8m17s
[11:03:53.638] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:12:0)
[11:03:53.691] Build status: SCHEDULED
[11:03:53.691] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:13:0) after 7m36s
[11:11:29.684] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:13:0)
[11:11:29.716] Build status: SCHEDULED
[11:11:29.716] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:14:0) after 1m17s
[11:12:46.790] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:14:0)
[11:12:46.804] Build status: SCHEDULED
[11:12:46.804] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:15:0) after 7m2s
[11:19:48.818] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:15:0)
[11:19:48.836] Build status: SCHEDULED
[11:19:48.837] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:16:0) after 7m51s
[11:27:39.850] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:16:0)
[11:27:39.878] Build status: SCHEDULED
[11:27:39.878] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:17:0) after 8m18s
[11:35:57.892] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:17:0)
[11:35:57.908] Build status: SCHEDULED
[11:35:57.908] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:18:0) after 8m19s
[11:44:16.973] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:18:0)
[11:44:17.001] Build status: SCHEDULED
[11:44:17.001] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:19:0) after 9m48s
[11:54:05.018] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:19:0)
[11:54:05.036] Build status: SCHEDULED
[11:54:05.036] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:20:0) after 3m29s
[11:57:34.572] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:20:0)
[11:57:34.589] Build status: SCHEDULED
[11:57:34.590] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:21:0) after 1m1s
[11:58:35.589] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:21:0)
[11:58:35.628] Build status: SCHEDULED
[11:58:35.628] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:22:0) after 1m34s
[12:00:09.694] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:22:0)
[12:00:09.739] Build status: SCHEDULED
[12:00:09.739] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:23:0) after 5m46s
[12:05:55.753] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:23:0)
[12:05:55.770] Build status: SCHEDULED
[12:05:55.770] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:24:0) after 5m7s
[12:11:02.752] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:24:0)
[12:11:02.776] Build status: SCHEDULED
[12:11:02.776] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:25:0) after 5m18s
[12:16:20.788] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:25:0)
[12:16:20.807] Build status: SCHEDULED
[12:16:20.807] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:26:0) after 2m33s
[12:18:53.917] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:26:0)
[12:18:53.984] Build status: SCHEDULED
[12:18:53.984] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:27:0) after 1m9s
[12:20:03.001] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:27:0)
[12:20:03.015] Build status: SCHEDULED
[12:20:03.016] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:28:0) after 9m32s
[12:29:35.029] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:28:0)
[12:29:35.062] Build status: SCHEDULED
[12:29:35.062] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:29:0) after 6m47s
[12:33:24.710] Received PubSub notification, asking Buildbucket for the build status
[12:33:24.733] Build status: STARTED
[12:36:22.084] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:29:0)
[12:36:22.129] Build status: STARTED
[12:36:22.129] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:31:0) after 9m3s
[12:45:25.201] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:31:0)
[12:45:25.219] Build status: STARTED
[12:45:25.219] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:32:0) after 6m52s
[12:52:17.233] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:32:0)
[12:52:17.268] Build status: STARTED
[12:52:17.268] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:33:0) after 8m47s
[13:01:04.287] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:33:0)
[13:01:04.305] Build status: STARTED
[13:01:04.305] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:34:0) after 8m33s
[13:09:37.318] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:34:0)
[13:09:37.332] Build status: STARTED
[13:09:37.332] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:35:0) after 1m36s
[13:11:13.346] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:35:0)
[13:11:13.362] Build status: STARTED
[13:11:13.363] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:36:0) after 9m12s
[13:20:25.374] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:36:0)
[13:20:25.390] Build status: STARTED
[13:20:25.390] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:37:0) after 5m13s
[13:25:38.445] Handling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:37:0)
[13:25:38.466] Build status: STARTED
[13:25:38.466] Scheduling timer "check-buildbucket-build-status" (r8/linux-jdk17:8865204084604542464:38:0) after 8m11s
[13:26:01.551] Received PubSub notification, asking Buildbucket for the build status
[13:26:01.623] Build:
{
  "id": "8699774022537828177",
  "builder": {
    "project": "r8",
    "bucket": "ci",
    "builder": "linux-jdk17"
  },
  "number": 3935,
  "createdBy": "project:r8",
  "createTime": "2025-10-28T10:06:18.375922412Z",
  "startTime": "2025-10-28T12:33:03.805149004Z",
  "endTime": "2025-10-28T13:26:01.234005844Z",
  "updateTime": "2025-10-28T13:26:01.234005844Z",
  "status": "FAILURE",
  "input": {
    "gitilesCommit": {
      "host": "r8.googlesource.com",
      "project": "r8",
      "id": "3c90b33f61f2266dee763d7ba4096c0c4c99ef1f",
      "ref": "refs/heads/main"
    }
  }
}
[13:26:01.623] Invocation finished in 3h19m44.602636026s with status FAILED