[20:19:32.949] New invocation is queued and will start shortly
[20:19:34.020] Starting the invocation (attempt 1)
[20:19:34.050] Popped buildset tag "buildset:commit/gitiles/pigweed.googlesource.com/pigweed/examples/+/f062ad2c5bbd6527d08b9b731e48280270f64f63"
[20:19:34.050] Popped gitiles commit info from properties and tags
[20:19:34.050] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[20:19:34.050] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[20:19:34.050] Buildbucket request:
{
  "requestId": "8866252664876407680",
  "builder": {
    "project": "pigweed",
    "bucket": "examples.dev.ci",
    "builder": "examples-default-build-mac-arm"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8866252664876407680",
            "job": "pigweed/examples.dev.ci-examples-default-build-mac-arm",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://pigweed.googlesource.com/pigweed/examples",
                              "revision": "f062ad2c5bbd6527d08b9b731e48280270f64f63"
                            },
                        "id": "https://pigweed.googlesource.com/pigweed/examples/+/refs/heads/main@f062ad2c5bbd6527d08b9b731e48280270f64f63",
                        "title": "f062ad2c5bbd6527d08b9b731e48280270f64f63",
                        "url": "https://pigweed.googlesource.com/pigweed/examples/+/f062ad2c5bbd6527d08b9b731e48280270f64f63"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "pigweed.googlesource.com",
    "project": "pigweed/examples",
    "id": "f062ad2c5bbd6527d08b9b731e48280270f64f63",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8866252664876407680"
    },
    {
      "key": "scheduler_job_id",
      "value": "pigweed/examples.dev.ci-examples-default-build-mac-arm"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[20:19:34.503] Scheduled build:
{
  "id": "8700822602991226753",
  "builder": {
    "project": "pigweed",
    "bucket": "examples.dev.ci",
    "builder": "examples-default-build-mac-arm"
  },
  "createdBy": "project:pigweed",
  "createTime": "2025-10-16T20:19:34.128887257Z",
  "updateTime": "2025-10-16T20:19:34.128887257Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "pigweed.googlesource.com",
      "project": "pigweed/examples",
      "id": "f062ad2c5bbd6527d08b9b731e48280270f64f63",
      "ref": "refs/heads/main"
    }
  }
}
[20:19:34.503] Task URL: https://cr-buildbucket.appspot.com/build/8700822602991226753
[20:19:34.503] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:2:0) after 5m0s
[20:19:35.141] Received PubSub notification, asking Buildbucket for the build status
[20:19:35.187] Build status: SCHEDULED
[20:24:34.515] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:2:0)
[20:24:34.533] Build status: SCHEDULED
[20:24:34.533] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:4:0) after 2m52s
[20:27:26.598] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:4:0)
[20:27:26.630] Build status: SCHEDULED
[20:27:26.630] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:5:0) after 3m22s
[20:30:48.642] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:5:0)
[20:30:48.721] Build status: SCHEDULED
[20:30:48.721] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:6:0) after 1m50s
[20:32:38.733] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:6:0)
[20:32:38.750] Build status: SCHEDULED
[20:32:38.750] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:7:0) after 7m57s
[20:40:35.766] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:7:0)
[20:40:35.791] Build status: SCHEDULED
[20:40:35.791] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:8:0) after 6m15s
[20:46:50.857] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:8:0)
[20:46:50.884] Build status: SCHEDULED
[20:46:50.884] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:9:0) after 9m2s
[20:55:52.946] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:9:0)
[20:55:52.964] Build status: SCHEDULED
[20:55:52.964] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:10:0) after 5m3s
[21:00:55.980] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:10:0)
[21:00:56.007] Build status: SCHEDULED
[21:00:56.007] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:11:0) after 2m46s
[21:03:42.119] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:11:0)
[21:03:42.135] Build status: SCHEDULED
[21:03:42.135] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:12:0) after 3m9s
[21:06:51.343] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:12:0)
[21:06:51.460] Build status: SCHEDULED
[21:06:51.460] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:13:0) after 9m10s
[21:16:01.524] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:13:0)
[21:16:01.554] Build status: SCHEDULED
[21:16:01.554] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:14:0) after 1m10s
[21:17:11.528] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:14:0)
[21:17:11.555] Build status: SCHEDULED
[21:17:11.555] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:15:0) after 4m2s
[21:21:13.636] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:15:0)
[21:21:13.658] Build status: SCHEDULED
[21:21:13.659] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:16:0) after 1m50s
[21:23:03.675] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:16:0)
[21:23:03.696] Build status: SCHEDULED
[21:23:03.696] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:17:0) after 2m39s
[21:25:42.740] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:17:0)
[21:25:42.757] Build status: SCHEDULED
[21:25:42.757] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:18:0) after 9m45s
[21:35:27.809] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:18:0)
[21:35:27.824] Build status: SCHEDULED
[21:35:27.824] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:19:0) after 8m54s
[21:44:21.839] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:19:0)
[21:44:21.863] Build status: SCHEDULED
[21:44:21.863] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:20:0) after 4m40s
[21:49:01.875] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:20:0)
[21:49:01.901] Build status: SCHEDULED
[21:49:01.901] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:21:0) after 7m40s
[21:56:41.913] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:21:0)
[21:56:41.932] Build status: SCHEDULED
[21:56:41.932] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:22:0) after 3m1s
[21:59:42.944] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:22:0)
[21:59:42.983] Build status: SCHEDULED
[21:59:42.983] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:23:0) after 6m7s
[22:05:49.995] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:23:0)
[22:05:50.011] Build status: SCHEDULED
[22:05:50.011] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:24:0) after 9m8s
[22:14:58.004] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:24:0)
[22:14:58.059] Build status: SCHEDULED
[22:14:58.059] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:25:0) after 8m57s
[22:23:55.279] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:25:0)
[22:23:55.307] Build status: SCHEDULED
[22:23:55.307] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:26:0) after 7m37s
[22:31:32.321] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:26:0)
[22:31:32.335] Build status: SCHEDULED
[22:31:32.335] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:27:0) after 7m5s
[22:38:37.397] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:27:0)
[22:38:37.460] Build status: SCHEDULED
[22:38:37.460] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:28:0) after 7m53s
[22:46:30.474] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:28:0)
[22:46:30.538] Build status: SCHEDULED
[22:46:30.538] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:29:0) after 5m47s
[22:52:17.558] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:29:0)
[22:52:17.577] Build status: SCHEDULED
[22:52:17.577] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:30:0) after 8m6s
[23:00:23.585] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:30:0)
[23:00:23.603] Build status: SCHEDULED
[23:00:23.603] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:31:0) after 5m49s
[23:06:12.621] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:31:0)
[23:06:12.663] Build status: SCHEDULED
[23:06:12.663] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:32:0) after 5m39s
[23:11:51.765] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:32:0)
[23:11:51.782] Build status: SCHEDULED
[23:11:51.782] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:33:0) after 8m20s
[23:20:11.898] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:33:0)
[23:20:11.919] Build status: SCHEDULED
[23:20:11.919] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:34:0) after 7m18s
[23:27:19.203] Received PubSub notification, asking Buildbucket for the build status
[23:27:19.222] Build status: STARTED
[23:27:29.985] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:34:0)
[23:27:30.003] Build status: STARTED
[23:27:30.003] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-default-build-mac-arm:8866252664876407680:36:0) after 7m44s
[23:32:46.825] Received PubSub notification, asking Buildbucket for the build status
[23:32:46.845] Build:
{
  "id": "8700822602991226753",
  "builder": {
    "project": "pigweed",
    "bucket": "examples.dev.ci",
    "builder": "examples-default-build-mac-arm"
  },
  "createdBy": "project:pigweed",
  "createTime": "2025-10-16T20:19:34.128887257Z",
  "startTime": "2025-10-16T23:27:18.728424Z",
  "endTime": "2025-10-16T23:32:46.478735692Z",
  "updateTime": "2025-10-16T23:32:46.478735692Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "pigweed.googlesource.com",
      "project": "pigweed/examples",
      "id": "f062ad2c5bbd6527d08b9b731e48280270f64f63",
      "ref": "refs/heads/main"
    }
  }
}
[23:32:46.845] Invocation finished in 3h13m13.898929373s with status SUCCEEDED