[21:00:03.389] New invocation is queued and will start shortly
[21:00:04.505] Starting the invocation (attempt 1)
[21:00:04.567] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/5851a5de0f35230e3c9393d06a056f4c177efec3"
[21:00:04.567] Popped gitiles commit info from properties and tags
[21:00:04.567] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:00:04.567] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:00:04.567] Buildbucket request:
{
  "requestId": "8870055188972691984",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "linux-x64-libfuzzer-asan-dbg-tests"
  },
  "properties": {
    },
  "gitilesCommit": {
    "host": "chromium.googlesource.com",
    "project": "chromium/src",
    "id": "5851a5de0f35230e3c9393d06a056f4c177efec3",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8870055188972691984"
    },
    {
      "key": "scheduler_job_id",
      "value": "chromium/linux-x64-libfuzzer-asan-dbg-tests"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[21:00:05.263] Scheduled build:
{
  "id": "8704625126953207809",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "linux-x64-libfuzzer-asan-dbg-tests"
  },
  "number": 1154,
  "createdBy": "project:chromium",
  "createTime": "2025-09-04T21:00:04.688684125Z",
  "updateTime": "2025-09-04T21:00:04.688684125Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "5851a5de0f35230e3c9393d06a056f4c177efec3",
      "ref": "refs/heads/main"
    }
  }
}
[21:00:05.263] Task URL: https://cr-buildbucket.appspot.com/build/8704625126953207809
[21:00:05.263] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:2:0) after 2m45s
[21:00:05.442] Received PubSub notification, asking Buildbucket for the build status
[21:00:05.473] Build status: SCHEDULED
[21:02:50.284] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:2:0)
[21:02:50.302] Build status: SCHEDULED
[21:02:50.302] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:4:0) after 7m5s
[21:09:55.347] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:4:0)
[21:09:55.368] Build status: SCHEDULED
[21:09:55.368] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:5:0) after 2m10s
[21:12:05.385] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:5:0)
[21:12:05.418] Build status: SCHEDULED
[21:12:05.418] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:6:0) after 9m14s
[21:21:19.473] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:6:0)
[21:21:19.492] Build status: SCHEDULED
[21:21:19.492] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:7:0) after 7m8s
[21:28:27.515] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:7:0)
[21:28:27.562] Build status: SCHEDULED
[21:28:27.562] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:8:0) after 1m24s
[21:29:51.581] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:8:0)
[21:29:51.647] Build status: SCHEDULED
[21:29:51.647] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:9:0) after 3m3s
[21:32:54.665] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:9:0)
[21:32:54.682] Build status: SCHEDULED
[21:32:54.682] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:10:0) after 2m22s
[21:35:16.699] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:10:0)
[21:35:16.724] Build status: SCHEDULED
[21:35:16.724] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:11:0) after 8m13s
[21:43:29.731] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:11:0)
[21:43:29.750] Build status: SCHEDULED
[21:43:29.750] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:12:0) after 7m46s
[21:51:15.819] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:12:0)
[21:51:15.892] Build status: SCHEDULED
[21:51:15.892] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:13:0) after 3m53s
[21:55:08.962] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:13:0)
[21:55:09.068] Build status: SCHEDULED
[21:55:09.068] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:14:0) after 9m15s
[22:01:34.307] Received PubSub notification, asking Buildbucket for the build status
[22:01:34.386] Build status: STARTED
[22:04:24.046] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:14:0)
[22:04:24.162] Build status: STARTED
[22:04:24.162] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:16:0) after 5m37s
[22:10:01.182] Handling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:16:0)
[22:10:01.201] Build status: STARTED
[22:10:01.202] Scheduling timer "check-buildbucket-build-status" (chromium/linux-x64-libfuzzer-asan-dbg-tests:8870055188972691984:17:0) after 7m50s
[22:10:44.454] Received PubSub notification, asking Buildbucket for the build status
[22:10:44.473] Build:
{
  "id": "8704625126953207809",
  "builder": {
    "project": "chromium",
    "bucket": "ci",
    "builder": "linux-x64-libfuzzer-asan-dbg-tests"
  },
  "number": 1154,
  "createdBy": "project:chromium",
  "createTime": "2025-09-04T21:00:04.688684125Z",
  "startTime": "2025-09-04T22:01:33.306873976Z",
  "endTime": "2025-09-04T22:10:43.652356429Z",
  "updateTime": "2025-09-04T22:10:43.652356429Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "5851a5de0f35230e3c9393d06a056f4c177efec3",
      "ref": "refs/heads/main"
    }
  }
}
[22:10:44.473] Invocation finished in 1h10m41.095289649s with status SUCCEEDED