[18:46:59.342] New invocation is queued and will start shortly
[18:47:00.388] Starting the invocation (attempt 1)
[18:47:00.428] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/3eead713655a1086b6b6a02f5ee853a9d5d3f12e"
[18:47:00.428] Popped gitiles commit info from properties and tags
[18:47:00.428] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[18:47:00.428] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[18:47:00.428] Buildbucket request:
{
"requestId": "8989560959539321056",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win32-official"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "3eead713655a1086b6b6a02f5ee853a9d5d3f12e",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8989560959539321056"
},
{
"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"
}
}
[18:47:00.904] Scheduled build:
{
"id": "8824130897678219873",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win32-official"
},
"number": 3495,
"createdBy": "project:chromium",
"createTime": "2022-01-24T18:47:00.485859340Z",
"updateTime": "2022-01-24T18:47:00.485859340Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "3eead713655a1086b6b6a02f5ee853a9d5d3f12e",
"ref": "refs/heads/main"
}
}
}
[18:47:00.904] Task URL: https://cr-buildbucket.appspot.com/build/8824130897678219873
[18:47:00.904] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:2:0) after 4m23s
[18:51:23.916] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:2:0)
[18:51:23.982] Build status: SCHEDULED
[18:51:23.982] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:3:0) after 6m15s
[18:52:36.700] Received PubSub notification, asking Buildbucket for the build status
[18:52:36.782] Build status: STARTED
[18:57:39.203] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:3:0)
[18:57:39.229] Build status: STARTED
[18:57:39.229] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:5:0) after 1m22s
[18:59:01.290] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:5:0)
[18:59:01.322] Build status: STARTED
[18:59:01.322] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:6:0) after 5m2s
[19:04:03.799] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:6:0)
[19:04:03.820] Build status: STARTED
[19:04:03.820] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:7:0) after 8m36s
[19:12:39.842] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:7:0)
[19:12:39.876] Build status: STARTED
[19:12:39.876] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:8:0) after 2m58s
[19:15:37.989] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:8:0)
[19:15:38.013] Build status: STARTED
[19:15:38.013] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:9:0) after 9m7s
[19:24:45.271] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:9:0)
[19:24:45.368] Build status: STARTED
[19:24:45.368] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:10:0) after 8m0s
[19:32:45.697] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:10:0)
[19:32:45.782] Build status: STARTED
[19:32:45.782] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:11:0) after 4m52s
[19:37:37.806] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:11:0)
[19:37:37.826] Build status: STARTED
[19:37:37.826] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:12:0) after 5m48s
[19:43:25.885] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:12:0)
[19:43:25.952] Build status: STARTED
[19:43:25.952] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:13:0) after 8m37s
[19:52:02.973] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:13:0)
[19:52:02.998] Build status: STARTED
[19:52:02.998] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:14:0) after 9m27s
[20:01:30.079] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:14:0)
[20:01:30.120] Build status: STARTED
[20:01:30.120] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:15:0) after 1m8s
[20:02:38.142] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:15:0)
[20:02:38.264] Build status: STARTED
[20:02:38.264] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:16:0) after 2m51s
[20:05:29.292] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:16:0)
[20:05:29.315] Build status: STARTED
[20:05:29.315] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:17:0) after 8m57s
[20:14:26.294] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:17:0)
[20:14:26.316] Build status: STARTED
[20:14:26.316] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:18:0) after 2m47s
[20:17:13.440] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:18:0)
[20:17:13.461] Build status: STARTED
[20:17:13.461] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:19:0) after 8m27s
[20:25:40.896] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:19:0)
[20:25:41.047] Build status: STARTED
[20:25:41.047] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:20:0) after 8m31s
[20:34:12.098] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:20:0)
[20:34:12.123] Build status: STARTED
[20:34:12.123] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:21:0) after 5m13s
[20:39:25.150] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:21:0)
[20:39:25.172] Build status: STARTED
[20:39:25.172] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:22:0) after 3m17s
[20:42:42.192] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:22:0)
[20:42:42.214] Build status: STARTED
[20:42:42.214] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:23:0) after 1m25s
[20:44:07.536] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:23:0)
[20:44:07.557] Build status: STARTED
[20:44:07.557] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:24:0) after 9m46s
[20:53:53.896] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:24:0)
[20:53:53.932] Build status: STARTED
[20:53:53.932] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:25:0) after 8m15s
[21:02:09.227] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:25:0)
[21:02:09.259] Build status: STARTED
[21:02:09.259] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:26:0) after 6m15s
[21:08:24.282] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:26:0)
[21:08:24.356] Build status: STARTED
[21:08:24.356] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:27:0) after 7m51s
[21:16:15.524] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:27:0)
[21:16:15.574] Build status: STARTED
[21:16:15.574] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:28:0) after 9m21s
[21:25:36.573] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:28:0)
[21:25:36.608] Build status: STARTED
[21:25:36.608] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:29:0) after 3m57s
[21:29:33.682] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:29:0)
[21:29:33.703] Build status: STARTED
[21:29:33.703] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:30:0) after 6m31s
[21:36:04.728] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:30:0)
[21:36:04.757] Build status: STARTED
[21:36:04.757] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:31:0) after 6m59s
[21:43:03.861] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:31:0)
[21:43:03.889] Build status: STARTED
[21:43:03.889] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:32:0) after 1m8s
[21:44:11.925] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:32:0)
[21:44:11.945] Build status: STARTED
[21:44:11.945] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:33:0) after 1m52s
[21:46:03.975] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:33:0)
[21:46:04.153] Build status: STARTED
[21:46:04.153] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:34:0) after 7m51s
[21:53:55.231] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:34:0)
[21:53:55.348] Build status: STARTED
[21:53:55.348] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:35:0) after 3m6s
[21:57:01.367] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:35:0)
[21:57:01.390] Build status: STARTED
[21:57:01.390] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:36:0) after 5m6s
[22:02:07.465] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:36:0)
[22:02:07.486] Build status: STARTED
[22:02:07.486] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:37:0) after 4m50s
[22:06:57.510] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:37:0)
[22:06:57.539] Build status: STARTED
[22:06:57.539] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:38:0) after 7m23s
[22:14:20.563] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:38:0)
[22:14:20.595] Build status: STARTED
[22:14:20.595] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:39:0) after 8m33s
[22:22:53.716] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:39:0)
[22:22:53.735] Build status: STARTED
[22:22:53.735] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:40:0) after 2m16s
[22:25:09.764] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:40:0)
[22:25:09.791] Build status: STARTED
[22:25:09.791] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:41:0) after 3m33s
[22:28:43.009] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:41:0)
[22:28:43.033] Build status: STARTED
[22:28:43.033] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:42:0) after 3m0s
[22:31:44.018] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:42:0)
[22:31:44.076] Build status: STARTED
[22:31:44.076] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:43:0) after 7m22s
[22:39:06.101] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:43:0)
[22:39:06.165] Build status: STARTED
[22:39:06.165] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:44:0) after 4m42s
[22:43:48.272] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:44:0)
[22:43:48.294] Build status: STARTED
[22:43:48.294] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:45:0) after 3m25s
[22:47:13.287] Handling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:45:0)
[22:47:13.309] Build status: STARTED
[22:47:13.309] Scheduling timer "check-buildbucket-build-status" (chromium/win32-official:8989560959539321056:46:0) after 5m20s
[22:50:13.754] Received PubSub notification, asking Buildbucket for the build status
[22:50:13.837] Build:
{
"id": "8824130897678219873",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "win32-official"
},
"number": 3495,
"createdBy": "project:chromium",
"createTime": "2022-01-24T18:47:00.485859340Z",
"startTime": "2022-01-24T18:52:36.146302Z",
"endTime": "2022-01-24T22:50:13.183736535Z",
"updateTime": "2022-01-24T22:50:13.183736535Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "3eead713655a1086b6b6a02f5ee853a9d5d3f12e",
"ref": "refs/heads/main"
}
}
}
[22:50:13.837] Invocation finished in 4h3m14.510053496s with status SUCCEEDED