[21:14:06.687] New invocation is queued and will start shortly
[21:14:08.093] Starting the invocation (attempt 1)
[21:14:08.113] Popped buildset tag "buildset:commit/gitiles/pigweed.googlesource.com/pigweed/examples/+/1b7cc0d8295825cef83e66ccbab5bf444400d271"
[21:14:08.113] Popped gitiles commit info from properties and tags
[21:14:08.113] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:14:08.113] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:14:08.113] Buildbucket request:
{
"requestId": "8867970574485511760",
"builder": {
"project": "pigweed",
"bucket": "examples.dev.ci",
"builder": "examples-envtest-mac"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8867970574485511760",
"job": "pigweed/examples.dev.ci-examples-envtest-mac",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://pigweed.googlesource.com/pigweed/examples",
"revision": "1b7cc0d8295825cef83e66ccbab5bf444400d271"
},
"id": "https://pigweed.googlesource.com/pigweed/examples/+/refs/heads/main@1b7cc0d8295825cef83e66ccbab5bf444400d271",
"title": "1b7cc0d8295825cef83e66ccbab5bf444400d271",
"url": "https://pigweed.googlesource.com/pigweed/examples/+/1b7cc0d8295825cef83e66ccbab5bf444400d271"
}
]
}
},
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/examples",
"id": "1b7cc0d8295825cef83e66ccbab5bf444400d271",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8867970574485511760"
},
{
"key": "scheduler_job_id",
"value": "pigweed/examples.dev.ci-examples-envtest-mac"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[21:14:08.667] Scheduled build:
{
"id": "8702540512250811777",
"builder": {
"project": "pigweed",
"bucket": "examples.dev.ci",
"builder": "examples-envtest-mac"
},
"createdBy": "project:pigweed",
"createTime": "2025-09-27T21:14:08.189135432Z",
"updateTime": "2025-09-27T21:14:08.189135432Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/examples",
"id": "1b7cc0d8295825cef83e66ccbab5bf444400d271",
"ref": "refs/heads/main"
}
}
}
[21:14:08.667] Task URL: https://cr-buildbucket.appspot.com/build/8702540512250811777
[21:14:08.667] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:2:0) after 6m55s
[21:14:09.615] Received PubSub notification, asking Buildbucket for the build status
[21:14:09.778] Build status: SCHEDULED
[21:21:03.681] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:2:0)
[21:21:03.712] Build status: SCHEDULED
[21:21:03.712] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:4:0) after 2m1s
[21:23:04.723] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:4:0)
[21:23:04.736] Build status: SCHEDULED
[21:23:04.736] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:5:0) after 1m48s
[21:24:52.723] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:5:0)
[21:24:52.780] Build status: SCHEDULED
[21:24:52.780] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:6:0) after 5m31s
[21:30:23.927] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:6:0)
[21:30:23.983] Build status: SCHEDULED
[21:30:23.983] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:7:0) after 2m8s
[21:32:31.995] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:7:0)
[21:32:32.079] Build status: SCHEDULED
[21:32:32.079] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:8:0) after 6m10s
[21:38:42.091] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:8:0)
[21:38:42.111] Build status: SCHEDULED
[21:38:42.111] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:9:0) after 3m49s
[21:42:31.128] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:9:0)
[21:42:31.148] Build status: SCHEDULED
[21:42:31.148] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:10:0) after 1m14s
[21:43:45.180] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:10:0)
[21:43:45.439] Build status: SCHEDULED
[21:43:45.439] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:11:0) after 4m58s
[21:48:43.453] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:11:0)
[21:48:43.482] Build status: SCHEDULED
[21:48:43.482] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:12:0) after 5m14s
[21:53:57.700] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:12:0)
[21:53:57.718] Build status: SCHEDULED
[21:53:57.718] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:13:0) after 2m35s
[21:56:32.733] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:13:0)
[21:56:32.751] Build status: SCHEDULED
[21:56:32.751] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:14:0) after 5m59s
[22:02:31.878] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:14:0)
[22:02:31.897] Build status: SCHEDULED
[22:02:31.897] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:15:0) after 5m56s
[22:08:27.911] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:15:0)
[22:08:27.925] Build status: SCHEDULED
[22:08:27.925] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:16:0) after 3m56s
[22:12:24.126] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:16:0)
[22:12:24.143] Build status: SCHEDULED
[22:12:24.143] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:17:0) after 8m32s
[22:20:56.109] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:17:0)
[22:20:56.127] Build status: SCHEDULED
[22:20:56.127] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:18:0) after 1m18s
[22:22:14.214] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:18:0)
[22:22:14.262] Build status: SCHEDULED
[22:22:14.262] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:19:0) after 1m55s
[22:24:09.321] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:19:0)
[22:24:09.335] Build status: SCHEDULED
[22:24:09.335] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:20:0) after 3m24s
[22:27:33.349] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:20:0)
[22:27:33.421] Build status: SCHEDULED
[22:27:33.421] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:21:0) after 5m22s
[22:32:55.557] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:21:0)
[22:32:55.576] Build status: SCHEDULED
[22:32:55.577] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:22:0) after 2m51s
[22:35:46.598] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:22:0)
[22:35:46.613] Build status: SCHEDULED
[22:35:46.613] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:23:0) after 5m12s
[22:40:58.629] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:23:0)
[22:40:58.649] Build status: SCHEDULED
[22:40:58.649] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:24:0) after 5m22s
[22:46:21.005] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:24:0)
[22:46:21.065] Build status: SCHEDULED
[22:46:21.065] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:25:0) after 5m31s
[22:51:52.213] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:25:0)
[22:51:52.232] Build status: SCHEDULED
[22:51:52.232] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:26:0) after 8m48s
[23:00:40.315] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:26:0)
[23:00:40.426] Build status: SCHEDULED
[23:00:40.426] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:27:0) after 9m21s
[23:10:01.444] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:27:0)
[23:10:01.459] Build status: SCHEDULED
[23:10:01.459] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:28:0) after 6m54s
[23:16:55.641] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:28:0)
[23:16:55.658] Build status: SCHEDULED
[23:16:55.658] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:29:0) after 7m51s
[23:24:46.998] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:29:0)
[23:24:47.049] Build status: SCHEDULED
[23:24:47.049] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:30:0) after 3m0s
[23:27:47.758] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:30:0)
[23:27:47.791] Build status: SCHEDULED
[23:27:47.791] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:31:0) after 2m28s
[23:30:15.805] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:31:0)
[23:30:15.829] Build status: SCHEDULED
[23:30:15.829] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:32:0) after 2m12s
[23:32:27.933] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:32:0)
[23:32:27.952] Build status: SCHEDULED
[23:32:27.952] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:33:0) after 4m5s
[23:36:33.257] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:33:0)
[23:36:33.278] Build status: SCHEDULED
[23:36:33.278] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:34:0) after 5m42s
[23:42:15.268] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:34:0)
[23:42:15.344] Build status: SCHEDULED
[23:42:15.344] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:35:0) after 8m8s
[23:50:23.360] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:35:0)
[23:50:23.374] Build status: SCHEDULED
[23:50:23.374] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:36:0) after 7m7s
[23:57:30.446] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:36:0)
[23:57:30.471] Build status: SCHEDULED
[23:57:30.471] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:37:0) after 2m46s
[00:00:16.486] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:37:0)
[00:00:16.507] Build status: SCHEDULED
[00:00:16.507] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:38:0) after 8m14s
[00:08:30.735] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:38:0)
[00:08:30.753] Build status: SCHEDULED
[00:08:30.753] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:39:0) after 4m29s
[00:12:59.871] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:39:0)
[00:12:59.893] Build status: SCHEDULED
[00:12:59.893] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:40:0) after 9m53s
[00:22:52.912] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:40:0)
[00:22:52.927] Build status: SCHEDULED
[00:22:52.927] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:41:0) after 2m18s
[00:25:11.121] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:41:0)
[00:25:11.177] Build status: SCHEDULED
[00:25:11.177] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:42:0) after 6m35s
[00:31:46.198] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:42:0)
[00:31:46.228] Build status: SCHEDULED
[00:31:46.228] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:43:0) after 8m36s
[00:40:22.313] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:43:0)
[00:40:22.327] Build status: SCHEDULED
[00:40:22.327] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:44:0) after 9m42s
[00:50:04.356] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:44:0)
[00:50:04.375] Build status: SCHEDULED
[00:50:04.375] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:45:0) after 7m32s
[00:57:36.665] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:45:0)
[00:57:36.685] Build status: SCHEDULED
[00:57:36.685] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:46:0) after 4m50s
[01:02:26.928] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:46:0)
[01:02:26.949] Build status: SCHEDULED
[01:02:26.949] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:47:0) after 7m7s
[01:09:34.155] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:47:0)
[01:09:34.170] Build status: SCHEDULED
[01:09:34.170] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:48:0) after 6m19s
[01:13:30.502] Received PubSub notification, asking Buildbucket for the build status
[01:13:30.523] Build status: STARTED
[01:15:53.186] Handling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:48:0)
[01:15:53.208] Build status: STARTED
[01:15:53.208] Scheduling timer "check-buildbucket-build-status" (pigweed/examples.dev.ci-examples-envtest-mac:8867970574485511760:50:0) after 8m35s
[01:23:33.740] Received PubSub notification, asking Buildbucket for the build status
[01:23:33.756] Build:
{
"id": "8702540512250811777",
"builder": {
"project": "pigweed",
"bucket": "examples.dev.ci",
"builder": "examples-envtest-mac"
},
"createdBy": "project:pigweed",
"createTime": "2025-09-27T21:14:08.189135432Z",
"startTime": "2025-09-28T01:13:29.513279027Z",
"endTime": "2025-09-28T01:23:33.524521559Z",
"updateTime": "2025-09-28T01:23:33.524521559Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/examples",
"id": "1b7cc0d8295825cef83e66ccbab5bf444400d271",
"ref": "refs/heads/main"
}
}
}
[01:23:33.756] Invocation finished in 4h9m27.082801201s with status SUCCEEDED