[22:29:16.458] New invocation is queued and will start shortly
[22:29:17.729] Starting the invocation (attempt 1)
[22:29:17.758] Popped buildset tag "buildset:commit/gitiles/pdfium.googlesource.com/pdfium/+/fa63d2782b18c0a608d2ff23e20be1364041abd5"
[22:29:17.758] Popped gitiles commit info from properties and tags
[22:29:17.758] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[22:29:17.758] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[22:29:17.759] Buildbucket request:
{
  "requestId": "8865610324513951984",
  "builder": {
    "project": "pdfium",
    "bucket": "ci",
    "builder": "mac_xfa"
  },
  "properties": {
      "$recipe_engine/scheduler": {
            "hostname": "luci-scheduler.appspot.com",
            "invocation": "8865610324513951984",
            "job": "pdfium/mac_xfa",
            "triggers": [
                  {
                        "gitiles": {
                              "ref": "refs/heads/main",
                              "repo": "https://pdfium.googlesource.com/pdfium",
                              "revision": "fa63d2782b18c0a608d2ff23e20be1364041abd5"
                            },
                        "id": "https://pdfium.googlesource.com/pdfium/+/refs/heads/main@fa63d2782b18c0a608d2ff23e20be1364041abd5",
                        "title": "fa63d2782b18c0a608d2ff23e20be1364041abd5",
                        "url": "https://pdfium.googlesource.com/pdfium/+/fa63d2782b18c0a608d2ff23e20be1364041abd5"
                      }
                ]
          }
    },
  "gitilesCommit": {
    "host": "pdfium.googlesource.com",
    "project": "pdfium",
    "id": "fa63d2782b18c0a608d2ff23e20be1364041abd5",
    "ref": "refs/heads/main"
  },
  "tags": [
    {
      "key": "scheduler_invocation_id",
      "value": "8865610324513951984"
    },
    {
      "key": "scheduler_job_id",
      "value": "pdfium/mac_xfa"
    },
    {
      "key": "user_agent",
      "value": "luci-scheduler"
    }
  ],
  "notify": {
    "pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
  }
}
[22:29:18.211] Scheduled build:
{
  "id": "8700180262441218833",
  "builder": {
    "project": "pdfium",
    "bucket": "ci",
    "builder": "mac_xfa"
  },
  "number": 14098,
  "createdBy": "project:pdfium",
  "createTime": "2025-10-23T22:29:17.813574532Z",
  "updateTime": "2025-10-23T22:29:17.813574532Z",
  "status": "SCHEDULED",
  "input": {
    "gitilesCommit": {
      "host": "pdfium.googlesource.com",
      "project": "pdfium",
      "id": "fa63d2782b18c0a608d2ff23e20be1364041abd5",
      "ref": "refs/heads/main"
    }
  }
}
[22:29:18.211] Task URL: https://cr-buildbucket.appspot.com/build/8700180262441218833
[22:29:18.211] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:2:0) after 3m56s
[22:29:18.485] Received PubSub notification, asking Buildbucket for the build status
[22:29:18.516] Build status: SCHEDULED
[22:33:14.245] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:2:0)
[22:33:14.267] Build status: SCHEDULED
[22:33:14.267] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:4:0) after 9m55s
[22:43:09.331] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:4:0)
[22:43:09.353] Build status: SCHEDULED
[22:43:09.353] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:5:0) after 9m0s
[22:52:09.365] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:5:0)
[22:52:09.418] Build status: SCHEDULED
[22:52:09.418] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:6:0) after 9m10s
[23:01:19.456] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:6:0)
[23:01:19.476] Build status: SCHEDULED
[23:01:19.476] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:7:0) after 3m16s
[23:04:35.448] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:7:0)
[23:04:35.469] Build status: SCHEDULED
[23:04:35.469] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:8:0) after 7m22s
[23:11:57.563] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:8:0)
[23:11:57.577] Build status: SCHEDULED
[23:11:57.577] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:9:0) after 3m42s
[23:15:39.590] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:9:0)
[23:15:39.616] Build status: SCHEDULED
[23:15:39.616] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:10:0) after 5m4s
[23:20:43.720] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:10:0)
[23:20:43.743] Build status: SCHEDULED
[23:20:43.743] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:11:0) after 4m1s
[23:24:44.764] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:11:0)
[23:24:44.799] Build status: SCHEDULED
[23:24:44.799] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:12:0) after 5m40s
[23:30:24.863] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:12:0)
[23:30:24.879] Build status: SCHEDULED
[23:30:24.879] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:13:0) after 1m3s
[23:31:27.874] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:13:0)
[23:31:27.926] Build status: SCHEDULED
[23:31:27.926] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:14:0) after 1m2s
[23:32:29.941] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:14:0)
[23:32:29.960] Build status: SCHEDULED
[23:32:29.960] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:15:0) after 9m46s
[23:38:52.145] Received PubSub notification, asking Buildbucket for the build status
[23:38:52.180] Build status: STARTED
[23:42:16.058] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:15:0)
[23:42:16.077] Build status: STARTED
[23:42:16.077] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:17:0) after 2m27s
[23:44:43.134] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:17:0)
[23:44:43.232] Build status: STARTED
[23:44:43.232] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:18:0) after 6m3s
[23:50:46.342] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:18:0)
[23:50:46.359] Build status: STARTED
[23:50:46.359] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:19:0) after 3m17s
[23:54:03.372] Handling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:19:0)
[23:54:03.389] Build status: STARTED
[23:54:03.389] Scheduling timer "check-buildbucket-build-status" (pdfium/mac_xfa:8865610324513951984:20:0) after 6m22s
[23:58:45.170] Received PubSub notification, asking Buildbucket for the build status
[23:58:45.189] Build:
{
  "id": "8700180262441218833",
  "builder": {
    "project": "pdfium",
    "bucket": "ci",
    "builder": "mac_xfa"
  },
  "number": 14098,
  "createdBy": "project:pdfium",
  "createTime": "2025-10-23T22:29:17.813574532Z",
  "startTime": "2025-10-23T23:38:28.834719632Z",
  "endTime": "2025-10-23T23:58:44.055429339Z",
  "updateTime": "2025-10-23T23:58:44.055429339Z",
  "status": "SUCCESS",
  "input": {
    "gitilesCommit": {
      "host": "pdfium.googlesource.com",
      "project": "pdfium",
      "id": "fa63d2782b18c0a608d2ff23e20be1364041abd5",
      "ref": "refs/heads/main"
    }
  }
}
[23:58:45.189] Invocation finished in 1h29m28.737045784s with status SUCCEEDED