[21:10:50.067] New invocation is queued and will start shortly
[21:10:51.145] Starting the invocation (attempt 1)
[21:10:51.174] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/d121fe800d123c438d925f8a7df8822edd686a8e"
[21:10:51.174] Popped gitiles commit info from properties and tags
[21:10:51.174] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[21:10:51.174] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[21:10:51.174] Buildbucket request:
{
"requestId": "8934921938822393280",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"invocation": "8934921938822393280",
"job": "infra/infra-continuous-win11-64",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "01c9c185d94e78baf30b2ce843bde52fea947ab6"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@01c9c185d94e78baf30b2ce843bde52fea947ab6",
"title": "01c9c185d94e78baf30b2ce843bde52fea947ab6",
"url": "https://chromium.googlesource.com/infra/infra/+/01c9c185d94e78baf30b2ce843bde52fea947ab6"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "b780cbbbb1087a611dfc84a73964ad2bb2934e7b"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@b780cbbbb1087a611dfc84a73964ad2bb2934e7b",
"title": "b780cbbbb1087a611dfc84a73964ad2bb2934e7b",
"url": "https://chromium.googlesource.com/infra/infra/+/b780cbbbb1087a611dfc84a73964ad2bb2934e7b"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "fb0f1a94d0669eca6046c0410d030e05f10b3efc"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@fb0f1a94d0669eca6046c0410d030e05f10b3efc",
"title": "fb0f1a94d0669eca6046c0410d030e05f10b3efc",
"url": "https://chromium.googlesource.com/infra/infra/+/fb0f1a94d0669eca6046c0410d030e05f10b3efc"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "64dd082b513ddf07676e76a12f2daaf9b64ba541"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@64dd082b513ddf07676e76a12f2daaf9b64ba541",
"title": "64dd082b513ddf07676e76a12f2daaf9b64ba541",
"url": "https://chromium.googlesource.com/infra/infra/+/64dd082b513ddf07676e76a12f2daaf9b64ba541"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "b54807615bf3ff88752ea3d232880790422252f8"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@b54807615bf3ff88752ea3d232880790422252f8",
"title": "b54807615bf3ff88752ea3d232880790422252f8",
"url": "https://chromium.googlesource.com/infra/infra/+/b54807615bf3ff88752ea3d232880790422252f8"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "5ca95201f8e1326ed5fe69999b2bdad86ea61ea1"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@5ca95201f8e1326ed5fe69999b2bdad86ea61ea1",
"title": "5ca95201f8e1326ed5fe69999b2bdad86ea61ea1",
"url": "https://chromium.googlesource.com/infra/infra/+/5ca95201f8e1326ed5fe69999b2bdad86ea61ea1"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "2836816fbfe6af6f088e427beae931df97477194"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@2836816fbfe6af6f088e427beae931df97477194",
"title": "2836816fbfe6af6f088e427beae931df97477194",
"url": "https://chromium.googlesource.com/infra/infra/+/2836816fbfe6af6f088e427beae931df97477194"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "d121fe800d123c438d925f8a7df8822edd686a8e"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@d121fe800d123c438d925f8a7df8822edd686a8e",
"title": "d121fe800d123c438d925f8a7df8822edd686a8e",
"url": "https://chromium.googlesource.com/infra/infra/+/d121fe800d123c438d925f8a7df8822edd686a8e"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "d121fe800d123c438d925f8a7df8822edd686a8e",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8934921938822393280"
},
{
"key": "scheduler_job_id",
"value": "infra/infra-continuous-win11-64"
},
{
"key": "user_agent",
"value": "luci-scheduler-dev"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
}
}
[21:10:52.084] Scheduled build:
{
"id": "8769491876930400433",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 4361,
"createdBy": "project:infra",
"createTime": "2023-09-19T21:10:51.246673680Z",
"updateTime": "2023-09-19T21:10:51.246673680Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "d121fe800d123c438d925f8a7df8822edd686a8e",
"ref": "refs/heads/main"
}
}
}
[21:10:52.084] Task URL: https://cr-buildbucket-dev.appspot.com/build/8769491876930400433
[21:10:52.084] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:2:0) after 5m40s
[21:10:52.995] Received PubSub notification, asking Buildbucket for the build status
[21:10:53.019] Build status: SCHEDULED
[21:16:32.105] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:2:0)
[21:16:32.156] Build status: SCHEDULED
[21:16:32.156] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:4:0) after 9m27s
[21:25:59.175] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:4:0)
[21:25:59.199] Build status: SCHEDULED
[21:25:59.200] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:5:0) after 6m54s
[21:32:53.255] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:5:0)
[21:32:53.285] Build status: SCHEDULED
[21:32:53.285] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:6:0) after 8m49s
[21:41:42.301] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:6:0)
[21:41:42.423] Build status: SCHEDULED
[21:41:42.424] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:7:0) after 4m47s
[21:46:29.440] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:7:0)
[21:46:29.473] Build status: SCHEDULED
[21:46:29.473] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:8:0) after 2m35s
[21:49:04.507] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:8:0)
[21:49:04.556] Build status: SCHEDULED
[21:49:04.556] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:9:0) after 5m40s
[21:54:44.580] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:9:0)
[21:54:44.603] Build status: SCHEDULED
[21:54:44.603] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:10:0) after 6m48s
[22:01:32.624] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:10:0)
[22:01:32.658] Build status: SCHEDULED
[22:01:32.658] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:11:0) after 2m24s
[22:03:56.687] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:11:0)
[22:03:56.750] Build status: SCHEDULED
[22:03:56.750] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:12:0) after 7m55s
[22:11:51.798] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:12:0)
[22:11:51.889] Build status: SCHEDULED
[22:11:51.889] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:13:0) after 8m39s
[22:20:30.906] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:13:0)
[22:20:30.935] Build status: SCHEDULED
[22:20:30.935] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:14:0) after 3m54s
[22:24:24.968] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:14:0)
[22:24:25.005] Build status: SCHEDULED
[22:24:25.005] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:15:0) after 9m48s
[22:34:13.025] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:15:0)
[22:34:13.054] Build status: SCHEDULED
[22:34:13.054] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:16:0) after 6m35s
[22:40:48.090] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:16:0)
[22:40:48.128] Build status: SCHEDULED
[22:40:48.128] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:17:0) after 9m0s
[22:49:48.145] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:17:0)
[22:49:48.176] Build status: SCHEDULED
[22:49:48.176] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:18:0) after 4m57s
[22:54:45.198] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:18:0)
[22:54:45.232] Build status: SCHEDULED
[22:54:45.232] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:19:0) after 9m45s
[23:03:39.243] Received PubSub notification, asking Buildbucket for the build status
[23:03:39.277] Build status: STARTED
[23:04:30.321] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:19:0)
[23:04:30.351] Build status: STARTED
[23:04:30.351] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:21:0) after 2m50s
[23:07:20.370] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:21:0)
[23:07:20.474] Build status: STARTED
[23:07:20.474] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:22:0) after 1m53s
[23:09:13.493] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:22:0)
[23:09:13.580] Build status: STARTED
[23:09:13.580] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:23:0) after 6m23s
[23:15:36.602] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:23:0)
[23:15:36.642] Build status: STARTED
[23:15:36.643] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8934921938822393280:24:0) after 4m9s
[23:17:53.332] Received PubSub notification, asking Buildbucket for the build status
[23:17:53.370] Build:
{
"id": "8769491876930400433",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 4361,
"createdBy": "project:infra",
"createTime": "2023-09-19T21:10:51.246673680Z",
"startTime": "2023-09-19T23:03:38.685091Z",
"endTime": "2023-09-19T23:17:52.008725473Z",
"updateTime": "2023-09-19T23:17:52.008725473Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "d121fe800d123c438d925f8a7df8822edd686a8e",
"ref": "refs/heads/main"
}
}
}
[23:17:53.370] Invocation finished in 2h7m3.312276138s with status SUCCEEDED