[04:00:06.970] New invocation is queued and will start shortly
[04:00:08.458] Starting the invocation (attempt 1)
[04:00:08.482] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/cc984b24072a4b3d5b84d2c049631de2751f8e8a"
[04:00:08.483] Popped gitiles commit info from properties and tags
[04:00:08.483] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[04:00:08.483] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[04:00:08.483] Buildbucket request:
{
"requestId": "8927829625662652976",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-code-coverage"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "cc984b24072a4b3d5b84d2c049631de2751f8e8a",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8927829625662652976"
},
{
"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"
}
}
[04:00:09.821] Scheduled build:
{
"id": "8762399563339689137",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-code-coverage"
},
"number": 5716,
"createdBy": "project:chromium",
"createTime": "2023-12-07T04:00:08.561119097Z",
"updateTime": "2023-12-07T04:00:08.561119097Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "cc984b24072a4b3d5b84d2c049631de2751f8e8a",
"ref": "refs/heads/main"
}
}
}
[04:00:09.821] Task URL: https://cr-buildbucket.appspot.com/build/8762399563339689137
[04:00:09.821] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:2:0) after 9m58s
[04:00:10.458] Received PubSub notification, asking Buildbucket for the build status
[04:00:10.487] Build status: SCHEDULED
[04:00:14.243] Received PubSub notification, asking Buildbucket for the build status
[04:00:14.268] Build status: STARTED
[04:10:08.439] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:2:0)
[04:10:08.477] Build status: STARTED
[04:10:08.477] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:5:0) after 6m1s
[04:16:09.468] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:5:0)
[04:16:09.499] Build status: STARTED
[04:16:09.499] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:6:0) after 5m34s
[04:21:43.515] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:6:0)
[04:21:43.550] Build status: STARTED
[04:21:43.550] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:7:0) after 9m12s
[04:30:55.573] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:7:0)
[04:30:55.677] Build status: STARTED
[04:30:55.677] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:8:0) after 7m35s
[04:38:30.692] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:8:0)
[04:38:30.710] Build status: STARTED
[04:38:30.710] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:9:0) after 3m31s
[04:42:01.691] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:9:0)
[04:42:01.714] Build status: STARTED
[04:42:01.714] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:10:0) after 8m53s
[04:50:55.014] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:10:0)
[04:50:55.033] Build status: STARTED
[04:50:55.033] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:11:0) after 3m28s
[04:54:23.053] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:11:0)
[04:54:23.293] Build status: STARTED
[04:54:23.293] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:12:0) after 6m11s
[05:00:34.311] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:12:0)
[05:00:34.372] Build status: STARTED
[05:00:34.372] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:13:0) after 3m3s
[05:03:37.386] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:13:0)
[05:03:37.415] Build status: STARTED
[05:03:37.415] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:14:0) after 6m28s
[05:10:05.542] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:14:0)
[05:10:05.608] Build status: STARTED
[05:10:05.608] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:15:0) after 9m33s
[05:19:38.676] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:15:0)
[05:19:38.733] Build status: STARTED
[05:19:38.733] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:16:0) after 9m3s
[05:28:41.749] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:16:0)
[05:28:41.767] Build status: STARTED
[05:28:41.767] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:17:0) after 5m34s
[05:34:15.800] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:17:0)
[05:34:15.832] Build status: STARTED
[05:34:15.832] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:18:0) after 2m16s
[05:36:32.007] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:18:0)
[05:36:32.030] Build status: STARTED
[05:36:32.030] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:19:0) after 3m49s
[05:40:21.048] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:19:0)
[05:40:21.079] Build status: STARTED
[05:40:21.079] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:20:0) after 5m1s
[05:45:22.129] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:20:0)
[05:45:22.147] Build status: STARTED
[05:45:22.147] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:21:0) after 2m19s
[05:47:41.300] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:21:0)
[05:47:41.329] Build status: STARTED
[05:47:41.329] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:22:0) after 7m0s
[05:54:41.456] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:22:0)
[05:54:41.564] Build status: STARTED
[05:54:41.564] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:23:0) after 6m18s
[06:00:59.948] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:23:0)
[06:00:59.970] Build status: STARTED
[06:00:59.970] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:24:0) after 7m5s
[06:08:05.326] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:24:0)
[06:08:05.381] Build status: STARTED
[06:08:05.381] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:25:0) after 2m41s
[06:10:46.396] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:25:0)
[06:10:46.424] Build status: STARTED
[06:10:46.424] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:26:0) after 4m36s
[06:15:22.575] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:26:0)
[06:15:22.735] Build status: STARTED
[06:15:22.735] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:27:0) after 3m17s
[06:18:39.841] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:27:0)
[06:18:39.857] Build status: STARTED
[06:18:39.857] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:28:0) after 3m55s
[06:22:34.909] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:28:0)
[06:22:34.929] Build status: STARTED
[06:22:34.929] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:29:0) after 4m39s
[06:27:13.955] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:29:0)
[06:27:13.990] Build status: STARTED
[06:27:13.990] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:30:0) after 4m22s
[06:31:36.092] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:30:0)
[06:31:36.116] Build status: STARTED
[06:31:36.116] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:31:0) after 5m11s
[06:36:47.740] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:31:0)
[06:36:47.823] Build status: STARTED
[06:36:47.823] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:32:0) after 8m5s
[06:44:52.848] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:32:0)
[06:44:52.871] Build status: STARTED
[06:44:52.871] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:33:0) after 6m24s
[06:51:17.078] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:33:0)
[06:51:17.112] Build status: STARTED
[06:51:17.112] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:34:0) after 5m57s
[06:57:14.436] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:34:0)
[06:57:14.454] Build status: STARTED
[06:57:14.454] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:35:0) after 4m6s
[07:01:20.752] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:35:0)
[07:01:20.856] Build status: STARTED
[07:01:20.856] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:36:0) after 5m53s
[07:07:14.253] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:36:0)
[07:07:14.275] Build status: STARTED
[07:07:14.275] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:37:0) after 8m42s
[07:15:56.680] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:37:0)
[07:15:56.701] Build status: STARTED
[07:15:56.701] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:38:0) after 8m33s
[07:24:29.958] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:38:0)
[07:24:29.974] Build status: STARTED
[07:24:29.974] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:39:0) after 7m13s
[07:31:42.994] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:39:0)
[07:31:43.013] Build status: STARTED
[07:31:43.013] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:40:0) after 3m34s
[07:35:17.052] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:40:0)
[07:35:17.071] Build status: STARTED
[07:35:17.071] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:41:0) after 4m20s
[07:39:37.186] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:41:0)
[07:39:37.206] Build status: STARTED
[07:39:37.207] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:42:0) after 4m56s
[07:44:33.776] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:42:0)
[07:44:33.792] Build status: STARTED
[07:44:33.792] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:43:0) after 1m40s
[07:46:13.817] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:43:0)
[07:46:13.987] Build status: STARTED
[07:46:13.987] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:44:0) after 1m16s
[07:47:30.066] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:44:0)
[07:47:30.094] Build status: STARTED
[07:47:30.094] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:45:0) after 2m55s
[07:50:25.118] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:45:0)
[07:50:25.144] Build status: STARTED
[07:50:25.144] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:46:0) after 1m47s
[07:52:12.164] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:46:0)
[07:52:12.180] Build status: STARTED
[07:52:12.180] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:47:0) after 2m4s
[07:54:16.328] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:47:0)
[07:54:16.444] Build status: STARTED
[07:54:16.445] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:48:0) after 9m15s
[08:03:31.548] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:48:0)
[08:03:31.604] Build status: STARTED
[08:03:31.604] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:49:0) after 1m47s
[08:05:19.179] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:49:0)
[08:05:19.199] Build status: STARTED
[08:05:19.199] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:50:0) after 7m31s
[08:12:50.292] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:50:0)
[08:12:50.313] Build status: STARTED
[08:12:50.313] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:51:0) after 6m0s
[08:18:50.433] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:51:0)
[08:18:50.455] Build status: STARTED
[08:18:50.455] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:52:0) after 1m24s
[08:20:14.842] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:52:0)
[08:20:14.880] Build status: STARTED
[08:20:14.880] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:53:0) after 4m16s
[08:24:31.213] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:53:0)
[08:24:31.292] Build status: STARTED
[08:24:31.292] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:54:0) after 4m18s
[08:28:49.277] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:54:0)
[08:28:49.300] Build status: STARTED
[08:28:49.300] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:55:0) after 8m15s
[08:37:04.424] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:55:0)
[08:37:04.444] Build status: STARTED
[08:37:04.444] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:56:0) after 6m51s
[08:43:55.661] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:56:0)
[08:43:55.736] Build status: STARTED
[08:43:55.736] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:57:0) after 7m16s
[08:51:12.220] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:57:0)
[08:51:12.249] Build status: STARTED
[08:51:12.249] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:58:0) after 7m5s
[08:58:17.258] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:58:0)
[08:58:17.279] Build status: STARTED
[08:58:17.279] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:59:0) after 2m56s
[09:01:13.300] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:59:0)
[09:01:13.327] Build status: STARTED
[09:01:13.327] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:60:0) after 1m6s
[09:02:19.555] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:60:0)
[09:02:19.700] Build status: STARTED
[09:02:19.700] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:61:0) after 5m10s
[09:07:29.960] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:61:0)
[09:07:30.171] Build status: STARTED
[09:07:30.171] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:62:0) after 9m31s
[09:17:01.595] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:62:0)
[09:17:01.625] Build status: STARTED
[09:17:01.625] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:63:0) after 4m51s
[09:21:52.594] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:63:0)
[09:21:52.613] Build status: STARTED
[09:21:52.613] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:64:0) after 7m59s
[09:29:51.701] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:64:0)
[09:29:51.720] Build status: STARTED
[09:29:51.720] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:65:0) after 8m8s
[09:37:59.887] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:65:0)
[09:37:59.907] Build status: STARTED
[09:37:59.907] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:66:0) after 9m27s
[09:47:27.062] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:66:0)
[09:47:27.092] Build status: STARTED
[09:47:27.092] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:67:0) after 2m27s
[09:49:54.109] Handling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:67:0)
[09:49:54.128] Build status: STARTED
[09:49:54.128] Scheduling timer "check-buildbucket-build-status" (chromium/linux-code-coverage:8927829625662652976:68:0) after 5m33s
[09:53:39.246] Received PubSub notification, asking Buildbucket for the build status
[09:53:39.274] Build:
{
"id": "8762399563339689137",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "linux-code-coverage"
},
"number": 5716,
"createdBy": "project:chromium",
"createTime": "2023-12-07T04:00:08.561119097Z",
"startTime": "2023-12-07T04:00:11.982811Z",
"endTime": "2023-12-07T09:53:38.346525Z",
"updateTime": "2023-12-07T09:53:38.346525Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "cc984b24072a4b3d5b84d2c049631de2751f8e8a",
"ref": "refs/heads/main"
}
}
}
[09:53:39.274] Invocation finished in 5h53m32.312342019s with status FAILED