[21:54:54.078] New invocation is queued and will start shortly
[21:54:55.179] Starting the invocation (attempt 1)
[21:54:55.217] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/4face79c361d6634c37bbb04a3f278018cd281e7"
[21:54:55.217] Popped gitiles commit info from properties and tags
[21:54:55.217] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[21:54:55.218] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[21:54:55.218] Buildbucket request:
{
"requestId": "8986197049365521600",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "75889f130cd80d6b60e3f09d0c52fc5ad55eee24"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@75889f130cd80d6b60e3f09d0c52fc5ad55eee24",
"title": "75889f130cd80d6b60e3f09d0c52fc5ad55eee24",
"url": "https://chromium.googlesource.com/infra/infra/+/75889f130cd80d6b60e3f09d0c52fc5ad55eee24"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "c82d6ab900ff601b888da2400db626d235463dbc"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@c82d6ab900ff601b888da2400db626d235463dbc",
"title": "c82d6ab900ff601b888da2400db626d235463dbc",
"url": "https://chromium.googlesource.com/infra/infra/+/c82d6ab900ff601b888da2400db626d235463dbc"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "ecfff48190f0409a96e6b0987b63ad1ff736a889"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@ecfff48190f0409a96e6b0987b63ad1ff736a889",
"title": "ecfff48190f0409a96e6b0987b63ad1ff736a889",
"url": "https://chromium.googlesource.com/infra/infra/+/ecfff48190f0409a96e6b0987b63ad1ff736a889"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "eddfc8cbb67453fc30d2148214334f9850882c84"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@eddfc8cbb67453fc30d2148214334f9850882c84",
"title": "eddfc8cbb67453fc30d2148214334f9850882c84",
"url": "https://chromium.googlesource.com/infra/infra/+/eddfc8cbb67453fc30d2148214334f9850882c84"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "8a5b54f04a93bc4d1dc776613db6a17eeb7adc6e"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@8a5b54f04a93bc4d1dc776613db6a17eeb7adc6e",
"title": "8a5b54f04a93bc4d1dc776613db6a17eeb7adc6e",
"url": "https://chromium.googlesource.com/infra/infra/+/8a5b54f04a93bc4d1dc776613db6a17eeb7adc6e"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "771a7c1baf5b9ac47ae879e17a2d77358a5a3614"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@771a7c1baf5b9ac47ae879e17a2d77358a5a3614",
"title": "771a7c1baf5b9ac47ae879e17a2d77358a5a3614",
"url": "https://chromium.googlesource.com/infra/infra/+/771a7c1baf5b9ac47ae879e17a2d77358a5a3614"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "2cb2d677dae13665e8e45d9017097a45b1246452"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@2cb2d677dae13665e8e45d9017097a45b1246452",
"title": "2cb2d677dae13665e8e45d9017097a45b1246452",
"url": "https://chromium.googlesource.com/infra/infra/+/2cb2d677dae13665e8e45d9017097a45b1246452"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "b309a62230643e2b98e91e67c8371715794452b6"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@b309a62230643e2b98e91e67c8371715794452b6",
"title": "b309a62230643e2b98e91e67c8371715794452b6",
"url": "https://chromium.googlesource.com/infra/infra/+/b309a62230643e2b98e91e67c8371715794452b6"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "4face79c361d6634c37bbb04a3f278018cd281e7"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@4face79c361d6634c37bbb04a3f278018cd281e7",
"title": "4face79c361d6634c37bbb04a3f278018cd281e7",
"url": "https://chromium.googlesource.com/infra/infra/+/4face79c361d6634c37bbb04a3f278018cd281e7"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "4face79c361d6634c37bbb04a3f278018cd281e7",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8986197049365521600"
},
{
"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:54:56.307] Scheduled build:
{
"id": "8820766987408381905",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 490,
"createdBy": "project:infra",
"createTime": "2022-03-02T21:54:55.312640057Z",
"updateTime": "2022-03-02T21:54:55.312640057Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "4face79c361d6634c37bbb04a3f278018cd281e7",
"ref": "refs/heads/main"
}
},
"canary": true
}
[21:54:56.308] Task URL: https://cr-buildbucket-dev.appspot.com/build/8820766987408381905
[21:54:56.308] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:2:0) after 8m22s
[22:03:18.328] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:2:0)
[22:03:18.356] Build status: SCHEDULED
[22:03:18.356] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:3:0) after 3m35s
[22:06:53.376] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:3:0)
[22:06:53.410] Build status: SCHEDULED
[22:06:53.410] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:4:0) after 2m38s
[22:09:31.437] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:4:0)
[22:09:31.477] Build status: SCHEDULED
[22:09:31.477] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:5:0) after 3m0s
[22:12:31.496] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:5:0)
[22:12:31.518] Build status: SCHEDULED
[22:12:31.518] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:6:0) after 2m31s
[22:15:02.539] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:6:0)
[22:15:02.584] Build status: SCHEDULED
[22:15:02.584] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:7:0) after 5m11s
[22:20:13.606] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:7:0)
[22:20:13.637] Build status: SCHEDULED
[22:20:13.637] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:8:0) after 1m41s
[22:21:54.659] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:8:0)
[22:21:54.684] Build status: SCHEDULED
[22:21:54.684] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:9:0) after 7m48s
[22:29:42.705] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:9:0)
[22:29:42.730] Build status: SCHEDULED
[22:29:42.730] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:10:0) after 1m35s
[22:31:17.750] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:10:0)
[22:31:17.801] Build status: SCHEDULED
[22:31:17.801] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:11:0) after 5m22s
[22:36:39.823] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:11:0)
[22:36:39.879] Build status: SCHEDULED
[22:36:39.879] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:12:0) after 8m22s
[22:45:01.907] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:12:0)
[22:45:01.943] Build status: SCHEDULED
[22:45:01.943] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:13:0) after 7m11s
[22:52:12.986] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:13:0)
[22:52:13.014] Build status: SCHEDULED
[22:52:13.014] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:14:0) after 6m52s
[22:59:05.037] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:14:0)
[22:59:05.075] Build status: SCHEDULED
[22:59:05.075] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:15:0) after 7m52s
[23:06:57.104] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:15:0)
[23:06:57.136] Build status: SCHEDULED
[23:06:57.136] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:16:0) after 2m34s
[23:09:31.158] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:16:0)
[23:09:31.197] Build status: SCHEDULED
[23:09:31.197] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:17:0) after 4m3s
[23:13:34.225] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:17:0)
[23:13:34.252] Build status: SCHEDULED
[23:13:34.252] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:18:0) after 5m1s
[23:18:35.277] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:18:0)
[23:18:35.310] Build status: SCHEDULED
[23:18:35.310] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:19:0) after 6m0s
[23:24:35.344] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:19:0)
[23:24:35.376] Build status: SCHEDULED
[23:24:35.376] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:20:0) after 4m21s
[23:28:56.402] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:20:0)
[23:28:56.448] Build status: SCHEDULED
[23:28:56.448] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:21:0) after 3m52s
[23:32:48.471] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:21:0)
[23:32:48.536] Build status: SCHEDULED
[23:32:48.536] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:22:0) after 7m40s
[23:40:28.558] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:22:0)
[23:40:28.595] Build status: SCHEDULED
[23:40:28.595] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:23:0) after 2m45s
[23:43:13.627] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:23:0)
[23:43:13.653] Build status: SCHEDULED
[23:43:13.653] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:24:0) after 6m28s
[23:49:41.676] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:24:0)
[23:49:41.708] Build status: SCHEDULED
[23:49:41.708] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:25:0) after 1m42s
[23:51:23.738] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:25:0)
[23:51:23.779] Build status: SCHEDULED
[23:51:23.779] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:26:0) after 2m44s
[23:54:07.809] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:26:0)
[23:54:07.846] Build status: SCHEDULED
[23:54:07.846] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:27:0) after 2m14s
[23:56:21.868] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:27:0)
[23:56:21.908] Build status: SCHEDULED
[23:56:21.908] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:28:0) after 7m39s
[00:04:00.934] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:28:0)
[00:04:00.958] Build status: SCHEDULED
[00:04:00.958] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:29:0) after 2m48s
[00:06:48.981] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:29:0)
[00:06:49.050] Build status: SCHEDULED
[00:06:49.050] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:30:0) after 7m45s
[00:14:34.086] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:30:0)
[00:14:34.116] Build status: SCHEDULED
[00:14:34.116] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:31:0) after 2m57s
[00:17:31.149] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:31:0)
[00:17:31.180] Build status: SCHEDULED
[00:17:31.180] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:32:0) after 1m37s
[00:19:08.200] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:32:0)
[00:19:08.429] Build status: SCHEDULED
[00:19:08.429] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:33:0) after 1m39s
[00:20:47.454] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:33:0)
[00:20:47.484] Build status: SCHEDULED
[00:20:47.484] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:34:0) after 4m24s
[00:25:11.738] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:34:0)
[00:25:11.800] Build status: SCHEDULED
[00:25:11.800] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:35:0) after 3m37s
[00:28:48.821] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:35:0)
[00:28:48.845] Build status: SCHEDULED
[00:28:48.845] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:36:0) after 1m55s
[00:30:43.867] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:36:0)
[00:30:43.913] Build status: SCHEDULED
[00:30:43.913] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:37:0) after 1m21s
[00:32:04.934] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:37:0)
[00:32:04.958] Build status: SCHEDULED
[00:32:04.958] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:38:0) after 6m45s
[00:38:49.982] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:38:0)
[00:38:50.031] Build status: SCHEDULED
[00:38:50.031] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:39:0) after 1m10s
[00:40:00.056] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:39:0)
[00:40:00.083] Build status: SCHEDULED
[00:40:00.083] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:40:0) after 4m55s
[00:44:55.124] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:40:0)
[00:44:55.194] Build status: SCHEDULED
[00:44:55.194] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:41:0) after 4m49s
[00:49:44.229] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:41:0)
[00:49:44.274] Build status: SCHEDULED
[00:49:44.274] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:42:0) after 6m24s
[00:56:08.299] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:42:0)
[00:56:08.323] Build status: SCHEDULED
[00:56:08.324] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:43:0) after 9m48s
[01:05:44.656] Received PubSub notification, asking Buildbucket for the build status
[01:05:44.730] Build status: STARTED
[01:05:56.345] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:43:0)
[01:05:56.384] Build status: STARTED
[01:05:56.384] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:45:0) after 5m36s
[01:11:32.456] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:45:0)
[01:11:32.506] Build status: STARTED
[01:11:32.506] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:46:0) after 5m45s
[01:17:18.497] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:46:0)
[01:17:18.536] Build status: STARTED
[01:17:18.536] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:47:0) after 9m26s
[01:26:44.558] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:47:0)
[01:26:44.618] Build status: STARTED
[01:26:44.618] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:48:0) after 9m57s
[01:36:41.698] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:48:0)
[01:36:41.735] Build status: STARTED
[01:36:41.735] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8986197049365521600:49:0) after 6m14s
[01:37:35.444] Received PubSub notification, asking Buildbucket for the build status
[01:37:35.484] Build:
{
"id": "8820766987408381905",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 490,
"createdBy": "project:infra",
"createTime": "2022-03-02T21:54:55.312640057Z",
"startTime": "2022-03-03T01:05:42.793705Z",
"endTime": "2022-03-03T01:37:33.351796255Z",
"updateTime": "2022-03-03T01:37:33.351796255Z",
"status": "INFRA_FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "4face79c361d6634c37bbb04a3f278018cd281e7",
"ref": "refs/heads/main"
}
},
"canary": true
}
[01:37:35.484] Invocation finished in 3h42m41.421879919s with status FAILED