[19:23:00.080] New invocation is queued and will start shortly
[19:23:01.174] Starting the invocation (attempt 1)
[19:23:01.201] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/cd92e094fd6759c0f437920e7567db640e53be4e"
[19:23:01.201] Popped gitiles commit info from properties and tags
[19:23:01.201] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[19:23:01.201] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[19:23:01.201] Buildbucket request:
{
"requestId": "8939549168392691696",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win-rel-dev"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "cd92e094fd6759c0f437920e7567db640e53be4e",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8939549168392691696"
},
{
"key": "scheduler_job_id",
"value": "chromium/win-rel-dev"
},
{
"key": "user_agent",
"value": "luci-scheduler-dev"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
}
}
[19:23:02.095] Scheduled build:
{
"id": "8774119106457637201",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win-rel-dev"
},
"number": 1746,
"createdBy": "project:chromium",
"createTime": "2023-07-30T19:23:01.289385771Z",
"updateTime": "2023-07-30T19:23:01.289385771Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "cd92e094fd6759c0f437920e7567db640e53be4e",
"ref": "refs/heads/main"
}
}
}
[19:23:02.095] Task URL: https://cr-buildbucket-dev.appspot.com/build/8774119106457637201
[19:23:02.095] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:2:0) after 6m53s
[19:23:02.690] Received PubSub notification, asking Buildbucket for the build status
[19:23:02.727] Build status: SCHEDULED
[19:29:55.115] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:2:0)
[19:29:55.154] Build status: SCHEDULED
[19:29:55.154] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:4:0) after 6m3s
[19:33:35.941] Received PubSub notification, asking Buildbucket for the build status
[19:33:35.980] Build status: STARTED
[19:35:58.188] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:4:0)
[19:35:58.217] Build status: STARTED
[19:35:58.217] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:6:0) after 5m11s
[19:41:09.236] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:6:0)
[19:41:09.289] Build status: STARTED
[19:41:09.289] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:7:0) after 2m11s
[19:43:20.310] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:7:0)
[19:43:20.334] Build status: STARTED
[19:43:20.334] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:8:0) after 9m27s
[19:52:47.365] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:8:0)
[19:52:47.425] Build status: STARTED
[19:52:47.425] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:9:0) after 7m20s
[20:00:07.444] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:9:0)
[20:00:07.504] Build status: STARTED
[20:00:07.504] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:10:0) after 9m21s
[20:09:28.520] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:10:0)
[20:09:28.555] Build status: STARTED
[20:09:28.555] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:11:0) after 4m10s
[20:13:38.578] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:11:0)
[20:13:38.609] Build status: STARTED
[20:13:38.609] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:12:0) after 8m49s
[20:22:27.628] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:12:0)
[20:22:27.734] Build status: STARTED
[20:22:27.734] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:13:0) after 8m15s
[20:30:42.754] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:13:0)
[20:30:42.792] Build status: STARTED
[20:30:42.793] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:14:0) after 7m11s
[20:37:53.808] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:14:0)
[20:37:53.837] Build status: STARTED
[20:37:53.837] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:15:0) after 4m6s
[20:41:59.854] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:15:0)
[20:41:59.892] Build status: STARTED
[20:41:59.892] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:16:0) after 2m10s
[20:44:09.918] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:16:0)
[20:44:09.945] Build status: STARTED
[20:44:09.945] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:17:0) after 4m8s
[20:48:18.401] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:17:0)
[20:48:18.424] Build status: STARTED
[20:48:18.424] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:18:0) after 8m5s
[20:56:23.439] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:18:0)
[20:56:23.503] Build status: STARTED
[20:56:23.503] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:19:0) after 9m44s
[21:06:07.531] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:19:0)
[21:06:07.553] Build status: STARTED
[21:06:07.553] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:20:0) after 6m47s
[21:12:54.594] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:20:0)
[21:12:54.620] Build status: STARTED
[21:12:54.620] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:21:0) after 8m13s
[21:21:07.637] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:21:0)
[21:21:07.659] Build status: STARTED
[21:21:07.659] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:22:0) after 1m25s
[21:22:32.676] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:22:0)
[21:22:32.699] Build status: STARTED
[21:22:32.699] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:23:0) after 3m51s
[21:26:23.720] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:23:0)
[21:26:23.747] Build status: STARTED
[21:26:23.747] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:24:0) after 1m22s
[21:27:45.764] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:24:0)
[21:27:45.799] Build status: STARTED
[21:27:45.799] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:25:0) after 2m16s
[21:30:01.833] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:25:0)
[21:30:01.881] Build status: STARTED
[21:30:01.881] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:26:0) after 9m58s
[21:39:59.900] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:26:0)
[21:39:59.929] Build status: STARTED
[21:39:59.929] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:27:0) after 6m17s
[21:46:16.946] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:27:0)
[21:46:17.004] Build status: STARTED
[21:46:17.004] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:28:0) after 9m45s
[21:56:02.023] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:28:0)
[21:56:02.059] Build status: STARTED
[21:56:02.059] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:29:0) after 2m8s
[21:58:10.104] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:29:0)
[21:58:10.124] Build status: STARTED
[21:58:10.124] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:30:0) after 5m36s
[22:03:46.156] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:30:0)
[22:03:46.208] Build status: STARTED
[22:03:46.208] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:31:0) after 6m12s
[22:09:58.226] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:31:0)
[22:09:58.268] Build status: STARTED
[22:09:58.268] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:32:0) after 1m38s
[22:11:36.283] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:32:0)
[22:11:36.325] Build status: STARTED
[22:11:36.325] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:33:0) after 7m40s
[22:19:16.343] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:33:0)
[22:19:16.378] Build status: STARTED
[22:19:16.378] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:34:0) after 7m34s
[22:26:50.394] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:34:0)
[22:26:50.425] Build status: STARTED
[22:26:50.425] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:35:0) after 2m47s
[22:29:37.440] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:35:0)
[22:29:37.498] Build status: STARTED
[22:29:37.498] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:36:0) after 1m25s
[22:31:02.522] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:36:0)
[22:31:02.572] Build status: STARTED
[22:31:02.572] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:37:0) after 8m0s
[22:39:02.589] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:37:0)
[22:39:02.623] Build status: STARTED
[22:39:02.623] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:38:0) after 4m18s
[22:43:20.640] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:38:0)
[22:43:20.690] Build status: STARTED
[22:43:20.690] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:39:0) after 7m10s
[22:50:30.707] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:39:0)
[22:50:30.774] Build status: STARTED
[22:50:30.775] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:40:0) after 3m48s
[22:54:18.791] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:40:0)
[22:54:18.836] Build status: STARTED
[22:54:18.836] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:41:0) after 2m23s
[22:56:41.855] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:41:0)
[22:56:42.011] Build status: STARTED
[22:56:42.011] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:42:0) after 3m55s
[23:00:37.029] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:42:0)
[23:00:37.149] Build status: STARTED
[23:00:37.149] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:43:0) after 1m39s
[23:02:16.191] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:43:0)
[23:02:16.245] Build status: STARTED
[23:02:16.245] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:44:0) after 3m16s
[23:05:32.271] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:44:0)
[23:05:32.320] Build status: STARTED
[23:05:32.320] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:45:0) after 5m8s
[23:10:40.343] Handling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:45:0)
[23:10:40.379] Build status: STARTED
[23:10:40.380] Scheduling timer "check-buildbucket-build-status" (chromium/win-rel-dev:8939549168392691696:46:0) after 8m23s
[23:11:27.013] Received PubSub notification, asking Buildbucket for the build status
[23:11:27.061] Build:
{
"id": "8774119106457637201",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win-rel-dev"
},
"number": 1746,
"createdBy": "project:chromium",
"createTime": "2023-07-30T19:23:01.289385771Z",
"startTime": "2023-07-30T19:33:34.312947Z",
"endTime": "2023-07-30T23:11:23.936070Z",
"updateTime": "2023-07-30T23:11:23.936070Z",
"status": "INFRA_FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "cd92e094fd6759c0f437920e7567db640e53be4e",
"ref": "refs/heads/main"
}
}
}
[23:11:27.061] Invocation finished in 3h48m26.999813808s with status FAILED