[20:31:14.841] New invocation is queued and will start shortly
[20:31:15.969] Starting the invocation (attempt 1)
[20:31:16.035] Popped buildset tag "buildset:commit/gitiles/pigweed.googlesource.com/pigweed/pigweed/+/afef6c3c7de6f5a84465aad469a89556d0b34fbb"
[20:31:16.035] Popped gitiles commit info from properties and tags
[20:31:16.035] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[20:31:16.035] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[20:31:16.035] Buildbucket request:
{
"requestId": "8917529811891777472",
"builder": {
"project": "pigweed",
"bucket": "pigweed.dev.ci",
"builder": "pigweed-mac-x86-zephyr"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8917529811891777472",
"job": "pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://pigweed.googlesource.com/pigweed/pigweed",
"revision": "afef6c3c7de6f5a84465aad469a89556d0b34fbb"
},
"id": "https://pigweed.googlesource.com/pigweed/pigweed/+/refs/heads/main@afef6c3c7de6f5a84465aad469a89556d0b34fbb",
"title": "afef6c3c7de6f5a84465aad469a89556d0b34fbb",
"url": "https://pigweed.googlesource.com/pigweed/pigweed/+/afef6c3c7de6f5a84465aad469a89556d0b34fbb"
}
]
}
},
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/pigweed",
"id": "afef6c3c7de6f5a84465aad469a89556d0b34fbb",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8917529811891777472"
},
{
"key": "scheduler_job_id",
"value": "pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[20:31:16.712] Scheduled build:
{
"id": "8752099749868192641",
"builder": {
"project": "pigweed",
"bucket": "pigweed.dev.ci",
"builder": "pigweed-mac-x86-zephyr"
},
"createdBy": "project:pigweed",
"createTime": "2024-03-29T20:31:16.133942356Z",
"updateTime": "2024-03-29T20:31:16.133942356Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/pigweed",
"id": "afef6c3c7de6f5a84465aad469a89556d0b34fbb",
"ref": "refs/heads/main"
}
}
}
[20:31:16.712] Task URL: https://cr-buildbucket.appspot.com/build/8752099749868192641
[20:31:16.712] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:2:0) after 1m31s
[20:31:17.442] Received PubSub notification, asking Buildbucket for the build status
[20:31:17.460] Build status: SCHEDULED
[20:32:47.755] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:2:0)
[20:32:47.772] Build status: SCHEDULED
[20:32:47.772] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:4:0) after 9m58s
[20:42:45.778] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:4:0)
[20:42:45.822] Build status: SCHEDULED
[20:42:45.822] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:5:0) after 4m28s
[20:47:13.873] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:5:0)
[20:47:13.937] Build status: SCHEDULED
[20:47:13.937] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:6:0) after 1m28s
[20:48:41.950] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:6:0)
[20:48:41.981] Build status: SCHEDULED
[20:48:41.981] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:7:0) after 6m25s
[20:55:07.009] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:7:0)
[20:55:07.029] Build status: SCHEDULED
[20:55:07.029] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:8:0) after 3m18s
[20:58:25.070] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:8:0)
[20:58:25.098] Build status: SCHEDULED
[20:58:25.098] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:9:0) after 7m24s
[21:05:49.104] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:9:0)
[21:05:49.129] Build status: SCHEDULED
[21:05:49.129] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:10:0) after 5m19s
[21:11:08.242] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:10:0)
[21:11:08.269] Build status: SCHEDULED
[21:11:08.269] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:11:0) after 5m40s
[21:16:48.290] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:11:0)
[21:16:48.306] Build status: SCHEDULED
[21:16:48.306] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:12:0) after 6m37s
[21:23:25.352] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:12:0)
[21:23:25.392] Build status: SCHEDULED
[21:23:25.392] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:13:0) after 7m55s
[21:31:20.405] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:13:0)
[21:31:20.424] Build status: SCHEDULED
[21:31:20.424] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:14:0) after 4m10s
[21:35:30.446] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:14:0)
[21:35:30.463] Build status: SCHEDULED
[21:35:30.463] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:15:0) after 7m37s
[21:43:08.763] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:15:0)
[21:43:08.846] Build status: SCHEDULED
[21:43:08.846] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:16:0) after 1m45s
[21:44:53.893] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:16:0)
[21:44:53.912] Build status: SCHEDULED
[21:44:53.912] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:17:0) after 4m32s
[21:49:26.011] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:17:0)
[21:49:26.039] Build status: SCHEDULED
[21:49:26.039] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:18:0) after 2m58s
[21:52:24.109] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:18:0)
[21:52:24.139] Build status: SCHEDULED
[21:52:24.139] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:19:0) after 7m15s
[21:59:39.342] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:19:0)
[21:59:39.378] Build status: SCHEDULED
[21:59:39.378] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:20:0) after 4m48s
[22:04:27.366] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:20:0)
[22:04:27.398] Build status: SCHEDULED
[22:04:27.398] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:21:0) after 5m20s
[22:09:47.463] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:21:0)
[22:09:47.483] Build status: SCHEDULED
[22:09:47.483] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:22:0) after 7m7s
[22:16:54.532] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:22:0)
[22:16:54.604] Build status: SCHEDULED
[22:16:54.604] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:23:0) after 9m18s
[22:26:12.626] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:23:0)
[22:26:12.708] Build status: SCHEDULED
[22:26:12.708] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:24:0) after 9m11s
[22:35:23.730] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:24:0)
[22:35:23.751] Build status: SCHEDULED
[22:35:23.751] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:25:0) after 7m44s
[22:43:07.835] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:25:0)
[22:43:07.922] Build status: SCHEDULED
[22:43:07.922] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:26:0) after 9m2s
[22:52:09.943] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:26:0)
[22:52:09.975] Build status: SCHEDULED
[22:52:09.975] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:27:0) after 5m59s
[22:58:09.101] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:27:0)
[22:58:09.123] Build status: SCHEDULED
[22:58:09.123] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:28:0) after 7m53s
[23:06:02.426] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:28:0)
[23:06:02.525] Build status: SCHEDULED
[23:06:02.525] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:29:0) after 2m47s
[23:08:49.618] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:29:0)
[23:08:49.676] Build status: SCHEDULED
[23:08:49.676] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:30:0) after 2m36s
[23:11:25.908] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:30:0)
[23:11:25.929] Build status: SCHEDULED
[23:11:25.929] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:31:0) after 8m34s
[23:19:59.961] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:31:0)
[23:19:59.980] Build status: SCHEDULED
[23:19:59.980] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:32:0) after 7m40s
[23:27:40.561] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:32:0)
[23:27:40.581] Build status: SCHEDULED
[23:27:40.581] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:33:0) after 2m47s
[23:30:27.952] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:33:0)
[23:30:28.007] Build status: SCHEDULED
[23:30:28.008] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:34:0) after 5m31s
[23:35:59.035] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:34:0)
[23:35:59.086] Build status: SCHEDULED
[23:35:59.086] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:35:0) after 8m1s
[23:44:00.106] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:35:0)
[23:44:00.144] Build status: SCHEDULED
[23:44:00.144] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:36:0) after 1m35s
[23:45:35.138] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:36:0)
[23:45:35.176] Build status: SCHEDULED
[23:45:35.176] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:37:0) after 4m26s
[23:50:01.241] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:37:0)
[23:50:01.268] Build status: SCHEDULED
[23:50:01.268] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:38:0) after 4m24s
[23:54:25.286] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:38:0)
[23:54:25.307] Build status: SCHEDULED
[23:54:25.307] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:39:0) after 1m37s
[23:56:02.315] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:39:0)
[23:56:02.332] Build status: SCHEDULED
[23:56:02.332] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:40:0) after 5m6s
[00:01:08.583] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:40:0)
[00:01:08.620] Build status: SCHEDULED
[00:01:08.620] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:41:0) after 3m25s
[00:04:33.638] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:41:0)
[00:04:33.655] Build status: SCHEDULED
[00:04:33.655] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:42:0) after 8m5s
[00:11:42.320] Received PubSub notification, asking Buildbucket for the build status
[00:11:42.338] Build status: STARTED
[00:12:38.746] Handling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:42:0)
[00:12:38.774] Build status: STARTED
[00:12:38.774] Scheduling timer "check-buildbucket-build-status" (pigweed/pigweed.dev.ci-pigweed-mac-x86-zephyr:8917529811891777472:44:0) after 9m24s
[00:19:29.556] Received PubSub notification, asking Buildbucket for the build status
[00:19:29.583] Build:
{
"id": "8752099749868192641",
"builder": {
"project": "pigweed",
"bucket": "pigweed.dev.ci",
"builder": "pigweed-mac-x86-zephyr"
},
"createdBy": "project:pigweed",
"createTime": "2024-03-29T20:31:16.133942356Z",
"startTime": "2024-03-30T00:11:29.889949676Z",
"endTime": "2024-03-30T00:19:28.939922Z",
"updateTime": "2024-03-30T00:19:28.939922Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/pigweed",
"id": "afef6c3c7de6f5a84465aad469a89556d0b34fbb",
"ref": "refs/heads/main"
}
}
}
[00:19:29.583] Invocation finished in 3h48m14.763455172s with status SUCCEEDED