[07:30:44.647] New invocation is queued and will start shortly
[07:30:44.647] Triggered by user:chromium-tarball-builder@chops-service-accounts.iam.gserviceaccount.com
[07:30:45.739] Starting the invocation (attempt 1)
[07:30:45.775] Ignoring gitiles_ref tag without the buildset tag
[07:30:45.775] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[07:30:45.776] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[07:30:45.776] Buildbucket request:
{
"requestId": "8981449778213007424",
"builder": {
"project": "infra",
"bucket": "cron",
"builder": "publish_tarball"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8981449778213007424",
"job": "infra/publish_tarball",
"triggers": [
{
"buildbucket": {
"properties": {
"version": "103.0.5022.0"
},
"tags": [
"parent_buildername:publish_tarball_dispatcher",
"user_agent:recipe"
]
},
"id": "79ab2102-fbfe-4d05-8c5d-15bb1dc82820",
"title": "publish_tarball_dispatcher/0"
}
]
},
"version": "103.0.5022.0"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8981449778213007424"
},
{
"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"
}
}
[07:30:46.159] Scheduled build:
{
"id": "8816019716294804849",
"builder": {
"project": "infra",
"bucket": "cron",
"builder": "publish_tarball"
},
"createdBy": "project:infra",
"createTime": "2022-04-24T07:30:45.846184671Z",
"updateTime": "2022-04-24T07:30:45.846184671Z",
"status": "SCHEDULED",
"input": {
}
}
[07:30:46.159] Task URL: https://cr-buildbucket.appspot.com/build/8816019716294804849
[07:30:46.159] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:2:0) after 4m42s
[07:35:28.174] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:2:0)
[07:35:28.203] Build status: SCHEDULED
[07:35:28.203] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:3:0) after 8m37s
[07:44:05.222] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:3:0)
[07:44:05.268] Build status: SCHEDULED
[07:44:05.268] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:4:0) after 2m41s
[07:46:46.288] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:4:0)
[07:46:46.318] Build status: SCHEDULED
[07:46:46.318] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:5:0) after 7m1s
[07:53:47.445] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:5:0)
[07:53:47.477] Build status: SCHEDULED
[07:53:47.477] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:6:0) after 4m15s
[07:58:02.793] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:6:0)
[07:58:02.822] Build status: SCHEDULED
[07:58:02.822] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:7:0) after 6m25s
[08:04:27.837] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:7:0)
[08:04:27.880] Build status: SCHEDULED
[08:04:27.880] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:8:0) after 5m14s
[08:09:41.894] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:8:0)
[08:09:41.923] Build status: SCHEDULED
[08:09:41.923] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:9:0) after 3m54s
[08:10:14.769] Received PubSub notification, asking Buildbucket for the build status
[08:10:14.799] Build status: STARTED
[08:13:36.190] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:9:0)
[08:13:36.270] Build status: STARTED
[08:13:36.270] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:11:0) after 9m20s
[08:22:56.488] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:11:0)
[08:22:56.546] Build status: STARTED
[08:22:56.546] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:12:0) after 6m47s
[08:29:43.598] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:12:0)
[08:29:43.627] Build status: STARTED
[08:29:43.627] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:13:0) after 8m14s
[08:37:57.740] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:13:0)
[08:37:57.862] Build status: STARTED
[08:37:57.862] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:14:0) after 1m12s
[08:39:09.907] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:14:0)
[08:39:09.984] Build status: STARTED
[08:39:09.984] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:15:0) after 5m6s
[08:44:16.286] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:15:0)
[08:44:16.322] Build status: STARTED
[08:44:16.322] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:16:0) after 4m45s
[08:49:01.463] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:16:0)
[08:49:01.495] Build status: STARTED
[08:49:01.495] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:17:0) after 1m34s
[08:50:35.509] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:17:0)
[08:50:35.548] Build status: STARTED
[08:50:35.548] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:18:0) after 5m17s
[08:55:52.802] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:18:0)
[08:55:52.835] Build status: STARTED
[08:55:52.835] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:19:0) after 8m2s
[09:03:54.892] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:19:0)
[09:03:54.926] Build status: STARTED
[09:03:54.926] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:20:0) after 8m49s
[09:12:43.944] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:20:0)
[09:12:43.976] Build status: STARTED
[09:12:43.976] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:21:0) after 9m33s
[09:22:17.168] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:21:0)
[09:22:17.205] Build status: STARTED
[09:22:17.205] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:22:0) after 9m43s
[09:32:00.283] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:22:0)
[09:32:00.313] Build status: STARTED
[09:32:00.313] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:23:0) after 8m18s
[09:40:18.407] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:23:0)
[09:40:18.432] Build status: STARTED
[09:40:18.432] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:24:0) after 2m36s
[09:42:54.470] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:24:0)
[09:42:54.500] Build status: STARTED
[09:42:54.500] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:25:0) after 1m39s
[09:44:33.514] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:25:0)
[09:44:33.548] Build status: STARTED
[09:44:33.548] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:26:0) after 6m50s
[09:51:23.809] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:26:0)
[09:51:23.848] Build status: STARTED
[09:51:23.848] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:27:0) after 6m34s
[09:57:57.869] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:27:0)
[09:57:57.896] Build status: STARTED
[09:57:57.896] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:28:0) after 7m31s
[10:05:28.944] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:28:0)
[10:05:28.976] Build status: STARTED
[10:05:28.976] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:29:0) after 8m36s
[10:14:05.298] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:29:0)
[10:14:05.330] Build status: STARTED
[10:14:05.330] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:30:0) after 7m14s
[10:21:19.348] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:30:0)
[10:21:19.469] Build status: STARTED
[10:21:19.469] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:31:0) after 4m15s
[10:25:34.616] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:31:0)
[10:25:34.646] Build status: STARTED
[10:25:34.646] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:32:0) after 9m14s
[10:34:48.732] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:32:0)
[10:34:48.773] Build status: STARTED
[10:34:48.773] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:33:0) after 7m16s
[10:42:04.791] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:33:0)
[10:42:04.840] Build status: STARTED
[10:42:04.840] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:34:0) after 2m23s
[10:44:27.857] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:34:0)
[10:44:27.895] Build status: STARTED
[10:44:27.895] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:35:0) after 1m3s
[10:45:30.946] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:35:0)
[10:45:30.990] Build status: STARTED
[10:45:30.990] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:36:0) after 5m24s
[10:50:54.975] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:36:0)
[10:50:55.004] Build status: STARTED
[10:50:55.004] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:37:0) after 9m34s
[11:00:29.035] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:37:0)
[11:00:29.067] Build status: STARTED
[11:00:29.067] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:38:0) after 4m19s
[11:04:48.091] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:38:0)
[11:04:48.125] Build status: STARTED
[11:04:48.125] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:39:0) after 8m17s
[11:13:05.240] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:39:0)
[11:13:05.276] Build status: STARTED
[11:13:05.276] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:40:0) after 7m43s
[11:20:48.367] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:40:0)
[11:20:48.398] Build status: STARTED
[11:20:48.398] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:41:0) after 4m27s
[11:25:15.415] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:41:0)
[11:25:15.445] Build status: STARTED
[11:25:15.445] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:42:0) after 5m49s
[11:31:04.464] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:42:0)
[11:31:04.496] Build status: STARTED
[11:31:04.496] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:43:0) after 6m3s
[11:37:07.518] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:43:0)
[11:37:07.583] Build status: STARTED
[11:37:07.583] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:44:0) after 9m25s
[11:46:32.602] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:44:0)
[11:46:32.630] Build status: STARTED
[11:46:32.630] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:45:0) after 8m39s
[11:55:11.684] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:45:0)
[11:55:11.746] Build status: STARTED
[11:55:11.746] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:46:0) after 1m4s
[11:56:15.881] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:46:0)
[11:56:15.910] Build status: STARTED
[11:56:15.910] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:47:0) after 6m21s
[12:02:36.929] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:47:0)
[12:02:36.965] Build status: STARTED
[12:02:36.965] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:48:0) after 8m19s
[12:10:56.152] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:48:0)
[12:10:56.181] Build status: STARTED
[12:10:56.182] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:49:0) after 2m9s
[12:13:05.201] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:49:0)
[12:13:05.231] Build status: STARTED
[12:13:05.231] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:50:0) after 3m49s
[12:16:54.249] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:50:0)
[12:16:54.286] Build status: STARTED
[12:16:54.286] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:51:0) after 4m56s
[12:21:50.305] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:51:0)
[12:21:50.350] Build status: STARTED
[12:21:50.350] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:52:0) after 6m13s
[12:28:03.380] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:52:0)
[12:28:03.433] Build status: STARTED
[12:28:03.433] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:53:0) after 9m31s
[12:37:34.544] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:53:0)
[12:37:34.590] Build status: STARTED
[12:37:34.590] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:54:0) after 6m29s
[12:44:03.610] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:54:0)
[12:44:03.688] Build status: STARTED
[12:44:03.688] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:55:0) after 4m42s
[12:48:45.821] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:55:0)
[12:48:45.856] Build status: STARTED
[12:48:45.856] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:56:0) after 5m6s
[12:53:51.966] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:56:0)
[12:53:52.001] Build status: STARTED
[12:53:52.001] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:57:0) after 5m49s
[12:59:41.024] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:57:0)
[12:59:41.072] Build status: STARTED
[12:59:41.072] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:58:0) after 2m17s
[13:01:58.110] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:58:0)
[13:01:58.145] Build status: STARTED
[13:01:58.145] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:59:0) after 7m56s
[13:09:54.183] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:59:0)
[13:09:54.217] Build status: STARTED
[13:09:54.217] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:60:0) after 9m45s
[13:19:39.237] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:60:0)
[13:19:39.269] Build status: STARTED
[13:19:39.269] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:61:0) after 3m22s
[13:23:01.315] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:61:0)
[13:23:01.370] Build status: STARTED
[13:23:01.370] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:62:0) after 8m52s
[13:31:53.616] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:62:0)
[13:31:53.645] Build status: STARTED
[13:31:53.645] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:63:0) after 2m38s
[13:34:31.803] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:63:0)
[13:34:31.840] Build status: STARTED
[13:34:31.840] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:64:0) after 1m53s
[13:36:25.662] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:64:0)
[13:36:25.874] Build status: STARTED
[13:36:25.874] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:65:0) after 6m57s
[13:43:22.881] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:65:0)
[13:43:22.922] Build status: STARTED
[13:43:22.922] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:66:0) after 9m43s
[13:53:06.053] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:66:0)
[13:53:06.083] Build status: STARTED
[13:53:06.083] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:67:0) after 4m32s
[13:57:38.108] Handling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:67:0)
[13:57:38.141] Build status: STARTED
[13:57:38.141] Scheduling timer "check-buildbucket-build-status" (infra/publish_tarball:8981449778213007424:68:0) after 9m26s
[13:59:26.221] Received PubSub notification, asking Buildbucket for the build status
[13:59:26.249] Build:
{
"id": "8816019716294804849",
"builder": {
"project": "infra",
"bucket": "cron",
"builder": "publish_tarball"
},
"createdBy": "project:infra",
"createTime": "2022-04-24T07:30:45.846184671Z",
"startTime": "2022-04-24T08:10:14.206845Z",
"endTime": "2022-04-24T13:59:25.965808234Z",
"updateTime": "2022-04-24T13:59:25.965808234Z",
"status": "SUCCESS",
"input": {
}
}
[13:59:26.249] Invocation finished in 6h28m41.616795198s with status SUCCEEDED