[03:15:08.052] New invocation is queued and will start shortly
[03:15:09.129] Starting the invocation (attempt 1)
[03:15:09.164] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/399ddb1f491d171313481bde439eaaffb38fdcc5"
[03:15:09.164] Popped gitiles commit info from properties and tags
[03:15:09.164] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[03:15:09.164] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[03:15:09.165] Buildbucket request:
{
"requestId": "8958273036393694944",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"invocation": "8958273036393694944",
"job": "infra/infra-continuous-win11-64",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "244060b741971bd1e096bc8fcbab5a3c58959347"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@244060b741971bd1e096bc8fcbab5a3c58959347",
"title": "244060b741971bd1e096bc8fcbab5a3c58959347",
"url": "https://chromium.googlesource.com/infra/infra/+/244060b741971bd1e096bc8fcbab5a3c58959347"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "3775a0e438b14fb7af4a5ddf52c8116f6b311f72"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@3775a0e438b14fb7af4a5ddf52c8116f6b311f72",
"title": "3775a0e438b14fb7af4a5ddf52c8116f6b311f72",
"url": "https://chromium.googlesource.com/infra/infra/+/3775a0e438b14fb7af4a5ddf52c8116f6b311f72"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "0b04cc123f4be3b30790cfc2f71c63698a35f25b"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@0b04cc123f4be3b30790cfc2f71c63698a35f25b",
"title": "0b04cc123f4be3b30790cfc2f71c63698a35f25b",
"url": "https://chromium.googlesource.com/infra/infra/+/0b04cc123f4be3b30790cfc2f71c63698a35f25b"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "a2473c2a81e0aea0a2881c276d190f63ed667ac0"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@a2473c2a81e0aea0a2881c276d190f63ed667ac0",
"title": "a2473c2a81e0aea0a2881c276d190f63ed667ac0",
"url": "https://chromium.googlesource.com/infra/infra/+/a2473c2a81e0aea0a2881c276d190f63ed667ac0"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "5ceeb9124f3a3971a6449de138848a7967b4fbf8"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@5ceeb9124f3a3971a6449de138848a7967b4fbf8",
"title": "5ceeb9124f3a3971a6449de138848a7967b4fbf8",
"url": "https://chromium.googlesource.com/infra/infra/+/5ceeb9124f3a3971a6449de138848a7967b4fbf8"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "dc49255f80379f0de96b286125968e999d21b7ef"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@dc49255f80379f0de96b286125968e999d21b7ef",
"title": "dc49255f80379f0de96b286125968e999d21b7ef",
"url": "https://chromium.googlesource.com/infra/infra/+/dc49255f80379f0de96b286125968e999d21b7ef"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "7e1a943a3df3ace648f53085e992737d666aeee4"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@7e1a943a3df3ace648f53085e992737d666aeee4",
"title": "7e1a943a3df3ace648f53085e992737d666aeee4",
"url": "https://chromium.googlesource.com/infra/infra/+/7e1a943a3df3ace648f53085e992737d666aeee4"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "399ddb1f491d171313481bde439eaaffb38fdcc5"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@399ddb1f491d171313481bde439eaaffb38fdcc5",
"title": "399ddb1f491d171313481bde439eaaffb38fdcc5",
"url": "https://chromium.googlesource.com/infra/infra/+/399ddb1f491d171313481bde439eaaffb38fdcc5"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "399ddb1f491d171313481bde439eaaffb38fdcc5",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8958273036393694944"
},
{
"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"
}
}
[03:15:09.913] Scheduled build:
{
"id": "8792842974437136225",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 2627,
"createdBy": "project:infra",
"createTime": "2023-01-05T03:15:09.294193222Z",
"updateTime": "2023-01-05T03:15:09.294193222Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "399ddb1f491d171313481bde439eaaffb38fdcc5",
"ref": "refs/heads/main"
}
}
}
[03:15:09.913] Task URL: https://cr-buildbucket-dev.appspot.com/build/8792842974437136225
[03:15:09.913] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:2:0) after 6m14s
[03:21:23.937] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:2:0)
[03:21:23.962] Build status: SCHEDULED
[03:21:23.962] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:3:0) after 7m55s
[03:29:18.979] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:3:0)
[03:29:19.011] Build status: SCHEDULED
[03:29:19.011] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:4:0) after 3m36s
[03:32:55.759] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:4:0)
[03:32:55.796] Build status: SCHEDULED
[03:32:55.796] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:5:0) after 4m23s
[03:37:18.811] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:5:0)
[03:37:18.856] Build status: SCHEDULED
[03:37:18.856] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:6:0) after 5m6s
[03:42:24.875] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:6:0)
[03:42:24.904] Build status: SCHEDULED
[03:42:24.904] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:7:0) after 8m7s
[03:50:31.957] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:7:0)
[03:50:32.007] Build status: SCHEDULED
[03:50:32.007] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:8:0) after 6m57s
[03:57:29.026] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:8:0)
[03:57:29.074] Build status: SCHEDULED
[03:57:29.074] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:9:0) after 2m28s
[03:59:57.094] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:9:0)
[03:59:57.154] Build status: SCHEDULED
[03:59:57.154] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:10:0) after 3m21s
[04:03:18.181] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:10:0)
[04:03:18.243] Build status: SCHEDULED
[04:03:18.243] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:11:0) after 3m40s
[04:06:58.262] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:11:0)
[04:06:58.317] Build status: SCHEDULED
[04:06:58.317] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:12:0) after 5m21s
[04:12:19.338] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:12:0)
[04:12:19.391] Build status: SCHEDULED
[04:12:19.391] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:13:0) after 7m56s
[04:20:15.413] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:13:0)
[04:20:15.470] Build status: SCHEDULED
[04:20:15.470] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:14:0) after 4m40s
[04:24:55.490] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:14:0)
[04:24:55.534] Build status: SCHEDULED
[04:24:55.534] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:15:0) after 7m45s
[04:32:40.562] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:15:0)
[04:32:40.616] Build status: SCHEDULED
[04:32:40.616] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:16:0) after 9m20s
[04:42:00.651] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:16:0)
[04:42:00.694] Build status: SCHEDULED
[04:42:00.694] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:17:0) after 4m11s
[04:46:11.719] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:17:0)
[04:46:11.765] Build status: SCHEDULED
[04:46:11.765] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:18:0) after 2m40s
[04:48:51.825] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:18:0)
[04:48:51.902] Build status: SCHEDULED
[04:48:51.902] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:19:0) after 9m26s
[04:57:51.868] Received PubSub notification, asking Buildbucket for the build status
[04:57:51.916] Build status: STARTED
[04:58:17.923] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:19:0)
[04:58:17.963] Build status: STARTED
[04:58:17.963] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:21:0) after 9m14s
[05:07:31.984] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:21:0)
[05:07:32.037] Build status: STARTED
[05:07:32.037] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8958273036393694944:22:0) after 6m38s
[05:08:21.240] Received PubSub notification, asking Buildbucket for the build status
[05:08:21.274] Build:
{
"id": "8792842974437136225",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 2627,
"createdBy": "project:infra",
"createTime": "2023-01-05T03:15:09.294193222Z",
"startTime": "2023-01-05T04:57:51.118103Z",
"endTime": "2023-01-05T05:08:20.821620047Z",
"updateTime": "2023-01-05T05:08:20.821620047Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "399ddb1f491d171313481bde439eaaffb38fdcc5",
"ref": "refs/heads/main"
}
}
}
[05:08:21.274] Invocation finished in 1h53m13.23044821s with status FAILED