[20:00:46.966] New invocation is queued and will start shortly
[20:00:49.076] Starting the invocation (attempt 1)
[20:00:49.106] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/d96d63f899f0d087960ad131930a0966a6668ee5"
[20:00:49.106] Popped gitiles commit info from properties and tags
[20:00:49.106] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[20:00:49.107] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[20:00:49.107] Buildbucket request:
{
  "requestId": "8870964887822346304",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "chromeos-structured-test-ids-amd64-generic-rel-fyi"
  },
  "properties": {
    },
  "gitilesCommit": {
    "host": "chromium.googlesource.com",
    "project": "chromium/src",
    "id": "d96d63f899f0d087960ad131930a0966a6668ee5",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8870964887822346304"
    },
    {
      "key": "scheduler_job_id",
      "value": "chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[20:00:49.806] Scheduled build:
{
  "id": "8705534824796218897",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "chromeos-structured-test-ids-amd64-generic-rel-fyi"
  },
  "number": 228,
  "createdBy": "project:chromium",
  "createTime": "2025-08-25T20:00:49.219755957Z",
  "updateTime": "2025-08-25T20:00:49.219755957Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "d96d63f899f0d087960ad131930a0966a6668ee5",
      "ref": "refs/heads/main"
    }
  }
}
[20:00:49.806] Task URL: https://cr-buildbucket.appspot.com/build/8705534824796218897
[20:00:49.806] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:2:0) after 2m45s
[20:00:51.857] Received PubSub notification, asking Buildbucket for the build status
[20:00:51.892] Build status: SCHEDULED
[20:00:57.536] Received PubSub notification, asking Buildbucket for the build status
[20:00:57.570] Build status: STARTED
[20:03:34.858] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:2:0)
[20:03:34.888] Build status: STARTED
[20:03:34.888] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:5:0) after 1m1s
[20:04:36.001] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:5:0)
[20:04:36.078] Build status: STARTED
[20:04:36.078] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:6:0) after 4m34s
[20:09:10.147] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:6:0)
[20:09:10.166] Build status: STARTED
[20:09:10.166] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:7:0) after 7m41s
[20:16:51.182] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:7:0)
[20:16:51.201] Build status: STARTED
[20:16:51.201] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:8:0) after 7m37s
[20:24:28.232] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:8:0)
[20:24:28.259] Build status: STARTED
[20:24:28.259] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:9:0) after 1m21s
[20:25:49.296] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:9:0)
[20:25:49.321] Build status: STARTED
[20:25:49.321] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:10:0) after 3m55s
[20:29:44.329] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:10:0)
[20:29:44.355] Build status: STARTED
[20:29:44.355] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:11:0) after 1m55s
[20:31:39.481] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:11:0)
[20:31:39.513] Build status: STARTED
[20:31:39.513] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:12:0) after 9m42s
[20:41:21.509] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:12:0)
[20:41:21.528] Build status: STARTED
[20:41:21.528] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:13:0) after 1m3s
[20:42:24.600] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:13:0)
[20:42:24.629] Build status: STARTED
[20:42:24.629] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:14:0) after 5m59s
[20:48:23.754] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:14:0)
[20:48:23.770] Build status: STARTED
[20:48:23.770] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:15:0) after 9m18s
[20:57:41.903] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:15:0)
[20:57:41.921] Build status: STARTED
[20:57:41.921] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:16:0) after 4m21s
[21:02:02.999] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:16:0)
[21:02:03.022] Build status: STARTED
[21:02:03.022] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:17:0) after 4m46s
[21:06:49.041] Handling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:17:0)
[21:06:49.059] Build status: STARTED
[21:06:49.059] Scheduling timer "check-buildbucket-build-status" (chromium/chromeos-structured-test-ids-amd64-generic-rel-fyi:8870964887822346304:18:0) after 9m47s
[21:07:25.091] Received PubSub notification, asking Buildbucket for the build status
[21:07:25.107] Build:
{
  "id": "8705534824796218897",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "chromeos-structured-test-ids-amd64-generic-rel-fyi"
  },
  "number": 228,
  "createdBy": "project:chromium",
  "createTime": "2025-08-25T20:00:49.219755957Z",
  "startTime": "2025-08-25T20:00:54.364550237Z",
  "endTime": "2025-08-25T21:07:24.693535059Z",
  "updateTime": "2025-08-25T21:07:24.693535059Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "d96d63f899f0d087960ad131930a0966a6668ee5",
      "ref": "refs/heads/main"
    }
  }
}
[21:07:25.107] Invocation finished in 1h6m38.156601134s with status SUCCEEDED