[07:03:28.605] New invocation is queued and will start shortly
[07:03:30.260] Starting the invocation (attempt 1)
[07:03:30.285] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/v8/v8/+/5eabe0e18a443ee8115b7c578ade2611ec434ba0"
[07:03:30.285] Popped gitiles commit info from properties and tags
[07:03:30.285] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[07:03:30.286] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[07:03:30.286] Buildbucket request:
{
  "requestId": "8867571106957198400",
  "builder": {
    "project": "v8",
    "bucket": "ci",
    "builder": "V8 Official Win64"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8867571106957198400",
            "job": "v8/V8 Official Win64",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/branch-heads/13.2",
                              "repo": "https://chromium.googlesource.com/v8/v8",
                              "revision": "5eabe0e18a443ee8115b7c578ade2611ec434ba0"
                            },
                        "id": "https://chromium.googlesource.com/v8/v8/+/refs/branch-heads/13.2@5eabe0e18a443ee8115b7c578ade2611ec434ba0",
                        "title": "5eabe0e18a443ee8115b7c578ade2611ec434ba0",
                        "url": "https://chromium.googlesource.com/v8/v8/+/5eabe0e18a443ee8115b7c578ade2611ec434ba0"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "chromium.googlesource.com",
    "project": "v8/v8",
    "id": "5eabe0e18a443ee8115b7c578ade2611ec434ba0",
    "ref": "refs/branch-heads/13.2"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8867571106957198400"
    },
    {
      "key": "scheduler_job_id",
      "value": "v8/V8 Official Win64"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[07:03:30.771] Scheduled build:
{
  "id": "8702141044486393345",
  "builder": {
    "project": "v8",
    "bucket": "ci",
    "builder": "V8 Official Win64"
  },
  "number": 35103,
  "createdBy": "project:v8",
  "createTime": "2025-10-02T07:03:30.336425984Z",
  "updateTime": "2025-10-02T07:03:30.336425984Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "v8/v8",
      "id": "5eabe0e18a443ee8115b7c578ade2611ec434ba0",
      "ref": "refs/branch-heads/13.2"
    }
  }
}
[07:03:30.771] Task URL: https://cr-buildbucket.appspot.com/build/8702141044486393345
[07:03:30.771] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:2:0) after 1m24s
[07:03:31.714] Received PubSub notification, asking Buildbucket for the build status
[07:03:31.739] Build status: SCHEDULED
[07:03:45.160] Received PubSub notification, asking Buildbucket for the build status
[07:03:45.180] Build status: STARTED
[07:04:54.788] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:2:0)
[07:04:54.809] Build status: STARTED
[07:04:54.809] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:5:0) after 3m18s
[07:08:12.878] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:5:0)
[07:08:12.891] Build status: STARTED
[07:08:12.891] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:6:0) after 4m18s
[07:12:30.954] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:6:0)
[07:12:30.967] Build status: STARTED
[07:12:30.968] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:7:0) after 9m11s
[07:21:42.015] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:7:0)
[07:21:42.041] Build status: STARTED
[07:21:42.041] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:8:0) after 6m41s
[07:28:23.057] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:8:0)
[07:28:23.076] Build status: STARTED
[07:28:23.076] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:9:0) after 2m28s
[07:30:51.180] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:9:0)
[07:30:51.199] Build status: STARTED
[07:30:51.199] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:10:0) after 8m34s
[07:39:25.214] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:10:0)
[07:39:25.230] Build status: STARTED
[07:39:25.230] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:11:0) after 4m36s
[07:44:01.308] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:11:0)
[07:44:01.336] Build status: STARTED
[07:44:01.336] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:12:0) after 2m16s
[07:46:17.419] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:12:0)
[07:46:17.455] Build status: STARTED
[07:46:17.455] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:13:0) after 1m34s
[07:47:51.469] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:13:0)
[07:47:51.487] Build status: STARTED
[07:47:51.487] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:14:0) after 8m45s
[07:56:36.552] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:14:0)
[07:56:36.574] Build status: STARTED
[07:56:36.574] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:15:0) after 3m34s
[08:00:10.590] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:15:0)
[08:00:10.617] Build status: STARTED
[08:00:10.617] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:16:0) after 3m54s
[08:04:04.630] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:16:0)
[08:04:04.643] Build status: STARTED
[08:04:04.643] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:17:0) after 5m49s
[08:09:53.686] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:17:0)
[08:09:53.701] Build status: STARTED
[08:09:53.701] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:18:0) after 4m21s
[08:14:14.733] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:18:0)
[08:14:14.747] Build status: STARTED
[08:14:14.747] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:19:0) after 8m46s
[08:23:00.762] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:19:0)
[08:23:00.779] Build status: STARTED
[08:23:00.779] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:20:0) after 9m27s
[08:32:27.859] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:20:0)
[08:32:27.884] Build status: STARTED
[08:32:27.884] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:21:0) after 6m11s
[08:38:39.057] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:21:0)
[08:38:39.083] Build status: STARTED
[08:38:39.083] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:22:0) after 3m15s
[08:41:54.101] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:22:0)
[08:41:54.120] Build status: STARTED
[08:41:54.120] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:23:0) after 9m43s
[08:51:37.137] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:23:0)
[08:51:37.172] Build status: STARTED
[08:51:37.172] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:24:0) after 7m57s
[08:59:34.280] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:24:0)
[08:59:34.297] Build status: STARTED
[08:59:34.297] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:25:0) after 2m54s
[09:02:28.283] Handling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:25:0)
[09:02:28.388] Build status: STARTED
[09:02:28.388] Scheduling timer "check-buildbucket-build-status" (v8/V8 Official Win64:8867571106957198400:26:0) after 4m4s
[09:03:47.990] Received PubSub notification, asking Buildbucket for the build status
[09:03:48.006] Build:
{
  "id": "8702141044486393345",
  "builder": {
    "project": "v8",
    "bucket": "ci",
    "builder": "V8 Official Win64"
  },
  "number": 35103,
  "createdBy": "project:v8",
  "createTime": "2025-10-02T07:03:30.336425984Z",
  "startTime": "2025-10-02T07:03:44.888507671Z",
  "endTime": "2025-10-02T09:03:47.763345863Z",
  "updateTime": "2025-10-02T09:03:47.763345863Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "chromium.googlesource.com",
      "project": "v8/v8",
      "id": "5eabe0e18a443ee8115b7c578ade2611ec434ba0",
      "ref": "refs/branch-heads/13.2"
    }
  }
}
[09:03:48.006] Invocation finished in 2h0m19.410565693s with status SUCCEEDED