[03:34:01.288] New invocation is queued and will start shortly
[03:34:02.403] Starting the invocation (attempt 1)
[03:34:02.430] Popped buildset tag "buildset:commit/gitiles/pigweed.googlesource.com/pigweed/experimental/+/808717e17fce55ccc99e6606ce0c9a8e8ca57bc3"
[03:34:02.430] Popped gitiles commit info from properties and tags
[03:34:02.430] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[03:34:02.430] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[03:34:02.430] Buildbucket request:
{
"requestId": "8897481283652718880",
"builder": {
"project": "pigweed",
"bucket": "experimental.dev.ci",
"builder": "experimental-envtest"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8897481283652718880",
"job": "pigweed/experimental.dev.ci-experimental-envtest",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://pigweed.googlesource.com/pigweed/experimental",
"revision": "808717e17fce55ccc99e6606ce0c9a8e8ca57bc3"
},
"id": "https://pigweed.googlesource.com/pigweed/experimental/+/refs/heads/main@808717e17fce55ccc99e6606ce0c9a8e8ca57bc3",
"title": "808717e17fce55ccc99e6606ce0c9a8e8ca57bc3",
"url": "https://pigweed.googlesource.com/pigweed/experimental/+/808717e17fce55ccc99e6606ce0c9a8e8ca57bc3"
}
]
}
},
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/experimental",
"id": "808717e17fce55ccc99e6606ce0c9a8e8ca57bc3",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8897481283652718880"
},
{
"key": "scheduler_job_id",
"value": "pigweed/experimental.dev.ci-experimental-envtest"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[03:34:02.827] Scheduled build:
{
"id": "8732051221745276369",
"builder": {
"project": "pigweed",
"bucket": "experimental.dev.ci",
"builder": "experimental-envtest"
},
"createdBy": "project:pigweed",
"createTime": "2024-11-06T03:34:02.485804280Z",
"updateTime": "2024-11-06T03:34:02.485804280Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/experimental",
"id": "808717e17fce55ccc99e6606ce0c9a8e8ca57bc3",
"ref": "refs/heads/main"
}
}
}
[03:34:02.827] Task URL: https://cr-buildbucket.appspot.com/build/8732051221745276369
[03:34:02.827] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:2:0) after 5m58s
[03:34:03.261] Received PubSub notification, asking Buildbucket for the build status
[03:34:03.316] Build status: SCHEDULED
[03:40:00.841] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:2:0)
[03:40:00.954] Build status: SCHEDULED
[03:40:00.954] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:4:0) after 1m51s
[03:41:51.972] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:4:0)
[03:41:52.046] Build status: SCHEDULED
[03:41:52.046] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:5:0) after 6m38s
[03:48:30.113] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:5:0)
[03:48:30.154] Build status: SCHEDULED
[03:48:30.154] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:6:0) after 7m52s
[03:56:22.339] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:6:0)
[03:56:22.370] Build status: SCHEDULED
[03:56:22.370] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:7:0) after 1m13s
[03:57:35.546] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:7:0)
[03:57:35.578] Build status: SCHEDULED
[03:57:35.578] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:8:0) after 6m11s
[04:03:46.682] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:8:0)
[04:03:46.712] Build status: SCHEDULED
[04:03:46.712] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:9:0) after 3m43s
[04:07:29.738] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:9:0)
[04:07:29.756] Build status: SCHEDULED
[04:07:29.756] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:10:0) after 8m11s
[04:15:40.819] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:10:0)
[04:15:40.845] Build status: SCHEDULED
[04:15:40.845] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:11:0) after 1m31s
[04:17:11.859] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:11:0)
[04:17:11.885] Build status: SCHEDULED
[04:17:11.885] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:12:0) after 2m7s
[04:19:19.001] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:12:0)
[04:19:19.037] Build status: SCHEDULED
[04:19:19.037] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:13:0) after 4m19s
[04:23:38.203] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:13:0)
[04:23:38.230] Build status: SCHEDULED
[04:23:38.230] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:14:0) after 4m34s
[04:28:12.328] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:14:0)
[04:28:12.357] Build status: SCHEDULED
[04:28:12.357] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:15:0) after 1m31s
[04:29:43.409] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:15:0)
[04:29:43.438] Build status: SCHEDULED
[04:29:43.438] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:16:0) after 4m7s
[04:33:50.462] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:16:0)
[04:33:50.494] Build status: SCHEDULED
[04:33:50.494] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:17:0) after 3m43s
[04:37:33.510] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:17:0)
[04:37:33.543] Build status: SCHEDULED
[04:37:33.543] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:18:0) after 1m38s
[04:39:11.573] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:18:0)
[04:39:11.591] Build status: SCHEDULED
[04:39:11.591] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:19:0) after 4m3s
[04:43:14.610] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:19:0)
[04:43:14.632] Build status: SCHEDULED
[04:43:14.632] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:20:0) after 2m51s
[04:46:05.747] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:20:0)
[04:46:05.772] Build status: SCHEDULED
[04:46:05.772] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:21:0) after 8m18s
[04:54:23.819] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:21:0)
[04:54:23.852] Build status: SCHEDULED
[04:54:23.852] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:22:0) after 5m4s
[04:59:27.871] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:22:0)
[04:59:27.919] Build status: SCHEDULED
[04:59:27.919] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:23:0) after 8m55s
[05:08:23.157] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:23:0)
[05:08:23.182] Build status: SCHEDULED
[05:08:23.182] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:24:0) after 1m9s
[05:09:32.281] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:24:0)
[05:09:32.312] Build status: SCHEDULED
[05:09:32.312] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:25:0) after 3m56s
[05:13:28.348] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:25:0)
[05:13:28.372] Build status: SCHEDULED
[05:13:28.372] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:26:0) after 3m55s
[05:17:23.527] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:26:0)
[05:17:23.593] Build status: SCHEDULED
[05:17:23.593] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:27:0) after 3m54s
[05:21:17.611] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:27:0)
[05:21:17.684] Build status: SCHEDULED
[05:21:17.684] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:28:0) after 3m19s
[05:24:36.807] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:28:0)
[05:24:36.825] Build status: SCHEDULED
[05:24:36.825] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:29:0) after 9m37s
[05:34:14.989] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:29:0)
[05:34:15.006] Build status: SCHEDULED
[05:34:15.006] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:30:0) after 4m56s
[05:39:11.008] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:30:0)
[05:39:11.065] Build status: SCHEDULED
[05:39:11.065] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:31:0) after 3m51s
[05:43:02.084] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:31:0)
[05:43:02.128] Build status: SCHEDULED
[05:43:02.128] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:32:0) after 7m25s
[05:50:27.148] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:32:0)
[05:50:27.169] Build status: SCHEDULED
[05:50:27.169] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:33:0) after 1m42s
[05:52:09.187] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:33:0)
[05:52:09.244] Build status: SCHEDULED
[05:52:09.244] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:34:0) after 7m10s
[05:59:19.269] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:34:0)
[05:59:19.293] Build status: SCHEDULED
[05:59:19.293] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:35:0) after 3m9s
[06:02:28.313] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:35:0)
[06:02:28.339] Build status: SCHEDULED
[06:02:28.339] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:36:0) after 7m59s
[06:10:27.354] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:36:0)
[06:10:27.372] Build status: SCHEDULED
[06:10:27.372] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:37:0) after 9m27s
[06:19:54.390] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:37:0)
[06:19:54.575] Build status: SCHEDULED
[06:19:54.576] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:38:0) after 4m34s
[06:24:28.661] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:38:0)
[06:24:28.683] Build status: SCHEDULED
[06:24:28.683] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:39:0) after 2m54s
[06:27:22.746] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:39:0)
[06:27:22.787] Build status: SCHEDULED
[06:27:22.787] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:40:0) after 2m8s
[06:29:15.336] Received PubSub notification, asking Buildbucket for the build status
[06:29:15.363] Build status: STARTED
[06:29:30.845] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:40:0)
[06:29:30.865] Build status: STARTED
[06:29:30.865] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:42:0) after 3m25s
[06:32:56.142] Handling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:42:0)
[06:32:56.173] Build status: STARTED
[06:32:56.173] Scheduling timer "check-buildbucket-build-status" (pigweed/experimental.dev.ci-experimental-envtest:8897481283652718880:43:0) after 4m4s
[06:33:52.721] Received PubSub notification, asking Buildbucket for the build status
[06:33:52.741] Build:
{
"id": "8732051221745276369",
"builder": {
"project": "pigweed",
"bucket": "experimental.dev.ci",
"builder": "experimental-envtest"
},
"createdBy": "project:pigweed",
"createTime": "2024-11-06T03:34:02.485804280Z",
"startTime": "2024-11-06T06:29:15.136376964Z",
"endTime": "2024-11-06T06:33:52.326169048Z",
"updateTime": "2024-11-06T06:33:52.326169048Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "pigweed.googlesource.com",
"project": "pigweed/experimental",
"id": "808717e17fce55ccc99e6606ce0c9a8e8ca57bc3",
"ref": "refs/heads/main"
}
}
}
[06:33:52.741] Invocation finished in 2h59m51.457704604s with status SUCCEEDED