[20:28:51.424] New invocation is queued and will start shortly
[20:28:53.167] Starting the invocation (attempt 1)
[20:28:53.210] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/ba2435da5b9dbdb4f036b093ae98d174cb4b0f63"
[20:28:53.210] Popped gitiles commit info from properties and tags
[20:28:53.210] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[20:28:53.210] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[20:28:53.210] Buildbucket request:
{
"requestId": "8979498287286266688",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Windows deterministic"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "ba2435da5b9dbdb4f036b093ae98d174cb4b0f63",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8979498287286266688"
},
{
"key": "scheduler_job_id",
"value": "chromium/Windows deterministic"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[20:28:53.785] Scheduled build:
{
"id": "8814068224670102433",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Windows deterministic"
},
"number": 20276,
"createdBy": "project:chromium",
"createTime": "2022-05-15T20:28:53.287759628Z",
"updateTime": "2022-05-15T20:28:53.287759628Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "ba2435da5b9dbdb4f036b093ae98d174cb4b0f63",
"ref": "refs/heads/main"
}
}
}
[20:28:53.786] Task URL: https://cr-buildbucket.appspot.com/build/8814068224670102433
[20:28:53.786] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:2:0) after 4m18s
[20:33:11.886] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:2:0)
[20:33:11.908] Build status: SCHEDULED
[20:33:11.908] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:3:0) after 1m58s
[20:35:09.924] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:3:0)
[20:35:09.969] Build status: SCHEDULED
[20:35:09.969] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:4:0) after 1m22s
[20:36:32.105] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:4:0)
[20:36:32.130] Build status: SCHEDULED
[20:36:32.130] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:5:0) after 8m33s
[20:41:07.442] Received PubSub notification, asking Buildbucket for the build status
[20:41:07.472] Build status: STARTED
[20:45:05.181] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:5:0)
[20:45:05.216] Build status: STARTED
[20:45:05.216] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:7:0) after 7m50s
[20:52:55.266] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:7:0)
[20:52:55.285] Build status: STARTED
[20:52:55.285] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:8:0) after 5m47s
[20:58:42.411] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:8:0)
[20:58:42.441] Build status: STARTED
[20:58:42.441] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:9:0) after 3m58s
[21:02:40.457] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:9:0)
[21:02:40.477] Build status: STARTED
[21:02:40.477] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:10:0) after 9m9s
[21:11:49.609] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:10:0)
[21:11:49.629] Build status: STARTED
[21:11:49.629] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:11:0) after 8m20s
[21:20:09.645] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:11:0)
[21:20:10.514] Build status: STARTED
[21:20:10.514] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:12:0) after 2m31s
[21:22:41.628] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:12:0)
[21:22:41.678] Build status: STARTED
[21:22:41.678] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:13:0) after 3m3s
[21:25:44.753] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:13:0)
[21:25:44.790] Build status: STARTED
[21:25:44.791] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:14:0) after 4m42s
[21:30:27.708] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:14:0)
[21:30:27.731] Build status: STARTED
[21:30:27.731] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:15:0) after 5m40s
[21:36:07.812] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:15:0)
[21:36:07.873] Build status: STARTED
[21:36:07.873] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:16:0) after 7m10s
[21:43:17.941] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:16:0)
[21:43:18.070] Build status: STARTED
[21:43:18.070] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:17:0) after 9m21s
[21:52:40.503] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:17:0)
[21:52:40.523] Build status: STARTED
[21:52:40.523] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:18:0) after 7m26s
[22:00:06.840] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:18:0)
[22:00:06.865] Build status: STARTED
[22:00:06.865] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:19:0) after 4m17s
[22:04:23.882] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:19:0)
[22:04:23.904] Build status: STARTED
[22:04:23.904] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:20:0) after 9m35s
[22:13:58.922] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:20:0)
[22:13:58.956] Build status: STARTED
[22:13:58.956] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:21:0) after 5m15s
[22:19:14.071] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:21:0)
[22:19:14.094] Build status: STARTED
[22:19:14.094] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:22:0) after 7m15s
[22:26:29.114] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:22:0)
[22:26:29.145] Build status: STARTED
[22:26:29.145] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:23:0) after 5m11s
[22:31:40.163] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:23:0)
[22:31:40.189] Build status: STARTED
[22:31:40.189] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:24:0) after 5m8s
[22:36:48.210] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:24:0)
[22:36:48.229] Build status: STARTED
[22:36:48.229] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:25:0) after 9m6s
[22:45:54.377] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:25:0)
[22:45:54.427] Build status: STARTED
[22:45:54.427] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:26:0) after 5m0s
[22:50:54.695] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:26:0)
[22:50:54.721] Build status: STARTED
[22:50:54.721] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:27:0) after 7m45s
[22:58:39.764] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:27:0)
[22:58:39.789] Build status: STARTED
[22:58:39.789] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:28:0) after 9m25s
[23:08:05.211] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:28:0)
[23:08:05.230] Build status: STARTED
[23:08:05.230] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:29:0) after 6m28s
[23:14:33.255] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:29:0)
[23:14:33.275] Build status: STARTED
[23:14:33.275] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:30:0) after 8m7s
[23:22:40.327] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:30:0)
[23:22:40.378] Build status: STARTED
[23:22:40.378] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:31:0) after 5m11s
[23:27:52.351] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:31:0)
[23:27:52.390] Build status: STARTED
[23:27:52.390] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:32:0) after 1m12s
[23:29:04.616] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:32:0)
[23:29:04.639] Build status: STARTED
[23:29:04.639] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:33:0) after 6m10s
[23:35:14.825] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:33:0)
[23:35:14.861] Build status: STARTED
[23:35:14.861] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:34:0) after 6m5s
[23:41:20.550] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:34:0)
[23:41:20.586] Build status: STARTED
[23:41:20.586] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:35:0) after 1m40s
[23:43:00.975] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:35:0)
[23:43:01.003] Build status: STARTED
[23:43:01.003] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:36:0) after 2m58s
[23:45:59.350] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:36:0)
[23:45:59.378] Build status: STARTED
[23:45:59.378] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:37:0) after 5m15s
[23:51:14.616] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:37:0)
[23:51:14.636] Build status: STARTED
[23:51:14.636] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:38:0) after 7m44s
[23:58:58.668] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:38:0)
[23:58:58.703] Build status: STARTED
[23:58:58.703] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:39:0) after 2m14s
[00:01:12.725] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:39:0)
[00:01:12.765] Build status: STARTED
[00:01:12.765] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:40:0) after 8m32s
[00:09:44.768] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:40:0)
[00:09:44.820] Build status: STARTED
[00:09:44.820] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:41:0) after 2m31s
[00:12:15.840] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:41:0)
[00:12:15.862] Build status: STARTED
[00:12:15.862] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:42:0) after 1m22s
[00:13:37.902] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:42:0)
[00:13:37.929] Build status: STARTED
[00:13:37.929] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:43:0) after 2m56s
[00:16:33.951] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:43:0)
[00:16:33.973] Build status: STARTED
[00:16:33.973] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:44:0) after 9m17s
[00:25:51.000] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:44:0)
[00:25:51.025] Build status: STARTED
[00:25:51.025] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:45:0) after 2m39s
[00:28:30.707] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:45:0)
[00:28:30.733] Build status: STARTED
[00:28:30.733] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:46:0) after 2m11s
[00:30:41.869] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:46:0)
[00:30:41.892] Build status: STARTED
[00:30:41.892] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:47:0) after 6m34s
[00:37:16.168] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:47:0)
[00:37:16.192] Build status: STARTED
[00:37:16.192] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:48:0) after 7m21s
[00:44:37.212] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:48:0)
[00:44:37.261] Build status: STARTED
[00:44:37.261] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:49:0) after 6m27s
[00:51:04.376] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:49:0)
[00:51:04.446] Build status: STARTED
[00:51:04.446] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:50:0) after 4m48s
[00:55:52.509] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:50:0)
[00:55:52.529] Build status: STARTED
[00:55:52.529] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:51:0) after 2m46s
[00:58:38.637] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:51:0)
[00:58:38.660] Build status: STARTED
[00:58:38.660] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:52:0) after 9m48s
[01:08:26.633] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:52:0)
[01:08:26.680] Build status: STARTED
[01:08:26.680] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:53:0) after 1m29s
[01:09:55.662] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:53:0)
[01:09:55.694] Build status: STARTED
[01:09:55.694] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:54:0) after 8m39s
[01:18:34.717] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:54:0)
[01:18:34.739] Build status: STARTED
[01:18:34.739] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:55:0) after 3m41s
[01:22:15.957] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:55:0)
[01:22:15.980] Build status: STARTED
[01:22:15.980] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:56:0) after 4m19s
[01:26:35.003] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:56:0)
[01:26:35.038] Build status: STARTED
[01:26:35.038] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:57:0) after 7m41s
[01:34:16.890] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:57:0)
[01:34:16.921] Build status: STARTED
[01:34:16.921] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:58:0) after 8m11s
[01:42:27.944] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:58:0)
[01:42:27.967] Build status: STARTED
[01:42:27.967] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:59:0) after 5m50s
[01:48:18.040] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:59:0)
[01:48:18.058] Build status: STARTED
[01:48:18.058] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:60:0) after 6m47s
[01:55:05.303] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:60:0)
[01:55:05.417] Build status: STARTED
[01:55:05.417] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:61:0) after 1m18s
[01:56:23.484] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:61:0)
[01:56:23.547] Build status: STARTED
[01:56:23.547] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:62:0) after 2m51s
[01:59:14.574] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:62:0)
[01:59:14.628] Build status: STARTED
[01:59:14.628] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:63:0) after 7m23s
[02:06:37.678] Handling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:63:0)
[02:06:37.700] Build status: STARTED
[02:06:37.700] Scheduling timer "check-buildbucket-build-status" (chromium/Windows deterministic:8979498287286266688:64:0) after 6m0s
[02:12:23.548] Received PubSub notification, asking Buildbucket for the build status
[02:12:23.567] Build:
{
"id": "8814068224670102433",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "Windows deterministic"
},
"number": 20276,
"createdBy": "project:chromium",
"createTime": "2022-05-15T20:28:53.287759628Z",
"startTime": "2022-05-15T20:41:06.975451Z",
"endTime": "2022-05-16T02:12:22.989380380Z",
"updateTime": "2022-05-16T02:12:22.989380380Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "ba2435da5b9dbdb4f036b093ae98d174cb4b0f63",
"ref": "refs/heads/main"
}
}
}
[02:12:23.567] Invocation finished in 5h43m32.157786102s with status SUCCEEDED