[22:17:26.497] New invocation is queued and will start shortly
[22:17:27.805] Starting the invocation (attempt 1)
[22:17:27.836] Popped buildset tag "buildset:commit/gitiles/pigweed.googlesource.com/pigweed/examples/+/56a6c8dd0d7c72900e8aa76465fa715a9b93b542"
[22:17:27.836] Popped gitiles commit info from properties and tags
[22:17:27.836] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[22:17:27.836] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[22:17:27.836] Buildbucket request:
{
"requestId": "8874670765603421056",
"builder": {
"project": "pigweed",
"bucket": "examples.dev.ci",
"builder": "examples-envtest-linux"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8874670765603421056",
"job": "pigweed/examples.dev.ci-examples-envtest-linux",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://pigweed.googlesource.com/pigweed/examples",
"revision": "56a6c8dd0d7c72900e8aa76465fa715a9b93b542"
},
"id": "https://pigweed.googlesource.com/pigweed/examples/+/refs/heads/main@56a6c8dd0d7c72900e8aa76465fa715a9b93b542",
"title": "56a6c8dd0d7c72900e8aa76465fa715a9b93b542",
"url": "https://pigweed.googlesource.com/pigweed/examples/+/56a6c8dd0d7c72900e8aa76465fa715a9b93b542"
}
]
}
},
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/examples",
"id": "56a6c8dd0d7c72900e8aa76465fa715a9b93b542",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8874670765603421056"
},
{
"key": "scheduler_job_id",
"value": "pigweed/examples.dev.ci-examples-envtest-linux"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[22:17:28.259] Scheduled build:
{
"id": "8709240703449748609",
"builder": {
"project": "pigweed",
"bucket": "examples.dev.ci",
"builder": "examples-envtest-linux"
},
"createdBy": "project:pigweed",
"createTime": "2025-07-15T22:17:27.928137905Z",
"updateTime": "2025-07-15T22:17:27.928137905Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/examples",
"id": "56a6c8dd0d7c72900e8aa76465fa715a9b93b542",
"ref": "refs/heads/main"
}
}
}
[22:17:28.259] Task URL: https://cr-buildbucket.appspot.com/build/8709240703449748609
[22:17:28.259] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:2:0) after 5m46s
[22:17:28.334] Received PubSub notification, asking Buildbucket for the build status
[22:17:28.401] Build status: SCHEDULED
[22:23:14.280] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:2:0)
[22:23:14.322] Build status: SCHEDULED
[22:23:14.322] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:4:0) after 3m3s
[22:26:17.301] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:4:0)
[22:26:17.330] Build status: SCHEDULED
[22:26:17.330] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:5:0) after 3m52s
[22:30:09.414] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:5:0)
[22:30:09.443] Build status: SCHEDULED
[22:30:09.443] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:6:0) after 5m0s
[22:35:09.539] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:6:0)
[22:35:09.558] Build status: SCHEDULED
[22:35:09.558] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:7:0) after 7m53s
[22:43:02.577] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:7:0)
[22:43:02.673] Build status: SCHEDULED
[22:43:02.673] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:8:0) after 8m18s
[22:51:20.719] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:8:0)
[22:51:20.801] Build status: SCHEDULED
[22:51:20.801] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:9:0) after 8m39s
[22:59:59.931] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:9:0)
[22:59:59.970] Build status: SCHEDULED
[22:59:59.970] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:10:0) after 8m28s
[23:08:27.999] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:10:0)
[23:08:28.047] Build status: SCHEDULED
[23:08:28.047] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:11:0) after 2m18s
[23:10:46.069] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:11:0)
[23:10:46.092] Build status: SCHEDULED
[23:10:46.092] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:12:0) after 5m1s
[23:15:47.169] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:12:0)
[23:15:47.188] Build status: SCHEDULED
[23:15:47.189] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:13:0) after 1m24s
[23:17:11.213] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:13:0)
[23:17:11.236] Build status: SCHEDULED
[23:17:11.236] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:14:0) after 5m4s
[23:22:15.256] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:14:0)
[23:22:15.284] Build status: SCHEDULED
[23:22:15.284] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:15:0) after 2m31s
[23:24:46.345] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:15:0)
[23:24:46.376] Build status: SCHEDULED
[23:24:46.376] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:16:0) after 3m8s
[23:27:54.403] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:16:0)
[23:27:54.441] Build status: SCHEDULED
[23:27:54.441] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:17:0) after 3m56s
[23:31:50.464] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:17:0)
[23:31:50.482] Build status: SCHEDULED
[23:31:50.482] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:18:0) after 8m0s
[23:39:50.552] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:18:0)
[23:39:50.582] Build status: SCHEDULED
[23:39:50.582] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:19:0) after 6m46s
[23:46:36.654] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:19:0)
[23:46:36.707] Build status: SCHEDULED
[23:46:36.707] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:20:0) after 4m46s
[23:51:22.810] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:20:0)
[23:51:22.834] Build status: SCHEDULED
[23:51:22.834] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:21:0) after 9m28s
[00:00:50.997] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:21:0)
[00:00:51.015] Build status: SCHEDULED
[00:00:51.015] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:22:0) after 4m38s
[00:05:29.187] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:22:0)
[00:05:29.209] Build status: SCHEDULED
[00:05:29.209] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:23:0) after 3m5s
[00:08:34.234] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:23:0)
[00:08:34.251] Build status: SCHEDULED
[00:08:34.251] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:24:0) after 6m2s
[00:14:36.403] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:24:0)
[00:14:36.461] Build status: SCHEDULED
[00:14:36.461] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:25:0) after 2m54s
[00:17:30.481] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:25:0)
[00:17:30.509] Build status: SCHEDULED
[00:17:30.509] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:26:0) after 9m5s
[00:26:35.511] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:26:0)
[00:26:35.549] Build status: SCHEDULED
[00:26:35.549] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:27:0) after 4m48s
[00:31:23.577] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:27:0)
[00:31:23.617] Build status: SCHEDULED
[00:31:23.617] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:28:0) after 6m47s
[00:38:10.659] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:28:0)
[00:38:10.689] Build status: SCHEDULED
[00:38:10.689] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:29:0) after 2m29s
[00:40:39.729] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:29:0)
[00:40:39.763] Build status: SCHEDULED
[00:40:39.763] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:30:0) after 7m9s
[00:47:48.786] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:30:0)
[00:47:48.802] Build status: SCHEDULED
[00:47:48.802] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:31:0) after 2m54s
[00:50:42.870] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:31:0)
[00:50:42.939] Build status: SCHEDULED
[00:50:42.939] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:32:0) after 7m9s
[00:57:51.955] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:32:0)
[00:57:51.985] Build status: SCHEDULED
[00:57:51.985] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:33:0) after 1m41s
[00:59:33.052] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:33:0)
[00:59:33.124] Build status: SCHEDULED
[00:59:33.125] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:34:0) after 6m55s
[01:06:28.128] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:34:0)
[01:06:28.161] Build status: SCHEDULED
[01:06:28.162] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:35:0) after 1m29s
[01:07:57.176] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:35:0)
[01:07:57.218] Build status: SCHEDULED
[01:07:57.218] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:36:0) after 8m51s
[01:16:48.243] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:36:0)
[01:16:48.276] Build status: SCHEDULED
[01:16:48.276] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:37:0) after 2m44s
[01:19:32.383] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:37:0)
[01:19:32.457] Build status: SCHEDULED
[01:19:32.457] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:38:0) after 2m33s
[01:22:05.574] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:38:0)
[01:22:05.594] Build status: SCHEDULED
[01:22:05.594] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:39:0) after 1m22s
[01:23:27.615] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:39:0)
[01:23:27.791] Build status: SCHEDULED
[01:23:27.791] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:40:0) after 7m25s
[01:30:52.823] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:40:0)
[01:30:52.843] Build status: SCHEDULED
[01:30:52.844] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:41:0) after 4m3s
[01:34:55.903] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:41:0)
[01:34:55.937] Build status: SCHEDULED
[01:34:55.937] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:42:0) after 4m42s
[01:39:38.004] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:42:0)
[01:39:38.024] Build status: SCHEDULED
[01:39:38.024] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:43:0) after 6m31s
[01:46:09.100] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:43:0)
[01:46:09.128] Build status: SCHEDULED
[01:46:09.128] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:44:0) after 7m43s
[01:53:52.194] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:44:0)
[01:53:52.229] Build status: SCHEDULED
[01:53:52.230] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:45:0) after 8m18s
[02:02:10.270] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:45:0)
[02:02:10.326] Build status: SCHEDULED
[02:02:10.326] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:46:0) after 7m8s
[02:09:18.487] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:46:0)
[02:09:18.508] Build status: SCHEDULED
[02:09:18.508] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:47:0) after 5m47s
[02:15:05.501] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:47:0)
[02:15:05.517] Build status: SCHEDULED
[02:15:05.517] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:48:0) after 6m15s
[02:18:27.444] Received PubSub notification, asking Buildbucket for the build status
[02:18:27.465] Build status: STARTED
[02:21:20.534] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:48:0)
[02:21:20.621] Build status: STARTED
[02:21:20.621] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-linux:8874670765603421056:50:0) after 7m45s
[02:24:04.419] Received PubSub notification, asking Buildbucket for the build status
[02:24:04.795] Build:
{
"id": "8709240703449748609",
"builder": {
"project": "pigweed",
"bucket": "examples.dev.ci",
"builder": "examples-envtest-linux"
},
"createdBy": "project:pigweed",
"createTime": "2025-07-15T22:17:27.928137905Z",
"startTime": "2025-07-16T02:18:27.195493924Z",
"endTime": "2025-07-16T02:23:59.821072621Z",
"updateTime": "2025-07-16T02:23:59.821072621Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/examples",
"id": "56a6c8dd0d7c72900e8aa76465fa715a9b93b542",
"ref": "refs/heads/main"
}
}
}
[02:24:04.795] Invocation finished in 4h6m38.304866853s with status SUCCEEDED