[21:47:45.306] New invocation is queued and will start shortly
[21:47:46.344] Starting the invocation (attempt 1)
[21:47:46.373] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/6742ca97ec4b7b099a57b6d1748ffe7113459477"
[21:47:46.373] Popped gitiles commit info from properties and tags
[21:47:46.373] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:47:46.373] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:47:46.373] Buildbucket request:
{
"requestId": "8994713613805515856",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win10-code-coverage"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "6742ca97ec4b7b099a57b6d1748ffe7113459477",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8994713613805515856"
},
{
"key": "scheduler_job_id",
"value": "chromium/win10-code-coverage"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[21:47:46.826] Scheduled build:
{
"id": "8829283551966660657",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win10-code-coverage"
},
"number": 13009,
"createdBy": "project:chromium",
"createTime": "2021-11-28T21:47:46.429714650Z",
"updateTime": "2021-11-28T21:47:46.429714650Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "6742ca97ec4b7b099a57b6d1748ffe7113459477",
"ref": "refs/heads/main"
}
}
}
[21:47:46.826] Task URL: https://cr-buildbucket.appspot.com/build/8829283551966660657
[21:47:46.826] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:2:0) after 1m28s
[21:49:15.132] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:2:0)
[21:49:15.170] Build status: SCHEDULED
[21:49:15.170] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:3:0) after 5m45s
[21:49:44.549] Received PubSub notification, asking Buildbucket for the build status
[21:49:44.653] Build status: STARTED
[21:55:00.457] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:3:0)
[21:55:00.660] Build status: STARTED
[21:55:00.660] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:5:0) after 9m13s
[22:04:13.917] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:5:0)
[22:04:14.072] Build status: STARTED
[22:04:14.072] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:6:0) after 9m16s
[22:13:30.288] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:6:0)
[22:13:30.318] Build status: STARTED
[22:13:30.318] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:7:0) after 8m55s
[22:22:25.402] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:7:0)
[22:22:25.441] Build status: STARTED
[22:22:25.441] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:8:0) after 8m22s
[22:30:47.976] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:8:0)
[22:30:48.007] Build status: STARTED
[22:30:48.007] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:9:0) after 5m20s
[22:36:08.003] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:9:0)
[22:36:08.051] Build status: STARTED
[22:36:08.051] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:10:0) after 4m31s
[22:40:39.058] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:10:0)
[22:40:39.119] Build status: STARTED
[22:40:39.119] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:11:0) after 9m25s
[22:50:04.151] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:11:0)
[22:50:04.209] Build status: STARTED
[22:50:04.210] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:12:0) after 5m28s
[22:55:32.227] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:12:0)
[22:55:32.254] Build status: STARTED
[22:55:32.254] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:13:0) after 5m45s
[23:01:17.371] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:13:0)
[23:01:17.410] Build status: STARTED
[23:01:17.410] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:14:0) after 6m14s
[23:07:31.461] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:14:0)
[23:07:31.492] Build status: STARTED
[23:07:31.492] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:15:0) after 3m6s
[23:10:37.475] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:15:0)
[23:10:37.507] Build status: STARTED
[23:10:37.507] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:16:0) after 3m34s
[23:14:11.563] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:16:0)
[23:14:11.597] Build status: STARTED
[23:14:11.597] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:17:0) after 5m34s
[23:19:45.801] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:17:0)
[23:19:45.831] Build status: STARTED
[23:19:45.831] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:18:0) after 7m26s
[23:27:11.998] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:18:0)
[23:27:12.100] Build status: STARTED
[23:27:12.100] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:19:0) after 1m52s
[23:29:04.115] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:19:0)
[23:29:04.166] Build status: STARTED
[23:29:04.166] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:20:0) after 6m2s
[23:35:06.186] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:20:0)
[23:35:06.215] Build status: STARTED
[23:35:06.215] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:21:0) after 9m35s
[23:44:41.246] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:21:0)
[23:44:41.289] Build status: STARTED
[23:44:41.289] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:22:0) after 8m34s
[23:53:15.308] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:22:0)
[23:53:15.345] Build status: STARTED
[23:53:15.346] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:23:0) after 8m28s
[00:01:43.366] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:23:0)
[00:01:43.403] Build status: STARTED
[00:01:43.403] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:24:0) after 2m7s
[00:03:50.424] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:24:0)
[00:03:50.456] Build status: STARTED
[00:03:50.456] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:25:0) after 8m15s
[00:12:05.479] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:25:0)
[00:12:05.512] Build status: STARTED
[00:12:05.512] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:26:0) after 7m39s
[00:19:44.534] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:26:0)
[00:19:44.562] Build status: STARTED
[00:19:44.562] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:27:0) after 5m4s
[00:24:48.581] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:27:0)
[00:24:48.615] Build status: STARTED
[00:24:48.615] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:28:0) after 5m14s
[00:30:02.789] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:28:0)
[00:30:02.895] Build status: STARTED
[00:30:02.895] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:29:0) after 2m11s
[00:32:13.982] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:29:0)
[00:32:14.012] Build status: STARTED
[00:32:14.012] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:30:0) after 7m27s
[00:39:41.098] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:30:0)
[00:39:41.138] Build status: STARTED
[00:39:41.138] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:31:0) after 8m15s
[00:47:56.156] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:31:0)
[00:47:56.187] Build status: STARTED
[00:47:56.187] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:32:0) after 5m51s
[00:53:47.208] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:32:0)
[00:53:47.237] Build status: STARTED
[00:53:47.237] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:33:0) after 2m16s
[00:56:03.266] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:33:0)
[00:56:03.318] Build status: STARTED
[00:56:03.318] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:34:0) after 7m47s
[01:03:50.354] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:34:0)
[01:03:50.405] Build status: STARTED
[01:03:50.405] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:35:0) after 5m35s
[01:09:25.424] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:35:0)
[01:09:25.454] Build status: STARTED
[01:09:25.454] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:36:0) after 7m35s
[01:17:01.311] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:36:0)
[01:17:01.340] Build status: STARTED
[01:17:01.340] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:37:0) after 3m33s
[01:20:34.360] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:37:0)
[01:20:34.403] Build status: STARTED
[01:20:34.403] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:38:0) after 3m53s
[01:24:27.809] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:38:0)
[01:24:27.836] Build status: STARTED
[01:24:27.836] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:39:0) after 1m21s
[01:25:48.857] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:39:0)
[01:25:48.889] Build status: STARTED
[01:25:48.889] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:40:0) after 5m52s
[01:31:40.869] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:40:0)
[01:31:40.907] Build status: STARTED
[01:31:40.907] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:41:0) after 3m32s
[01:35:12.933] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:41:0)
[01:35:12.967] Build status: STARTED
[01:35:12.967] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:42:0) after 1m52s
[01:37:05.073] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:42:0)
[01:37:05.105] Build status: STARTED
[01:37:05.105] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:43:0) after 9m56s
[01:47:01.292] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:43:0)
[01:47:01.324] Build status: STARTED
[01:47:01.324] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:44:0) after 6m0s
[01:53:01.349] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:44:0)
[01:53:01.430] Build status: STARTED
[01:53:01.430] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:45:0) after 9m6s
[02:02:07.449] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:45:0)
[02:02:07.476] Build status: STARTED
[02:02:07.476] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:46:0) after 8m10s
[02:10:17.496] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:46:0)
[02:10:17.527] Build status: STARTED
[02:10:17.527] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:47:0) after 9m1s
[02:19:18.544] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:47:0)
[02:19:18.592] Build status: STARTED
[02:19:18.592] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:48:0) after 5m59s
[02:25:17.636] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:48:0)
[02:25:17.668] Build status: STARTED
[02:25:17.668] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:49:0) after 1m21s
[02:26:38.645] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:49:0)
[02:26:38.672] Build status: STARTED
[02:26:38.672] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:50:0) after 2m3s
[02:28:41.689] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:50:0)
[02:28:41.723] Build status: STARTED
[02:28:41.723] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:51:0) after 8m49s
[02:37:30.743] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:51:0)
[02:37:30.817] Build status: STARTED
[02:37:30.817] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:52:0) after 4m34s
[02:42:04.842] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:52:0)
[02:42:04.874] Build status: STARTED
[02:42:04.874] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:53:0) after 3m2s
[02:45:06.898] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:53:0)
[02:45:06.927] Build status: STARTED
[02:45:06.927] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:54:0) after 1m40s
[02:46:47.160] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:54:0)
[02:46:47.212] Build status: STARTED
[02:46:47.212] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:55:0) after 4m52s
[02:51:39.231] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:55:0)
[02:51:39.259] Build status: STARTED
[02:51:39.259] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:56:0) after 7m2s
[02:58:41.718] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:56:0)
[02:58:41.745] Build status: STARTED
[02:58:41.745] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:57:0) after 2m58s
[03:01:39.809] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:57:0)
[03:01:39.839] Build status: STARTED
[03:01:39.840] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:58:0) after 6m25s
[03:08:04.858] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:58:0)
[03:08:04.888] Build status: STARTED
[03:08:04.888] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:59:0) after 2m33s
[03:10:37.959] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:59:0)
[03:10:37.988] Build status: STARTED
[03:10:37.988] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:60:0) after 1m55s
[03:12:33.143] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:60:0)
[03:12:33.171] Build status: STARTED
[03:12:33.171] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:61:0) after 7m10s
[03:19:43.222] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:61:0)
[03:19:43.251] Build status: STARTED
[03:19:43.251] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:62:0) after 8m7s
[03:27:50.273] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:62:0)
[03:27:50.308] Build status: STARTED
[03:27:50.308] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:63:0) after 4m27s
[03:32:17.528] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:63:0)
[03:32:17.554] Build status: STARTED
[03:32:17.554] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:64:0) after 1m31s
[03:33:49.249] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:64:0)
[03:33:49.281] Build status: STARTED
[03:33:49.281] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:65:0) after 4m35s
[03:38:24.302] Handling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:65:0)
[03:38:24.337] Build status: STARTED
[03:38:24.337] Scheduling timer "check-buildbucket-build-status" (chromium/win10-code-coverage:8994713613805515856:66:0) after 4m6s
[03:39:16.555] Received PubSub notification, asking Buildbucket for the build status
[03:39:16.585] Build:
{
"id": "8829283551966660657",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win10-code-coverage"
},
"number": 13009,
"createdBy": "project:chromium",
"createTime": "2021-11-28T21:47:46.429714650Z",
"startTime": "2021-11-28T21:49:43.320180Z",
"endTime": "2021-11-29T03:39:16.242714485Z",
"updateTime": "2021-11-29T03:39:16.242714485Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "6742ca97ec4b7b099a57b6d1748ffe7113459477",
"ref": "refs/heads/main"
}
}
}
[03:39:16.585] Invocation finished in 5h51m31.292129977s with status FAILED