[00:42:43.083] New invocation is queued and will start shortly
[00:42:44.176] Starting the invocation (attempt 1)
[00:42:44.218] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/4ad93a61c0196e2eab69fa345a754c0afff5093c"
[00:42:44.218] Popped gitiles commit info from properties and tags
[00:42:44.218] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[00:42:49.589] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[00:42:49.590] Buildbucket request:
{
"requestId": "8982562612593488560",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"invocation": "8982562612593488560",
"job": "infra/infra-continuous-win11-64",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "fe0acba8cc3ab01127d04a31fa7815ace0aaff2b"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@fe0acba8cc3ab01127d04a31fa7815ace0aaff2b",
"title": "fe0acba8cc3ab01127d04a31fa7815ace0aaff2b",
"url": "https://chromium.googlesource.com/infra/infra/+/fe0acba8cc3ab01127d04a31fa7815ace0aaff2b"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "13f8fb635dd434ba75f486b91245812517b167a2"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@13f8fb635dd434ba75f486b91245812517b167a2",
"title": "13f8fb635dd434ba75f486b91245812517b167a2",
"url": "https://chromium.googlesource.com/infra/infra/+/13f8fb635dd434ba75f486b91245812517b167a2"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "691ddc48391fcf8c0b69a54e7b401b0def578297"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@691ddc48391fcf8c0b69a54e7b401b0def578297",
"title": "691ddc48391fcf8c0b69a54e7b401b0def578297",
"url": "https://chromium.googlesource.com/infra/infra/+/691ddc48391fcf8c0b69a54e7b401b0def578297"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "93fe23a56ac8b91ef206517bb04367ccb0f47248"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@93fe23a56ac8b91ef206517bb04367ccb0f47248",
"title": "93fe23a56ac8b91ef206517bb04367ccb0f47248",
"url": "https://chromium.googlesource.com/infra/infra/+/93fe23a56ac8b91ef206517bb04367ccb0f47248"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "c81999e37efa0be99ec0498e3c223ea293382962"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@c81999e37efa0be99ec0498e3c223ea293382962",
"title": "c81999e37efa0be99ec0498e3c223ea293382962",
"url": "https://chromium.googlesource.com/infra/infra/+/c81999e37efa0be99ec0498e3c223ea293382962"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "ab90374eeeb40d7bc7b21a9e8db075421f6feb48"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@ab90374eeeb40d7bc7b21a9e8db075421f6feb48",
"title": "ab90374eeeb40d7bc7b21a9e8db075421f6feb48",
"url": "https://chromium.googlesource.com/infra/infra/+/ab90374eeeb40d7bc7b21a9e8db075421f6feb48"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "b9c8dd9fcce8676127d7914a405a658ae4c2781c"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@b9c8dd9fcce8676127d7914a405a658ae4c2781c",
"title": "b9c8dd9fcce8676127d7914a405a658ae4c2781c",
"url": "https://chromium.googlesource.com/infra/infra/+/b9c8dd9fcce8676127d7914a405a658ae4c2781c"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "2ff6d29c48497aa765739e08d98f28cb7daf4a50"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@2ff6d29c48497aa765739e08d98f28cb7daf4a50",
"title": "2ff6d29c48497aa765739e08d98f28cb7daf4a50",
"url": "https://chromium.googlesource.com/infra/infra/+/2ff6d29c48497aa765739e08d98f28cb7daf4a50"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "29d546e8023f9ed867bd20b874dda7ccc9a6b014"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@29d546e8023f9ed867bd20b874dda7ccc9a6b014",
"title": "29d546e8023f9ed867bd20b874dda7ccc9a6b014",
"url": "https://chromium.googlesource.com/infra/infra/+/29d546e8023f9ed867bd20b874dda7ccc9a6b014"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "efed745b36a44076ccbdc19b27e1e4bd91eb7f6e"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@efed745b36a44076ccbdc19b27e1e4bd91eb7f6e",
"title": "efed745b36a44076ccbdc19b27e1e4bd91eb7f6e",
"url": "https://chromium.googlesource.com/infra/infra/+/efed745b36a44076ccbdc19b27e1e4bd91eb7f6e"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "4ad93a61c0196e2eab69fa345a754c0afff5093c"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@4ad93a61c0196e2eab69fa345a754c0afff5093c",
"title": "4ad93a61c0196e2eab69fa345a754c0afff5093c",
"url": "https://chromium.googlesource.com/infra/infra/+/4ad93a61c0196e2eab69fa345a754c0afff5093c"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "4ad93a61c0196e2eab69fa345a754c0afff5093c",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8982562612593488560"
},
{
"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"
}
}
[00:42:50.480] Scheduled build:
{
"id": "8817132544989158721",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 862,
"createdBy": "project:infra",
"createTime": "2022-04-12T00:42:49.702825299Z",
"updateTime": "2022-04-12T00:42:49.702825299Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "4ad93a61c0196e2eab69fa345a754c0afff5093c",
"ref": "refs/heads/main"
}
},
"canary": true
}
[00:42:50.480] Task URL: https://cr-buildbucket-dev.appspot.com/build/8817132544989158721
[00:42:50.480] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:2:0) after 9m23s
[00:52:13.500] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:2:0)
[00:52:13.545] Build status: SCHEDULED
[00:52:13.545] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:3:0) after 4m11s
[00:56:24.566] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:3:0)
[00:56:24.617] Build status: SCHEDULED
[00:56:24.617] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:4:0) after 9m29s
[01:05:53.668] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:4:0)
[01:05:53.756] Build status: SCHEDULED
[01:05:53.756] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:5:0) after 5m41s
[01:11:34.823] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:5:0)
[01:11:34.845] Build status: SCHEDULED
[01:11:34.845] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:6:0) after 9m20s
[01:20:54.865] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:6:0)
[01:20:54.924] Build status: SCHEDULED
[01:20:54.924] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:7:0) after 8m58s
[01:29:52.955] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:7:0)
[01:29:53.005] Build status: SCHEDULED
[01:29:53.005] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:8:0) after 3m44s
[01:33:37.029] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:8:0)
[01:33:37.092] Build status: SCHEDULED
[01:33:37.092] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:9:0) after 8m1s
[01:41:38.115] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:9:0)
[01:41:38.150] Build status: SCHEDULED
[01:41:38.150] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:10:0) after 4m13s
[01:45:51.175] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:10:0)
[01:45:51.204] Build status: SCHEDULED
[01:45:51.204] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:11:0) after 4m18s
[01:50:09.249] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:11:0)
[01:50:09.298] Build status: SCHEDULED
[01:50:09.298] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:12:0) after 4m12s
[01:54:21.328] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:12:0)
[01:54:21.384] Build status: SCHEDULED
[01:54:21.384] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:13:0) after 3m19s
[01:57:40.423] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:13:0)
[01:57:40.465] Build status: SCHEDULED
[01:57:40.465] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:14:0) after 6m41s
[02:04:21.491] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:14:0)
[02:04:21.536] Build status: SCHEDULED
[02:04:21.536] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:15:0) after 4m11s
[02:08:32.566] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:15:0)
[02:08:32.625] Build status: SCHEDULED
[02:08:32.625] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:16:0) after 9m20s
[02:17:52.646] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:16:0)
[02:17:52.686] Build status: SCHEDULED
[02:17:52.686] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:17:0) after 7m45s
[02:22:59.020] Received PubSub notification, asking Buildbucket for the build status
[02:22:59.076] Build status: STARTED
[02:25:37.713] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:17:0)
[02:25:37.765] Build status: STARTED
[02:25:37.765] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:19:0) after 5m33s
[02:31:10.793] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:19:0)
[02:31:10.878] Build status: STARTED
[02:31:10.878] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:20:0) after 7m18s
[02:38:28.902] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:20:0)
[02:38:28.953] Build status: STARTED
[02:38:28.953] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win11-64:8982562612593488560:21:0) after 9m24s
[02:40:25.105] Received PubSub notification, asking Buildbucket for the build status
[02:40:25.156] Build:
{
"id": "8817132544989158721",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win11-64"
},
"number": 862,
"createdBy": "project:infra",
"createTime": "2022-04-12T00:42:49.702825299Z",
"startTime": "2022-04-12T02:22:57.085290Z",
"endTime": "2022-04-12T02:40:22.297339543Z",
"updateTime": "2022-04-12T02:40:22.297339543Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "4ad93a61c0196e2eab69fa345a754c0afff5093c",
"ref": "refs/heads/main"
}
},
"canary": true
}
[02:40:25.156] Invocation finished in 1h57m42.090404803s with status SUCCEEDED