[02:37:17.113] New invocation is queued and will start shortly
[02:37:18.275] Starting the invocation (attempt 1)
[02:37:18.313] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/1ebc8e1ba2446a9feb5a6f0ba90a414a85d9cf07"
[02:37:18.313] Popped gitiles commit info from properties and tags
[02:37:18.313] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[02:37:18.313] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[02:37:18.314] Buildbucket request:
{
  "requestId": "8867950242148642288",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "mac-arm64-archive-rel"
  },
  "properties": {
    },
  "gitilesCommit": {
    "host": "chromium.googlesource.com",
    "project": "chromium/src",
    "id": "1ebc8e1ba2446a9feb5a6f0ba90a414a85d9cf07",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8867950242148642288"
    },
    {
      "key": "scheduler_job_id",
      "value": "chromium/mac-arm64-archive-rel"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[02:37:18.789] Scheduled build:
{
  "id": "8702520180150608689",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "mac-arm64-archive-rel"
  },
  "number": 56146,
  "createdBy": "project:chromium",
  "createTime": "2025-09-28T02:37:18.391555353Z",
  "updateTime": "2025-09-28T02:37:18.391555353Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "1ebc8e1ba2446a9feb5a6f0ba90a414a85d9cf07",
      "ref": "refs/heads/main"
    }
  },
  "canary": true
}
[02:37:18.789] Task URL: https://cr-buildbucket.appspot.com/build/8702520180150608689
[02:37:18.789] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:2:0) after 4m35s
[02:37:19.824] Received PubSub notification, asking Buildbucket for the build status
[02:37:19.905] Build status: SCHEDULED
[02:37:21.810] Received PubSub notification, asking Buildbucket for the build status
[02:37:21.838] Build status: STARTED
[02:41:53.969] Handling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:2:0)
[02:41:53.989] Build status: STARTED
[02:41:53.989] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:5:0) after 1m15s
[02:43:09.158] Handling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:5:0)
[02:43:09.186] Build status: STARTED
[02:43:09.186] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:6:0) after 3m14s
[02:46:23.313] Handling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:6:0)
[02:46:23.397] Build status: STARTED
[02:46:23.397] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:7:0) after 3m22s
[02:49:45.433] Handling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:7:0)
[02:49:45.503] Build status: STARTED
[02:49:45.503] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:8:0) after 6m59s
[02:56:44.589] Handling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:8:0)
[02:56:44.604] Build status: STARTED
[02:56:44.605] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:9:0) after 2m28s
[02:59:12.673] Handling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:9:0)
[02:59:12.703] Build status: STARTED
[02:59:12.703] Scheduling timer "check-buildbucket-build-status" (chromium/mac-arm64-archive-rel:8867950242148642288:10:0) after 8m7s
[03:01:59.879] Received PubSub notification, asking Buildbucket for the build status
[03:01:59.894] Build:
{
  "id": "8702520180150608689",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "mac-arm64-archive-rel"
  },
  "number": 56146,
  "createdBy": "project:chromium",
  "createTime": "2025-09-28T02:37:18.391555353Z",
  "startTime": "2025-09-28T02:37:21.620453869Z",
  "endTime": "2025-09-28T03:01:49.404963618Z",
  "updateTime": "2025-09-28T03:01:49.404963618Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "1ebc8e1ba2446a9feb5a6f0ba90a414a85d9cf07",
      "ref": "refs/heads/main"
    }
  },
  "canary": true
}
[03:01:59.894] Invocation finished in 24m42.791800481s with status SUCCEEDED