[21:20:12.539] New invocation is queued and will start shortly
[21:20:13.677] Starting the invocation (attempt 1)
[21:20:13.700] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/76d73fdfe92a58ed5c66b599d13ef277f5b39f84"
[21:20:13.700] Popped gitiles commit info from properties and tags
[21:20:13.700] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:20:13.700] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:20:13.701] Buildbucket request:
{
  "requestId": "8867245415125881376",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "Win ASan Release Media"
  },
  "properties": {
    },
  "gitilesCommit": {
    "host": "chromium.googlesource.com",
    "project": "chromium/src",
    "id": "76d73fdfe92a58ed5c66b599d13ef277f5b39f84",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8867245415125881376"
    },
    {
      "key": "scheduler_job_id",
      "value": "chromium/Win ASan Release Media"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[21:20:14.493] Scheduled build:
{
  "id": "8701815353193624785",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "Win ASan Release Media"
  },
  "number": 335204,
  "createdBy": "project:chromium",
  "createTime": "2025-10-05T21:20:13.757725862Z",
  "updateTime": "2025-10-05T21:20:13.757725862Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "76d73fdfe92a58ed5c66b599d13ef277f5b39f84",
      "ref": "refs/heads/main"
    }
  }
}
[21:20:14.493] Task URL: https://cr-buildbucket.appspot.com/build/8701815353193624785
[21:20:14.493] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:2:0) after 4m2s
[21:20:15.209] Received PubSub notification, asking Buildbucket for the build status
[21:20:15.228] Build status: SCHEDULED
[21:21:42.094] Received PubSub notification, asking Buildbucket for the build status
[21:21:42.141] Build status: STARTED
[21:24:16.505] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:2:0)
[21:24:16.529] Build status: STARTED
[21:24:16.529] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:5:0) after 2m9s
[21:26:25.619] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:5:0)
[21:26:25.636] Build status: STARTED
[21:26:25.636] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:6:0) after 3m7s
[21:29:33.153] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:6:0)
[21:29:33.169] Build status: STARTED
[21:29:33.169] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:7:0) after 7m40s
[21:37:13.188] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:7:0)
[21:37:13.219] Build status: STARTED
[21:37:13.219] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:8:0) after 6m52s
[21:44:05.235] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:8:0)
[21:44:05.255] Build status: STARTED
[21:44:05.255] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:9:0) after 3m37s
[21:47:42.474] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:9:0)
[21:47:42.504] Build status: STARTED
[21:47:42.504] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:10:0) after 8m51s
[21:56:33.517] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:10:0)
[21:56:33.534] Build status: STARTED
[21:56:33.534] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:11:0) after 9m51s
[22:06:24.571] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:11:0)
[22:06:24.586] Build status: STARTED
[22:06:24.586] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:12:0) after 4m2s
[22:10:26.718] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:12:0)
[22:10:26.767] Build status: STARTED
[22:10:26.767] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:13:0) after 8m49s
[22:19:15.908] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:13:0)
[22:19:15.925] Build status: STARTED
[22:19:15.925] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:14:0) after 8m32s
[22:27:47.967] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:14:0)
[22:27:47.983] Build status: STARTED
[22:27:47.983] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:15:0) after 4m9s
[22:31:57.093] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:15:0)
[22:31:57.118] Build status: STARTED
[22:31:57.118] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:16:0) after 4m44s
[22:36:41.129] Handling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:16:0)
[22:36:41.192] Build status: STARTED
[22:36:41.192] Scheduling timer "check-buildbucket-build-status" (chromium/Win ASan Release Media:8867245415125881376:17:0) after 8m51s
[22:43:58.715] Received PubSub notification, asking Buildbucket for the build status
[22:43:58.735] Build:
{
  "id": "8701815353193624785",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "Win ASan Release Media"
  },
  "number": 335204,
  "createdBy": "project:chromium",
  "createTime": "2025-10-05T21:20:13.757725862Z",
  "startTime": "2025-10-05T21:21:41.918129321Z",
  "endTime": "2025-10-05T22:43:36.945308489Z",
  "updateTime": "2025-10-05T22:43:36.945308489Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "76d73fdfe92a58ed5c66b599d13ef277f5b39f84",
      "ref": "refs/heads/main"
    }
  }
}
[22:43:58.735] Invocation finished in 1h23m46.20328103s with status SUCCEEDED