[20:46:00.957] New invocation is queued and will start shortly
[20:46:02.029] Starting the invocation (attempt 1)
[20:46:02.117] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/0371781ad6abf24993f9f0aa0d98aaf25719a9bf"
[20:46:02.117] Popped gitiles commit info from properties and tags
[20:46:02.117] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[20:46:02.117] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[20:46:02.118] Buildbucket request:
{
"requestId": "8988013322586329248",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "0371781ad6abf24993f9f0aa0d98aaf25719a9bf",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8988013322586329248"
},
{
"key": "scheduler_job_id",
"value": "chromium/win32-official"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[20:46:02.719] Scheduled build:
{
"id": "8822583260573295617",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win32-official"
},
"number": 3579,
"createdBy": "project:chromium",
"createTime": "2022-02-10T20:46:02.243360683Z",
"updateTime": "2022-02-10T20:46:02.243360683Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "0371781ad6abf24993f9f0aa0d98aaf25719a9bf",
"ref": "refs/heads/main"
}
}
}
[20:46:02.719] Task URL: https://cr-buildbucket.appspot.com/build/8822583260573295617
[20:46:02.719] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:2:0) after 4m43s
[20:50:31.878] Received PubSub notification, asking Buildbucket for the build status
[20:50:31.909] Build status: STARTED
[20:50:45.740] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:2:0)
[20:50:45.759] Build status: STARTED
[20:50:45.759] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:4:0) after 3m38s
[20:54:23.967] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:4:0)
[20:54:23.986] Build status: STARTED
[20:54:23.986] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:5:0) after 2m19s
[20:56:43.132] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:5:0)
[20:56:43.153] Build status: STARTED
[20:56:43.153] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:6:0) after 7m36s
[21:04:19.192] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:6:0)
[21:04:19.220] Build status: STARTED
[21:04:19.220] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:7:0) after 9m12s
[21:13:31.278] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:7:0)
[21:13:31.298] Build status: STARTED
[21:13:31.298] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:8:0) after 4m19s
[21:17:50.465] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:8:0)
[21:17:50.490] Build status: STARTED
[21:17:50.490] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:9:0) after 9m20s
[21:27:10.681] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:9:0)
[21:27:10.700] Build status: STARTED
[21:27:10.700] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:10:0) after 3m21s
[21:30:31.806] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:10:0)
[21:30:31.823] Build status: STARTED
[21:30:31.823] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:11:0) after 3m32s
[21:34:04.020] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:11:0)
[21:34:04.044] Build status: STARTED
[21:34:04.044] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:12:0) after 5m35s
[21:39:39.193] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:12:0)
[21:39:39.215] Build status: STARTED
[21:39:39.215] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:13:0) after 7m14s
[21:46:53.267] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:13:0)
[21:46:53.454] Build status: STARTED
[21:46:53.454] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:14:0) after 4m17s
[21:51:10.958] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:14:0)
[21:51:10.981] Build status: STARTED
[21:51:10.981] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:15:0) after 2m10s
[21:53:21.055] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:15:0)
[21:53:21.085] Build status: STARTED
[21:53:21.085] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:16:0) after 6m43s
[22:00:04.469] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:16:0)
[22:00:04.507] Build status: STARTED
[22:00:04.507] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:17:0) after 4m4s
[22:04:08.780] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:17:0)
[22:04:08.810] Build status: STARTED
[22:04:08.810] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:18:0) after 1m1s
[22:05:09.828] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:18:0)
[22:05:09.854] Build status: STARTED
[22:05:09.854] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:19:0) after 1m28s
[22:06:38.119] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:19:0)
[22:06:38.142] Build status: STARTED
[22:06:38.142] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:20:0) after 1m1s
[22:07:39.333] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:20:0)
[22:07:39.488] Build status: STARTED
[22:07:39.488] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:21:0) after 8m56s
[22:16:35.517] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:21:0)
[22:17:22.260] Build status: STARTED
[22:17:22.260] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:22:0) after 6m24s
[22:23:46.314] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:22:0)
[22:23:46.341] Build status: STARTED
[22:23:46.342] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:23:0) after 2m15s
[22:26:01.351] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:23:0)
[22:26:01.383] Build status: STARTED
[22:26:01.383] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:24:0) after 7m15s
[22:33:16.585] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:24:0)
[22:33:16.604] Build status: STARTED
[22:33:16.604] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:25:0) after 6m53s
[22:40:09.654] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:25:0)
[22:40:10.005] Build status: STARTED
[22:40:10.005] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:26:0) after 3m10s
[22:43:20.027] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:26:0)
[22:43:20.058] Build status: STARTED
[22:43:20.058] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:27:0) after 5m11s
[22:48:31.163] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:27:0)
[22:48:31.185] Build status: STARTED
[22:48:31.185] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:28:0) after 7m18s
[22:55:49.395] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:28:0)
[22:55:49.415] Build status: STARTED
[22:55:49.415] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:29:0) after 9m20s
[23:05:09.646] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:29:0)
[23:05:09.676] Build status: STARTED
[23:05:09.676] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:30:0) after 7m46s
[23:12:55.879] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:30:0)
[23:12:55.901] Build status: STARTED
[23:12:55.901] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:31:0) after 5m11s
[23:18:07.363] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:31:0)
[23:18:07.393] Build status: STARTED
[23:18:07.393] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:32:0) after 6m59s
[23:25:06.437] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:32:0)
[23:25:06.467] Build status: STARTED
[23:25:06.467] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:33:0) after 2m21s
[23:27:27.510] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:33:0)
[23:27:27.529] Build status: STARTED
[23:27:27.529] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:34:0) after 1m29s
[23:28:56.703] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:34:0)
[23:28:56.730] Build status: STARTED
[23:28:56.730] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:35:0) after 7m34s
[23:36:30.853] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:35:0)
[23:36:30.875] Build status: STARTED
[23:36:30.875] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:36:0) after 3m25s
[23:39:55.914] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:36:0)
[23:39:55.943] Build status: STARTED
[23:39:55.943] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:37:0) after 7m26s
[23:47:21.981] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:37:0)
[23:47:21.999] Build status: STARTED
[23:47:21.999] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:38:0) after 6m2s
[23:53:24.131] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:38:0)
[23:53:24.183] Build status: STARTED
[23:53:24.183] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:39:0) after 3m42s
[23:57:06.216] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:39:0)
[23:57:06.235] Build status: STARTED
[23:57:06.235] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:40:0) after 6m21s
[00:03:27.260] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:40:0)
[00:03:27.280] Build status: STARTED
[00:03:27.280] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:41:0) after 1m32s
[00:04:59.330] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:41:0)
[00:04:59.380] Build status: STARTED
[00:04:59.380] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:42:0) after 6m7s
[00:11:06.425] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:42:0)
[00:11:06.476] Build status: STARTED
[00:11:06.476] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:43:0) after 6m51s
[00:17:57.608] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:43:0)
[00:17:57.629] Build status: STARTED
[00:17:57.629] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:44:0) after 1m42s
[00:19:39.843] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:44:0)
[00:19:39.864] Build status: STARTED
[00:19:39.864] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:45:0) after 5m4s
[00:24:44.197] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:45:0)
[00:24:44.219] Build status: STARTED
[00:24:44.219] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:46:0) after 3m6s
[00:27:50.306] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:46:0)
[00:27:50.329] Build status: STARTED
[00:27:50.329] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:47:0) after 2m31s
[00:30:21.560] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:47:0)
[00:30:21.598] Build status: STARTED
[00:30:21.598] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:48:0) after 3m39s
[00:34:00.638] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:48:0)
[00:34:00.662] Build status: STARTED
[00:34:00.662] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:49:0) after 1m9s
[00:35:09.668] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:49:0)
[00:35:09.691] Build status: STARTED
[00:35:09.691] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:50:0) after 1m15s
[00:36:24.884] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:50:0)
[00:36:24.918] Build status: STARTED
[00:36:24.918] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:51:0) after 7m10s
[00:43:34.997] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:51:0)
[00:43:35.022] Build status: STARTED
[00:43:35.022] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:52:0) after 8m10s
[00:51:45.145] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:52:0)
[00:51:45.168] Build status: STARTED
[00:51:45.168] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:53:0) after 5m59s
[00:57:44.193] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:53:0)
[00:57:44.213] Build status: STARTED
[00:57:44.213] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:54:0) after 4m13s
[01:01:57.238] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:54:0)
[01:01:57.258] Build status: STARTED
[01:01:57.258] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:55:0) after 1m22s
[01:03:19.366] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:55:0)
[01:03:19.388] Build status: STARTED
[01:03:19.388] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:56:0) after 3m8s
[01:06:27.412] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:56:0)
[01:06:27.462] Build status: STARTED
[01:06:27.462] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:57:0) after 3m26s
[01:09:53.485] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:57:0)
[01:09:53.516] Build status: STARTED
[01:09:53.516] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:58:0) after 1m39s
[01:11:32.610] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:58:0)
[01:11:32.643] Build status: STARTED
[01:11:32.643] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:59:0) after 5m30s
[01:17:02.839] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:59:0)
[01:17:02.948] Build status: STARTED
[01:17:02.948] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:60:0) after 9m11s
[01:26:13.998] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:60:0)
[01:26:14.021] Build status: STARTED
[01:26:14.021] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:61:0) after 7m38s
[01:33:52.046] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:61:0)
[01:33:52.071] Build status: STARTED
[01:33:52.071] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:62:0) after 1m58s
[01:35:50.220] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:62:0)
[01:35:50.253] Build status: STARTED
[01:35:50.253] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8988013322586329248:63:0) after 6m4s
[01:41:45.376] Received PubSub notification, asking Buildbucket for the build status
[01:41:45.400] Build:
{
"id": "8822583260573295617",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win32-official"
},
"number": 3579,
"createdBy": "project:chromium",
"createTime": "2022-02-10T20:46:02.243360683Z",
"startTime": "2022-02-10T20:50:31.045351Z",
"endTime": "2022-02-11T01:41:45.026699517Z",
"updateTime": "2022-02-11T01:41:45.026699517Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "0371781ad6abf24993f9f0aa0d98aaf25719a9bf",
"ref": "refs/heads/main"
}
}
}
[01:41:45.400] Invocation finished in 4h55m44.459642662s with status SUCCEEDED