[06:51:38.368] New invocation is queued and will start shortly
[06:51:38.368] Triggered by user:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com
[06:51:39.440] Starting the invocation (attempt 1)
[06:51:39.479] Ignoring gitiles_ref tag without the buildset tag
[06:51:39.479] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[06:51:39.479] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[06:51:39.479] Buildbucket request:
{
"requestId": "8979096717339567376",
"builder": {
"project": "infra",
"bucket": "cron",
"builder": "publish_tarball"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8979096717339567376",
"job": "infra/publish_tarball",
"triggers": [
{
"buildbucket": {
"properties": {
"version": "104.0.5071.0"
},
"tags": [
"parent_buildername:publish_tarball_dispatcher",
"user_agent:recipe"
]
},
"id": "6ec8be01-8aec-435c-9589-61d569ebee19",
"title": "publish_tarball_dispatcher/0"
}
]
},
"version": "104.0.5071.0"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8979096717339567376"
},
{
"key": "scheduler_job_id",
"value": "infra/publish_tarball"
},
{
"key": "user_agent",
"value": "luci-scheduler"
},
{
"key": "parent_buildername",
"value": "publish_tarball_dispatcher"
},
{
"key": "user_agent",
"value": "recipe"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[06:51:39.908] Scheduled build:
{
"id": "8813666655452899281",
"builder": {
"project": "infra",
"bucket": "cron",
"builder": "publish_tarball"
},
"createdBy": "project:infra",
"createTime": "2022-05-20T06:51:39.536937734Z",
"updateTime": "2022-05-20T06:51:39.536937734Z",
"status": "SCHEDULED",
"input": {
}
}
[06:51:39.908] Task URL: https://cr-buildbucket.appspot.com/build/8813666655452899281
[06:51:39.908] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:2:0) after 4m8s
[06:51:41.837] Received PubSub notification, asking Buildbucket for the build status
[06:51:41.870] Build status: STARTED
[06:55:47.926] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:2:0)
[06:55:47.959] Build status: STARTED
[06:55:47.960] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:4:0) after 5m44s
[07:01:31.976] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:4:0)
[07:01:32.005] Build status: STARTED
[07:01:32.005] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:5:0) after 8m11s
[07:09:43.123] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:5:0)
[07:09:43.151] Build status: STARTED
[07:09:43.151] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:6:0) after 7m17s
[07:17:00.293] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:6:0)
[07:17:00.320] Build status: STARTED
[07:17:00.320] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:7:0) after 2m48s
[07:19:48.454] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:7:0)
[07:19:48.484] Build status: STARTED
[07:19:48.484] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:8:0) after 8m3s
[07:27:51.622] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:8:0)
[07:27:51.682] Build status: STARTED
[07:27:51.682] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:9:0) after 3m24s
[07:31:15.770] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:9:0)
[07:31:15.840] Build status: STARTED
[07:31:15.840] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:10:0) after 7m57s
[07:39:12.970] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:10:0)
[07:39:13.056] Build status: STARTED
[07:39:13.056] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:11:0) after 9m30s
[07:48:43.175] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:11:0)
[07:48:43.208] Build status: STARTED
[07:48:43.208] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:12:0) after 5m44s
[07:54:27.225] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:12:0)
[07:54:27.252] Build status: STARTED
[07:54:27.252] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:13:0) after 9m56s
[08:04:23.284] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:13:0)
[08:04:23.307] Build status: STARTED
[08:04:23.307] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:14:0) after 2m8s
[08:06:31.424] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:14:0)
[08:06:31.452] Build status: STARTED
[08:06:31.452] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:15:0) after 9m10s
[08:15:41.561] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:15:0)
[08:15:41.589] Build status: STARTED
[08:15:41.589] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:16:0) after 3m8s
[08:18:49.875] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:16:0)
[08:18:49.904] Build status: STARTED
[08:18:49.904] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:17:0) after 5m25s
[08:24:14.880] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:17:0)
[08:24:14.908] Build status: STARTED
[08:24:14.908] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:18:0) after 6m29s
[08:30:43.923] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:18:0)
[08:30:43.959] Build status: STARTED
[08:30:43.959] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:19:0) after 1m7s
[08:31:51.175] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:19:0)
[08:31:51.205] Build status: STARTED
[08:31:51.205] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:20:0) after 3m0s
[08:34:51.222] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:20:0)
[08:34:51.254] Build status: STARTED
[08:34:51.254] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:21:0) after 1m50s
[08:36:41.537] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:21:0)
[08:36:41.571] Build status: STARTED
[08:36:41.571] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:22:0) after 7m58s
[08:44:39.687] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:22:0)
[08:44:39.716] Build status: STARTED
[08:44:39.716] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:23:0) after 9m30s
[08:54:09.765] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:23:0)
[08:54:09.839] Build status: STARTED
[08:54:09.839] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:24:0) after 4m44s
[08:58:53.857] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:24:0)
[08:58:53.901] Build status: STARTED
[08:58:53.901] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:25:0) after 7m15s
[09:06:08.979] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:25:0)
[09:06:09.018] Build status: STARTED
[09:06:09.018] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:26:0) after 5m0s
[09:11:09.046] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:26:0)
[09:11:09.106] Build status: STARTED
[09:11:09.106] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:27:0) after 1m22s
[09:12:31.360] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:27:0)
[09:12:31.391] Build status: STARTED
[09:12:31.391] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:28:0) after 2m37s
[09:15:08.410] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:28:0)
[09:15:08.443] Build status: STARTED
[09:15:08.443] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:29:0) after 7m9s
[09:22:17.721] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:29:0)
[09:22:17.755] Build status: STARTED
[09:22:17.755] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:30:0) after 9m21s
[09:31:38.801] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:30:0)
[09:31:38.840] Build status: STARTED
[09:31:38.840] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:31:0) after 1m43s
[09:33:21.899] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:31:0)
[09:33:21.929] Build status: STARTED
[09:33:21.929] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:32:0) after 4m39s
[09:38:01.090] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:32:0)
[09:38:01.121] Build status: STARTED
[09:38:01.121] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:33:0) after 6m15s
[09:44:16.159] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:33:0)
[09:44:16.206] Build status: STARTED
[09:44:16.206] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:34:0) after 1m6s
[09:45:22.633] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:34:0)
[09:45:22.678] Build status: STARTED
[09:45:22.678] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:35:0) after 9m44s
[09:55:06.695] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:35:0)
[09:55:06.727] Build status: STARTED
[09:55:06.727] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:36:0) after 6m45s
[10:01:51.757] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:36:0)
[10:01:51.786] Build status: STARTED
[10:01:51.786] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:37:0) after 8m28s
[10:10:20.012] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:37:0)
[10:10:20.061] Build status: STARTED
[10:10:20.061] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:38:0) after 4m53s
[10:15:13.216] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:38:0)
[10:15:13.264] Build status: STARTED
[10:15:13.265] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:39:0) after 9m53s
[10:25:06.378] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:39:0)
[10:25:06.411] Build status: STARTED
[10:25:06.411] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:40:0) after 9m49s
[10:34:55.570] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:40:0)
[10:34:55.606] Build status: STARTED
[10:34:55.606] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:41:0) after 7m6s
[10:42:01.698] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:41:0)
[10:42:01.729] Build status: STARTED
[10:42:01.729] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:42:0) after 6m40s
[10:48:41.980] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:42:0)
[10:48:42.011] Build status: STARTED
[10:48:42.011] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:43:0) after 3m13s
[10:51:55.326] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:43:0)
[10:51:55.359] Build status: STARTED
[10:51:55.359] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:44:0) after 2m17s
[10:54:12.706] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:44:0)
[10:54:12.777] Build status: STARTED
[10:54:12.777] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:45:0) after 7m42s
[11:01:54.876] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:45:0)
[11:01:54.910] Build status: STARTED
[11:01:54.910] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:46:0) after 4m43s
[11:06:38.040] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:46:0)
[11:06:38.076] Build status: STARTED
[11:06:38.076] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:47:0) after 7m32s
[11:14:10.006] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:47:0)
[11:14:10.046] Build status: STARTED
[11:14:10.046] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:48:0) after 9m48s
[11:23:58.256] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:48:0)
[11:23:58.292] Build status: STARTED
[11:23:58.292] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:49:0) after 3m24s
[11:27:22.336] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:49:0)
[11:27:22.369] Build status: STARTED
[11:27:22.369] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:50:0) after 8m11s
[11:35:33.393] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:50:0)
[11:35:33.425] Build status: STARTED
[11:35:33.425] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:51:0) after 8m27s
[11:44:00.587] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:51:0)
[11:44:00.654] Build status: STARTED
[11:44:00.654] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:52:0) after 7m9s
[11:51:09.720] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:52:0)
[11:51:09.756] Build status: STARTED
[11:51:09.756] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:53:0) after 3m6s
[11:54:15.772] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:53:0)
[11:54:15.803] Build status: STARTED
[11:54:15.803] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:54:0) after 9m33s
[12:03:48.909] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:54:0)
[12:03:48.940] Build status: STARTED
[12:03:48.940] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:55:0) after 3m1s
[12:06:49.965] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:55:0)
[12:06:49.999] Build status: STARTED
[12:06:49.999] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:56:0) after 3m27s
[12:10:17.083] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:56:0)
[12:10:17.116] Build status: STARTED
[12:10:17.116] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:57:0) after 4m24s
[12:14:41.140] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:57:0)
[12:14:41.193] Build status: STARTED
[12:14:41.193] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:58:0) after 5m53s
[12:20:34.314] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:58:0)
[12:20:34.346] Build status: STARTED
[12:20:34.346] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:59:0) after 5m10s
[12:25:44.333] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:59:0)
[12:25:44.369] Build status: STARTED
[12:25:44.369] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:60:0) after 2m9s
[12:27:53.518] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:60:0)
[12:27:53.559] Build status: STARTED
[12:27:53.559] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:61:0) after 9m19s
[12:37:12.804] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:61:0)
[12:37:12.952] Build status: STARTED
[12:37:12.952] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:62:0) after 9m20s
[12:46:33.064] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:62:0)
[12:46:33.153] Build status: STARTED
[12:46:33.153] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:63:0) after 1m46s
[12:48:19.537] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:63:0)
[12:48:19.572] Build status: STARTED
[12:48:19.572] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:64:0) after 6m20s
[12:54:39.614] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:64:0)
[12:54:39.649] Build status: STARTED
[12:54:39.649] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8979096717339567376:65:0) after 9m7s
[13:01:04.684] Received PubSub notification, asking Buildbucket for the build status
[13:01:04.715] Build:
{
"id": "8813666655452899281",
"builder": {
"project": "infra",
"bucket": "cron",
"builder": "publish_tarball"
},
"createdBy": "project:infra",
"createTime": "2022-05-20T06:51:39.536937734Z",
"startTime": "2022-05-20T06:51:40.482162Z",
"endTime": "2022-05-20T13:01:04.319447989Z",
"updateTime": "2022-05-20T13:01:04.319447989Z",
"status": "SUCCESS",
"input": {
}
}
[13:01:04.715] Invocation finished in 6h9m26.362104108s with status SUCCEEDED