[03:11:46.122] New invocation is queued and will start shortly
[03:11:47.187] Starting the invocation (attempt 1)
[03:11:47.240] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/21021095288b976caa9c6fe5eecc1842be10ef61"
[03:11:47.240] Popped gitiles commit info from properties and tags
[03:11:47.240] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[03:11:47.240] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[03:11:47.240] Buildbucket request:
{
"requestId": "8955283548248557888",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "ToTWin64"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "21021095288b976caa9c6fe5eecc1842be10ef61",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8955283548248557888"
},
{
"key": "scheduler_job_id",
"value": "chromium/ToTWin64"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[03:11:47.800] Scheduled build:
{
"id": "8789853486284209985",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "ToTWin64"
},
"number": 3444,
"createdBy": "project:chromium",
"createTime": "2023-02-07T03:11:47.364784082Z",
"updateTime": "2023-02-07T03:11:47.364784082Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "21021095288b976caa9c6fe5eecc1842be10ef61",
"ref": "refs/heads/main"
}
},
"canary": true
}
[03:11:47.800] Task URL: https://cr-buildbucket.appspot.com/build/8789853486284209985
[03:11:47.800] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:2:0) after 3m1s
[03:14:48.957] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:2:0)
[03:14:48.980] Build status: SCHEDULED
[03:14:48.981] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:3:0) after 2m2s
[03:15:27.728] Received PubSub notification, asking Buildbucket for the build status
[03:15:27.771] Build status: STARTED
[03:16:51.004] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:3:0)
[03:16:51.023] Build status: STARTED
[03:16:51.023] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:5:0) after 4m25s
[03:21:16.059] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:5:0)
[03:21:16.081] Build status: STARTED
[03:21:16.081] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:6:0) after 3m39s
[03:24:55.439] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:6:0)
[03:24:55.474] Build status: STARTED
[03:24:55.474] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:7:0) after 1m50s
[03:26:45.641] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:7:0)
[03:26:45.686] Build status: STARTED
[03:26:45.686] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:8:0) after 8m45s
[03:35:30.709] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:8:0)
[03:35:30.728] Build status: STARTED
[03:35:30.728] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:9:0) after 5m39s
[03:41:09.758] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:9:0)
[03:41:09.780] Build status: STARTED
[03:41:09.780] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:10:0) after 3m23s
[03:44:32.803] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:10:0)
[03:44:32.823] Build status: STARTED
[03:44:32.823] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:11:0) after 2m44s
[03:47:16.844] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:11:0)
[03:47:16.894] Build status: STARTED
[03:47:16.894] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:12:0) after 1m57s
[03:49:13.924] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:12:0)
[03:49:13.959] Build status: STARTED
[03:49:13.959] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:13:0) after 2m16s
[03:51:29.985] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:13:0)
[03:51:30.014] Build status: STARTED
[03:51:30.014] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:14:0) after 7m42s
[03:59:12.261] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:14:0)
[03:59:12.287] Build status: STARTED
[03:59:12.287] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:15:0) after 7m56s
[04:07:08.308] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:15:0)
[04:07:08.337] Build status: STARTED
[04:07:08.337] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:16:0) after 7m47s
[04:14:55.361] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:16:0)
[04:14:55.390] Build status: STARTED
[04:14:55.390] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:17:0) after 9m46s
[04:24:41.567] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:17:0)
[04:24:41.597] Build status: STARTED
[04:24:41.597] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:18:0) after 6m39s
[04:31:20.725] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:18:0)
[04:31:20.752] Build status: STARTED
[04:31:20.752] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:19:0) after 9m0s
[04:40:20.782] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:19:0)
[04:40:20.824] Build status: STARTED
[04:40:20.824] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:20:0) after 6m8s
[04:46:28.911] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:20:0)
[04:46:28.933] Build status: STARTED
[04:46:28.933] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:21:0) after 8m54s
[04:55:23.036] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:21:0)
[04:55:23.058] Build status: STARTED
[04:55:23.058] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:22:0) after 9m33s
[05:04:56.200] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:22:0)
[05:04:56.224] Build status: STARTED
[05:04:56.224] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:23:0) after 5m18s
[05:10:14.245] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:23:0)
[05:10:14.266] Build status: STARTED
[05:10:14.266] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:24:0) after 4m2s
[05:14:16.339] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:24:0)
[05:14:16.359] Build status: STARTED
[05:14:16.359] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:25:0) after 5m56s
[05:20:12.468] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:25:0)
[05:20:12.493] Build status: STARTED
[05:20:12.493] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:26:0) after 7m54s
[05:28:06.735] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:26:0)
[05:28:06.757] Build status: STARTED
[05:28:06.757] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:27:0) after 6m45s
[05:34:51.758] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:27:0)
[05:34:51.780] Build status: STARTED
[05:34:51.780] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:28:0) after 3m16s
[05:38:07.815] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:28:0)
[05:38:07.895] Build status: STARTED
[05:38:07.895] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:29:0) after 8m42s
[05:46:49.986] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:29:0)
[05:46:50.011] Build status: STARTED
[05:46:50.011] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:30:0) after 5m51s
[05:52:41.037] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:30:0)
[05:52:41.068] Build status: STARTED
[05:52:41.068] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:31:0) after 3m57s
[05:56:38.172] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:31:0)
[05:56:38.226] Build status: STARTED
[05:56:38.226] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:32:0) after 5m18s
[06:01:56.433] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:32:0)
[06:01:56.454] Build status: STARTED
[06:01:56.454] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:33:0) after 7m57s
[06:09:53.472] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:33:0)
[06:09:53.525] Build status: STARTED
[06:09:53.525] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:34:0) after 5m43s
[06:15:36.804] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:34:0)
[06:15:36.825] Build status: STARTED
[06:15:36.825] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:35:0) after 8m4s
[06:23:40.947] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:35:0)
[06:23:40.970] Build status: STARTED
[06:23:40.970] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:36:0) after 8m46s
[06:32:27.184] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:36:0)
[06:32:27.227] Build status: STARTED
[06:32:27.227] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:37:0) after 3m44s
[06:36:11.247] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:37:0)
[06:36:11.289] Build status: STARTED
[06:36:11.289] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:38:0) after 9m39s
[06:45:50.527] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:38:0)
[06:45:50.558] Build status: STARTED
[06:45:50.558] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:39:0) after 7m14s
[06:53:04.580] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:39:0)
[06:53:04.601] Build status: STARTED
[06:53:04.601] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:40:0) after 4m5s
[06:57:09.623] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:40:0)
[06:57:09.667] Build status: STARTED
[06:57:09.667] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:41:0) after 7m24s
[07:04:33.675] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:41:0)
[07:04:33.697] Build status: STARTED
[07:04:33.698] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:42:0) after 6m30s
[07:11:03.735] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:42:0)
[07:11:03.771] Build status: STARTED
[07:11:03.771] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:43:0) after 8m51s
[07:19:54.825] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:43:0)
[07:19:54.845] Build status: STARTED
[07:19:54.845] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:44:0) after 5m12s
[07:25:06.873] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:44:0)
[07:25:06.932] Build status: STARTED
[07:25:06.932] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:45:0) after 3m0s
[07:28:07.012] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:45:0)
[07:28:07.034] Build status: STARTED
[07:28:07.034] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:46:0) after 4m43s
[07:32:50.190] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:46:0)
[07:32:50.212] Build status: STARTED
[07:32:50.212] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:47:0) after 5m9s
[07:37:59.234] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:47:0)
[07:37:59.299] Build status: STARTED
[07:37:59.300] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:48:0) after 3m48s
[07:41:47.336] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:48:0)
[07:41:47.357] Build status: STARTED
[07:41:47.357] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:49:0) after 6m27s
[07:48:14.548] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:49:0)
[07:48:14.569] Build status: STARTED
[07:48:14.569] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:50:0) after 8m17s
[07:56:31.591] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:50:0)
[07:56:31.613] Build status: STARTED
[07:56:31.613] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:51:0) after 3m31s
[08:00:02.734] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:51:0)
[08:00:02.769] Build status: STARTED
[08:00:02.769] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:52:0) after 6m52s
[08:06:54.853] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:52:0)
[08:06:54.877] Build status: STARTED
[08:06:54.877] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:53:0) after 5m51s
[08:12:45.910] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:53:0)
[08:12:45.932] Build status: STARTED
[08:12:45.932] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:54:0) after 2m37s
[08:15:23.079] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:54:0)
[08:15:23.151] Build status: STARTED
[08:15:23.151] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:55:0) after 6m1s
[08:21:24.148] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:55:0)
[08:21:24.168] Build status: STARTED
[08:21:24.168] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:56:0) after 7m58s
[08:29:22.194] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:56:0)
[08:29:22.222] Build status: STARTED
[08:29:22.222] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:57:0) after 7m14s
[08:36:36.245] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:57:0)
[08:36:36.267] Build status: STARTED
[08:36:36.267] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:58:0) after 3m58s
[08:40:34.383] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:58:0)
[08:40:34.406] Build status: STARTED
[08:40:34.406] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:59:0) after 3m7s
[08:43:41.795] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:59:0)
[08:43:41.814] Build status: STARTED
[08:43:41.814] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:60:0) after 9m36s
[08:53:17.852] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:60:0)
[08:53:17.877] Build status: STARTED
[08:53:17.877] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:61:0) after 5m25s
[08:58:43.069] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:61:0)
[08:58:43.094] Build status: STARTED
[08:58:43.094] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:62:0) after 6m24s
[09:05:07.117] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:62:0)
[09:05:07.138] Build status: STARTED
[09:05:07.138] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:63:0) after 2m0s
[09:07:07.182] Handling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:63:0)
[09:07:07.211] Build status: STARTED
[09:07:07.211] Scheduling timer "check-buildbucket-build-status" (chromium/ToTWin64:8955283548248557888:64:0) after 3m6s
[09:08:14.169] Received PubSub notification, asking Buildbucket for the build status
[09:08:14.203] Build:
{
"id": "8789853486284209985",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "ToTWin64"
},
"number": 3444,
"createdBy": "project:chromium",
"createTime": "2023-02-07T03:11:47.364784082Z",
"startTime": "2023-02-07T03:15:25.844409Z",
"endTime": "2023-02-07T09:08:13.831517504Z",
"updateTime": "2023-02-07T09:08:13.831517504Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "21021095288b976caa9c6fe5eecc1842be10ef61",
"ref": "refs/heads/main"
}
},
"canary": true
}
[09:08:14.203] Invocation finished in 5h56m28.095705716s with status FAILED