[14:39:09.837] New invocation is queued and will start shortly
[14:39:11.069] Starting the invocation (attempt 1)
[14:39:11.103] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/f38463fd645d12a2eb07cd4dae77afabf2ba4139"
[14:39:11.103] Popped gitiles commit info from properties and tags
[14:39:11.104] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[14:39:11.104] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[14:39:11.104] Buildbucket request:
{
  "requestId": "8866274080076125328",
  "builder": {
    "project": "chromium-m140",
    "bucket": "ci",
    "builder": "Dawn Win11 arm64 DEPS Builder"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8866274080076125328",
            "job": "chromium-m140/Dawn Win11 arm64 DEPS Builder",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/branch-heads/7339",
                              "repo": "https://chromium.googlesource.com/chromium/src",
                              "revision": "f38463fd645d12a2eb07cd4dae77afabf2ba4139"
                            },
                        "id": "https://chromium.googlesource.com/chromium/src/+/refs/branch-heads/7339@f38463fd645d12a2eb07cd4dae77afabf2ba4139",
                        "title": "f38463fd645d12a2eb07cd4dae77afabf2ba4139",
                        "url": "https://chromium.googlesource.com/chromium/src/+/f38463fd645d12a2eb07cd4dae77afabf2ba4139"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "chromium.googlesource.com",
    "project": "chromium/src",
    "id": "f38463fd645d12a2eb07cd4dae77afabf2ba4139",
    "ref": "refs/branch-heads/7339"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8866274080076125328"
    },
    {
      "key": "scheduler_job_id",
      "value": "chromium-m140/Dawn Win11 arm64 DEPS Builder"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[14:39:11.626] Scheduled build:
{
  "id": "8700844017994935329",
  "builder": {
    "project": "chromium-m140",
    "bucket": "ci",
    "builder": "Dawn Win11 arm64 DEPS Builder"
  },
  "number": 2732,
  "createdBy": "project:chromium-m140",
  "createTime": "2025-10-16T14:39:11.189241598Z",
  "updateTime": "2025-10-16T14:39:11.189241598Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "f38463fd645d12a2eb07cd4dae77afabf2ba4139",
      "ref": "refs/branch-heads/7339"
    }
  }
}
[14:39:11.626] Task URL: https://cr-buildbucket.appspot.com/build/8700844017994935329
[14:39:11.626] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:2:0) after 2m38s
[14:39:11.799] Received PubSub notification, asking Buildbucket for the build status
[14:39:11.823] Build status: SCHEDULED
[14:41:49.677] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:2:0)
[14:41:49.694] Build status: SCHEDULED
[14:41:49.694] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:4:0) after 4m36s
[14:43:26.278] Received PubSub notification, asking Buildbucket for the build status
[14:43:26.319] Build status: STARTED
[14:46:25.709] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:4:0)
[14:46:25.729] Build status: STARTED
[14:46:25.729] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:6:0) after 7m22s
[14:53:47.743] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:6:0)
[14:53:47.764] Build status: STARTED
[14:53:47.764] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:7:0) after 6m16s
[15:00:03.774] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:7:0)
[15:00:03.793] Build status: STARTED
[15:00:03.793] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:8:0) after 1m9s
[15:01:12.816] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:8:0)
[15:01:12.838] Build status: STARTED
[15:01:12.838] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:9:0) after 3m22s
[15:04:34.858] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:9:0)
[15:04:34.883] Build status: STARTED
[15:04:34.883] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:10:0) after 4m5s
[15:08:39.914] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:10:0)
[15:08:39.935] Build status: STARTED
[15:08:39.935] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:11:0) after 6m12s
[15:14:52.019] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:11:0)
[15:14:52.036] Build status: STARTED
[15:14:52.036] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:12:0) after 6m9s
[15:21:01.069] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:12:0)
[15:21:01.086] Build status: STARTED
[15:21:01.086] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:13:0) after 6m20s
[15:27:21.120] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:13:0)
[15:27:21.204] Build status: STARTED
[15:27:21.204] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:14:0) after 4m54s
[15:32:15.264] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:14:0)
[15:32:15.297] Build status: STARTED
[15:32:15.297] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:15:0) after 9m58s
[15:42:13.359] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:15:0)
[15:42:13.381] Build status: STARTED
[15:42:13.381] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:16:0) after 4m28s
[15:46:41.412] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:16:0)
[15:46:41.429] Build status: STARTED
[15:46:41.429] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:17:0) after 6m15s
[15:52:56.444] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:17:0)
[15:52:56.463] Build status: STARTED
[15:52:56.463] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:18:0) after 8m34s
[16:01:30.534] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:18:0)
[16:01:30.628] Build status: STARTED
[16:01:30.628] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:19:0) after 4m14s
[16:05:44.642] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:19:0)
[16:05:44.661] Build status: STARTED
[16:05:44.661] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:20:0) after 7m17s
[16:13:01.725] Handling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:20:0)
[16:13:01.768] Build status: STARTED
[16:13:01.768] Scheduling timer "check-buildbucket-build-status" (chromium-m140/Dawn Win11 arm64 DEPS Builder:8866274080076125328:21:0) after 4m43s
[16:16:51.136] Received PubSub notification, asking Buildbucket for the build status
[16:16:51.154] Build:
{
  "id": "8700844017994935329",
  "builder": {
    "project": "chromium-m140",
    "bucket": "ci",
    "builder": "Dawn Win11 arm64 DEPS Builder"
  },
  "number": 2732,
  "createdBy": "project:chromium-m140",
  "createTime": "2025-10-16T14:39:11.189241598Z",
  "startTime": "2025-10-16T14:43:26.003712296Z",
  "endTime": "2025-10-16T16:16:50.844934031Z",
  "updateTime": "2025-10-16T16:16:50.844934031Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "chromium/src",
      "id": "f38463fd645d12a2eb07cd4dae77afabf2ba4139",
      "ref": "refs/branch-heads/7339"
    }
  }
}
[16:16:51.154] Invocation finished in 1h37m41.333641867s with status SUCCEEDED