[06:29:30.221] New invocation is queued and will start shortly
[06:29:31.304] Starting the invocation (attempt 1)
[06:29:31.344] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/e1f5b5f1acea4348eb02865aee7d636e9cc63e34"
[06:29:31.344] Popped gitiles commit info from properties and tags
[06:29:31.344] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[06:29:31.345] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[06:29:31.345] Buildbucket request:
{
"requestId": "8955180510868828736",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"invocation": "8955180510868828736",
"job": "infra/infra-continuous-win11-64",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "f04eb2587e4e419813cf2a873e348ce2d6369f31"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@f04eb2587e4e419813cf2a873e348ce2d6369f31",
"title": "f04eb2587e4e419813cf2a873e348ce2d6369f31",
"url": "https://chromium.googlesource.com/infra/infra/+/f04eb2587e4e419813cf2a873e348ce2d6369f31"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "73d3e8f8fdbaa17c87e4fae09d373ddc25a290f3"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@73d3e8f8fdbaa17c87e4fae09d373ddc25a290f3",
"title": "73d3e8f8fdbaa17c87e4fae09d373ddc25a290f3",
"url": "https://chromium.googlesource.com/infra/infra/+/73d3e8f8fdbaa17c87e4fae09d373ddc25a290f3"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "7749fdef4e1e2106d2a260b28c8d9762bce7c9b5"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@7749fdef4e1e2106d2a260b28c8d9762bce7c9b5",
"title": "7749fdef4e1e2106d2a260b28c8d9762bce7c9b5",
"url": "https://chromium.googlesource.com/infra/infra/+/7749fdef4e1e2106d2a260b28c8d9762bce7c9b5"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "56201173c3fc5023bddbf3bbe048ca0b313aa02b"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@56201173c3fc5023bddbf3bbe048ca0b313aa02b",
"title": "56201173c3fc5023bddbf3bbe048ca0b313aa02b",
"url": "https://chromium.googlesource.com/infra/infra/+/56201173c3fc5023bddbf3bbe048ca0b313aa02b"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "722a9a34c2388f5eb20c7a7120d2f25db4f9f1eb"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@722a9a34c2388f5eb20c7a7120d2f25db4f9f1eb",
"title": "722a9a34c2388f5eb20c7a7120d2f25db4f9f1eb",
"url": "https://chromium.googlesource.com/infra/infra/+/722a9a34c2388f5eb20c7a7120d2f25db4f9f1eb"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "e1f5b5f1acea4348eb02865aee7d636e9cc63e34"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@e1f5b5f1acea4348eb02865aee7d636e9cc63e34",
"title": "e1f5b5f1acea4348eb02865aee7d636e9cc63e34",
"url": "https://chromium.googlesource.com/infra/infra/+/e1f5b5f1acea4348eb02865aee7d636e9cc63e34"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "e1f5b5f1acea4348eb02865aee7d636e9cc63e34",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8955180510868828736"
},
{
"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"
}
}
[06:29:32.502] Scheduled build:
{
"id": "8789750448804303713",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 2841,
"createdBy": "project:infra",
"createTime": "2023-02-08T06:29:31.563148152Z",
"updateTime": "2023-02-08T06:29:31.563148152Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "e1f5b5f1acea4348eb02865aee7d636e9cc63e34",
"ref": "refs/heads/main"
}
},
"canary": true
}
[06:29:32.502] Task URL: https://cr-buildbucket-dev.appspot.com/build/8789750448804303713
[06:29:32.502] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:2:0) after 3m37s
[06:33:09.519] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:2:0)
[06:33:09.574] Build status: SCHEDULED
[06:33:09.574] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:3:0) after 3m44s
[06:36:53.590] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:3:0)
[06:36:53.626] Build status: SCHEDULED
[06:36:53.626] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:4:0) after 4m17s
[06:41:10.645] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:4:0)
[06:41:10.685] Build status: SCHEDULED
[06:41:10.685] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:5:0) after 8m19s
[06:49:29.706] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:5:0)
[06:49:29.738] Build status: SCHEDULED
[06:49:29.738] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:6:0) after 7m48s
[06:57:17.768] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:6:0)
[06:57:17.819] Build status: SCHEDULED
[06:57:17.819] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:7:0) after 1m14s
[06:58:31.837] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:7:0)
[06:58:31.861] Build status: SCHEDULED
[06:58:31.861] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:8:0) after 6m12s
[07:04:43.878] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:8:0)
[07:04:43.923] Build status: SCHEDULED
[07:04:43.923] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:9:0) after 9m35s
[07:14:18.999] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:9:0)
[07:14:19.042] Build status: SCHEDULED
[07:14:19.043] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:10:0) after 2m55s
[07:17:14.062] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:10:0)
[07:17:14.088] Build status: SCHEDULED
[07:17:14.088] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:11:0) after 2m2s
[07:19:16.110] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:11:0)
[07:19:16.139] Build status: SCHEDULED
[07:19:16.139] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:12:0) after 1m54s
[07:21:10.161] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:12:0)
[07:21:10.221] Build status: SCHEDULED
[07:21:10.222] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:13:0) after 1m22s
[07:22:32.239] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:13:0)
[07:22:32.272] Build status: SCHEDULED
[07:22:32.272] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:14:0) after 9m48s
[07:32:20.288] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:14:0)
[07:32:20.319] Build status: SCHEDULED
[07:32:20.319] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:15:0) after 6m38s
[07:38:58.338] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:15:0)
[07:38:58.382] Build status: SCHEDULED
[07:38:58.382] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:16:0) after 5m51s
[07:44:49.401] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:16:0)
[07:44:49.431] Build status: SCHEDULED
[07:44:49.432] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:17:0) after 5m36s
[07:50:25.453] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:17:0)
[07:50:25.486] Build status: SCHEDULED
[07:50:25.486] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:18:0) after 7m37s
[07:58:02.508] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:18:0)
[07:58:02.548] Build status: SCHEDULED
[07:58:02.548] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:19:0) after 5m25s
[08:03:27.570] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:19:0)
[08:03:27.594] Build status: SCHEDULED
[08:03:27.594] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:20:0) after 6m57s
[08:10:24.613] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:20:0)
[08:10:24.663] Build status: SCHEDULED
[08:10:24.663] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:21:0) after 1m44s
[08:12:08.682] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:21:0)
[08:12:08.733] Build status: SCHEDULED
[08:12:08.733] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:22:0) after 6m41s
[08:18:49.755] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:22:0)
[08:18:49.780] Build status: SCHEDULED
[08:18:49.780] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:23:0) after 7m14s
[08:26:03.808] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:23:0)
[08:26:04.200] Build status: SCHEDULED
[08:26:04.200] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:24:0) after 5m22s
[08:31:26.231] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:24:0)
[08:31:26.274] Build status: SCHEDULED
[08:31:26.274] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:25:0) after 3m14s
[08:34:40.292] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:25:0)
[08:34:40.339] Build status: SCHEDULED
[08:34:40.339] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:26:0) after 2m31s
[08:37:11.365] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:26:0)
[08:37:11.397] Build status: SCHEDULED
[08:37:11.397] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:27:0) after 9m45s
[08:46:56.420] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:27:0)
[08:46:56.444] Build status: SCHEDULED
[08:46:56.444] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:28:0) after 2m53s
[08:49:49.463] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:28:0)
[08:49:49.495] Build status: SCHEDULED
[08:49:49.495] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:29:0) after 5m3s
[08:51:38.176] Received PubSub notification, asking Buildbucket for the build status
[08:51:38.201] Build status: STARTED
[08:54:52.514] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:29:0)
[08:54:52.576] Build status: STARTED
[08:54:52.576] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:31:0) after 9m27s
[09:04:19.593] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:31:0)
[09:04:19.637] Build status: STARTED
[09:04:19.637] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:32:0) after 2m3s
[09:06:22.662] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:32:0)
[09:06:22.691] Build status: STARTED
[09:06:22.691] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8955180510868828736:33:0) after 5m46s
[09:09:58.898] Received PubSub notification, asking Buildbucket for the build status
[09:09:58.936] Build:
{
"id": "8789750448804303713",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 2841,
"createdBy": "project:infra",
"createTime": "2023-02-08T06:29:31.563148152Z",
"startTime": "2023-02-08T08:51:37.423207Z",
"endTime": "2023-02-08T09:09:58.610948913Z",
"updateTime": "2023-02-08T09:09:58.610948913Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "e1f5b5f1acea4348eb02865aee7d636e9cc63e34",
"ref": "refs/heads/main"
}
},
"canary": true
}
[09:09:58.936] Invocation finished in 2h40m28.725850563s with status SUCCEEDED