[23:13:42.267] New invocation is queued and will start shortly
[23:13:43.403] Starting the invocation (attempt 1)
[23:13:43.440] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/f5512ed12d8bf45f05bd8438609582bfe3f1958a"
[23:13:43.440] Popped gitiles commit info from properties and tags
[23:13:43.440] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[23:13:43.440] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[23:13:43.440] Buildbucket request:
{
"requestId": "8950587483697413024",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-code-coverage"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f5512ed12d8bf45f05bd8438609582bfe3f1958a",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8950587483697413024"
},
{
"key": "scheduler_job_id",
"value": "chromium/linux-code-coverage"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[23:13:43.992] Scheduled build:
{
"id": "8785157421661182369",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-code-coverage"
},
"number": 5373,
"createdBy": "project:chromium",
"createTime": "2023-03-30T23:13:43.583785752Z",
"updateTime": "2023-03-30T23:13:43.583785752Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f5512ed12d8bf45f05bd8438609582bfe3f1958a",
"ref": "refs/heads/main"
}
}
}
[23:13:43.992] Task URL: https://cr-buildbucket.appspot.com/build/8785157421661182369
[23:13:43.992] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:2:0) after 2m38s
[23:16:22.565] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:2:0)
[23:16:22.584] Build status: SCHEDULED
[23:16:22.584] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:3:0) after 4m25s
[23:20:47.606] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:3:0)
[23:20:47.632] Build status: SCHEDULED
[23:20:47.632] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:4:0) after 6m22s
[23:27:09.665] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:4:0)
[23:27:09.692] Build status: SCHEDULED
[23:27:09.692] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:5:0) after 2m20s
[23:29:29.926] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:5:0)
[23:29:29.954] Build status: SCHEDULED
[23:29:29.954] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:6:0) after 4m47s
[23:34:17.175] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:6:0)
[23:34:17.199] Build status: SCHEDULED
[23:34:17.199] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:7:0) after 3m41s
[23:37:58.381] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:7:0)
[23:37:58.399] Build status: SCHEDULED
[23:37:58.399] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:8:0) after 4m58s
[23:41:28.830] Received PubSub notification, asking Buildbucket for the build status
[23:41:28.859] Build status: STARTED
[23:42:56.606] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:8:0)
[23:42:56.676] Build status: STARTED
[23:42:56.676] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:10:0) after 1m36s
[23:44:32.699] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:10:0)
[23:44:32.719] Build status: STARTED
[23:44:32.719] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:11:0) after 6m47s
[23:51:20.035] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:11:0)
[23:51:20.054] Build status: STARTED
[23:51:20.054] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:12:0) after 3m29s
[23:54:49.180] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:12:0)
[23:54:49.209] Build status: STARTED
[23:54:49.209] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:13:0) after 8m37s
[00:03:26.300] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:13:0)
[00:03:26.325] Build status: STARTED
[00:03:26.326] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:14:0) after 7m44s
[00:11:10.345] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:14:0)
[00:11:10.368] Build status: STARTED
[00:11:10.368] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:15:0) after 9m39s
[00:20:49.412] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:15:0)
[00:20:49.432] Build status: STARTED
[00:20:49.432] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:16:0) after 1m39s
[00:22:28.452] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:16:0)
[00:22:28.472] Build status: STARTED
[00:22:28.472] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:17:0) after 3m40s
[00:26:08.583] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:17:0)
[00:26:08.605] Build status: STARTED
[00:26:08.605] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:18:0) after 7m16s
[00:33:24.633] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:18:0)
[00:33:24.656] Build status: STARTED
[00:33:24.656] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:19:0) after 1m50s
[00:35:14.902] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:19:0)
[00:35:14.925] Build status: STARTED
[00:35:14.925] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:20:0) after 9m44s
[00:44:59.032] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:20:0)
[00:44:59.052] Build status: STARTED
[00:44:59.052] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:21:0) after 2m24s
[00:47:23.080] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:21:0)
[00:47:23.107] Build status: STARTED
[00:47:23.107] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:22:0) after 4m17s
[00:51:40.130] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:22:0)
[00:51:40.154] Build status: STARTED
[00:51:40.154] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:23:0) after 8m26s
[01:00:06.257] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:23:0)
[01:00:06.277] Build status: STARTED
[01:00:06.277] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:24:0) after 2m59s
[01:03:05.314] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:24:0)
[01:03:05.369] Build status: STARTED
[01:03:05.369] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:25:0) after 4m9s
[01:07:14.789] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:25:0)
[01:07:14.811] Build status: STARTED
[01:07:14.811] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:26:0) after 7m47s
[01:15:01.842] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:26:0)
[01:15:01.863] Build status: STARTED
[01:15:01.863] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:27:0) after 6m17s
[01:21:18.892] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:27:0)
[01:21:18.921] Build status: STARTED
[01:21:18.921] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:28:0) after 4m19s
[01:25:38.099] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:28:0)
[01:25:38.123] Build status: STARTED
[01:25:38.123] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:29:0) after 1m31s
[01:27:09.201] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:29:0)
[01:27:09.232] Build status: STARTED
[01:27:09.232] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:30:0) after 8m17s
[01:35:26.689] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:30:0)
[01:35:26.709] Build status: STARTED
[01:35:26.709] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:31:0) after 6m40s
[01:42:06.923] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:31:0)
[01:42:06.945] Build status: STARTED
[01:42:06.945] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:32:0) after 2m5s
[01:44:11.987] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:32:0)
[01:44:12.008] Build status: STARTED
[01:44:12.008] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:33:0) after 4m21s
[01:48:33.462] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:33:0)
[01:48:33.484] Build status: STARTED
[01:48:33.484] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:34:0) after 6m18s
[01:54:51.630] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:34:0)
[01:54:51.658] Build status: STARTED
[01:54:51.658] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:35:0) after 4m34s
[01:59:25.655] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:35:0)
[01:59:25.694] Build status: STARTED
[01:59:25.694] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:36:0) after 1m53s
[02:01:18.827] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:36:0)
[02:01:18.864] Build status: STARTED
[02:01:18.864] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:37:0) after 4m5s
[02:05:23.971] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:37:0)
[02:05:23.992] Build status: STARTED
[02:05:23.992] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:38:0) after 1m19s
[02:06:43.060] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:38:0)
[02:06:43.083] Build status: STARTED
[02:06:43.083] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:39:0) after 1m34s
[02:08:17.277] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:39:0)
[02:08:17.301] Build status: STARTED
[02:08:17.301] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:40:0) after 3m4s
[02:11:21.656] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:40:0)
[02:11:21.678] Build status: STARTED
[02:11:21.678] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:41:0) after 9m44s
[02:21:05.701] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:41:0)
[02:21:05.748] Build status: STARTED
[02:21:05.748] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:42:0) after 9m4s
[02:30:10.129] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:42:0)
[02:30:10.154] Build status: STARTED
[02:30:10.154] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:43:0) after 1m57s
[02:32:07.184] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:43:0)
[02:32:07.219] Build status: STARTED
[02:32:07.219] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:44:0) after 4m26s
[02:36:33.244] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:44:0)
[02:36:33.264] Build status: STARTED
[02:36:33.264] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:45:0) after 5m45s
[02:42:18.290] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:45:0)
[02:42:18.317] Build status: STARTED
[02:42:18.317] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:46:0) after 5m53s
[02:48:11.475] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:46:0)
[02:48:11.496] Build status: STARTED
[02:48:11.496] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:47:0) after 6m52s
[02:55:03.622] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:47:0)
[02:55:03.645] Build status: STARTED
[02:55:03.645] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:48:0) after 3m50s
[02:58:53.673] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:48:0)
[02:58:53.701] Build status: STARTED
[02:58:53.701] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:49:0) after 3m52s
[03:02:46.023] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:49:0)
[03:02:46.087] Build status: STARTED
[03:02:46.087] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:50:0) after 7m27s
[03:10:13.321] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:50:0)
[03:10:13.348] Build status: STARTED
[03:10:13.348] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:51:0) after 9m21s
[03:19:34.568] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:51:0)
[03:19:34.600] Build status: STARTED
[03:19:34.600] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:52:0) after 3m11s
[03:22:45.902] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:52:0)
[03:22:45.973] Build status: STARTED
[03:22:45.973] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:53:0) after 2m13s
[03:24:58.994] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:53:0)
[03:24:59.135] Build status: STARTED
[03:24:59.135] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:54:0) after 9m15s
[03:34:14.451] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:54:0)
[03:34:14.476] Build status: STARTED
[03:34:14.476] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:55:0) after 5m12s
[03:39:26.603] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:55:0)
[03:39:26.623] Build status: STARTED
[03:39:26.623] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:56:0) after 6m12s
[03:45:38.640] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:56:0)
[03:45:38.662] Build status: STARTED
[03:45:38.663] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:57:0) after 8m12s
[03:53:50.699] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:57:0)
[03:53:50.721] Build status: STARTED
[03:53:50.721] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:58:0) after 2m1s
[03:55:51.740] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:58:0)
[03:55:51.787] Build status: STARTED
[03:55:51.787] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:59:0) after 3m48s
[03:59:40.025] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:59:0)
[03:59:40.084] Build status: STARTED
[03:59:40.084] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:60:0) after 4m34s
[04:04:14.310] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:60:0)
[04:04:14.375] Build status: STARTED
[04:04:14.375] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:61:0) after 9m5s
[04:13:19.551] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:61:0)
[04:13:19.571] Build status: STARTED
[04:13:19.571] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:62:0) after 6m11s
[04:19:30.595] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:62:0)
[04:19:30.613] Build status: STARTED
[04:19:30.613] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8950587483697413024:63:0) after 7m19s
[04:23:10.611] Received PubSub notification, asking Buildbucket for the build status
[04:23:10.637] Build:
{
"id": "8785157421661182369",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-code-coverage"
},
"number": 5373,
"createdBy": "project:chromium",
"createTime": "2023-03-30T23:13:43.583785752Z",
"startTime": "2023-03-30T23:41:28.103023Z",
"endTime": "2023-03-31T04:23:09.545874797Z",
"updateTime": "2023-03-31T04:23:09.545874797Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "f5512ed12d8bf45f05bd8438609582bfe3f1958a",
"ref": "refs/heads/main"
}
}
}
[04:23:10.637] Invocation finished in 5h9m28.379053999s with status FAILED