[00:47:50.081] New invocation is queued and will start shortly
[00:47:51.161] Starting the invocation (attempt 1)
[00:47:51.203] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/165ff7f17032081b2ce04c6e164cef6e2ec5273e"
[00:47:51.203] Popped gitiles commit info from properties and tags
[00:47:51.203] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[00:47:51.204] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[00:47:51.204] Buildbucket request:
{
"requestId": "8974589757637323536",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win10-64"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"invocation": "8974589757637323536",
"job": "infra/infra-continuous-win10-64",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "862aa088aa05c0ac44af4f92e2cdf1b7e897f369"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@862aa088aa05c0ac44af4f92e2cdf1b7e897f369",
"title": "862aa088aa05c0ac44af4f92e2cdf1b7e897f369",
"url": "https://chromium.googlesource.com/infra/infra/+/862aa088aa05c0ac44af4f92e2cdf1b7e897f369"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "52e91012c992438982819d5c859f689039c2c2ad"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@52e91012c992438982819d5c859f689039c2c2ad",
"title": "52e91012c992438982819d5c859f689039c2c2ad",
"url": "https://chromium.googlesource.com/infra/infra/+/52e91012c992438982819d5c859f689039c2c2ad"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "55c116aaf66875ddd8f3c6b0eb47b9dbea57d9b4"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@55c116aaf66875ddd8f3c6b0eb47b9dbea57d9b4",
"title": "55c116aaf66875ddd8f3c6b0eb47b9dbea57d9b4",
"url": "https://chromium.googlesource.com/infra/infra/+/55c116aaf66875ddd8f3c6b0eb47b9dbea57d9b4"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "165ff7f17032081b2ce04c6e164cef6e2ec5273e"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@165ff7f17032081b2ce04c6e164cef6e2ec5273e",
"title": "165ff7f17032081b2ce04c6e164cef6e2ec5273e",
"url": "https://chromium.googlesource.com/infra/infra/+/165ff7f17032081b2ce04c6e164cef6e2ec5273e"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "165ff7f17032081b2ce04c6e164cef6e2ec5273e",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8974589757637323536"
},
{
"key": "scheduler_job_id",
"value": "infra/infra-continuous-win10-64"
},
{
"key": "user_agent",
"value": "luci-scheduler-dev"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
}
}
[00:47:52.223] Scheduled build:
{
"id": "8809159695703629201",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win10-64"
},
"number": 22872,
"createdBy": "project:infra",
"createTime": "2022-07-09T00:47:51.294285015Z",
"updateTime": "2022-07-09T00:47:51.294285015Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "165ff7f17032081b2ce04c6e164cef6e2ec5273e",
"ref": "refs/heads/main"
}
},
"canary": true
}
[00:47:52.223] Task URL: https://cr-buildbucket-dev.appspot.com/build/8809159695703629201
[00:47:52.223] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:2:0) after 2m23s
[00:50:15.242] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:2:0)
[00:50:15.266] Build status: SCHEDULED
[00:50:15.266] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:3:0) after 5m35s
[00:55:50.298] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:3:0)
[00:55:50.334] Build status: SCHEDULED
[00:55:50.334] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:4:0) after 9m0s
[01:04:50.262] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:4:0)
[01:04:50.350] Build status: SCHEDULED
[01:04:50.351] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:5:0) after 1m13s
[01:06:03.301] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:5:0)
[01:06:03.389] Build status: SCHEDULED
[01:06:03.389] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:6:0) after 6m28s
[01:12:31.411] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:6:0)
[01:12:31.444] Build status: SCHEDULED
[01:12:31.444] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:7:0) after 2m11s
[01:14:42.469] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:7:0)
[01:14:42.560] Build status: SCHEDULED
[01:14:42.560] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:8:0) after 2m38s
[01:17:20.588] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:8:0)
[01:17:20.683] Build status: SCHEDULED
[01:17:20.683] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:9:0) after 7m22s
[01:24:42.725] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:9:0)
[01:24:42.802] Build status: SCHEDULED
[01:24:42.802] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:10:0) after 5m54s
[01:30:36.823] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:10:0)
[01:30:36.860] Build status: SCHEDULED
[01:30:36.860] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:11:0) after 4m37s
[01:35:13.880] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:11:0)
[01:35:13.949] Build status: SCHEDULED
[01:35:13.949] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:12:0) after 6m6s
[01:41:19.972] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:12:0)
[01:41:20.043] Build status: SCHEDULED
[01:41:20.043] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:13:0) after 7m51s
[01:49:11.066] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:13:0)
[01:49:11.093] Build status: SCHEDULED
[01:49:11.093] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:14:0) after 1m45s
[01:50:56.114] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:14:0)
[01:50:56.230] Build status: SCHEDULED
[01:50:56.230] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:15:0) after 7m20s
[01:58:16.268] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:15:0)
[01:58:16.325] Build status: SCHEDULED
[01:58:16.325] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:16:0) after 3m12s
[02:01:28.345] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:16:0)
[02:01:28.387] Build status: SCHEDULED
[02:01:28.387] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:17:0) after 6m44s
[02:08:12.412] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:17:0)
[02:08:12.452] Build status: SCHEDULED
[02:08:12.452] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:18:0) after 6m3s
[02:14:15.480] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:18:0)
[02:14:15.517] Build status: SCHEDULED
[02:14:15.517] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:19:0) after 9m26s
[02:23:41.560] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:19:0)
[02:23:41.598] Build status: SCHEDULED
[02:23:41.599] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:20:0) after 6m10s
[02:29:51.619] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:20:0)
[02:29:51.644] Build status: SCHEDULED
[02:29:51.644] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:21:0) after 8m38s
[02:38:29.666] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:21:0)
[02:38:29.700] Build status: SCHEDULED
[02:38:29.701] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:22:0) after 8m11s
[02:46:40.730] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:22:0)
[02:46:40.785] Build status: SCHEDULED
[02:46:40.785] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:23:0) after 7m15s
[02:53:55.806] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:23:0)
[02:53:55.893] Build status: SCHEDULED
[02:53:55.893] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:24:0) after 4m48s
[02:58:43.915] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:24:0)
[02:58:43.952] Build status: SCHEDULED
[02:58:43.952] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:25:0) after 3m46s
[03:02:29.978] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:25:0)
[03:02:30.049] Build status: SCHEDULED
[03:02:30.049] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:26:0) after 4m50s
[03:07:20.072] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:26:0)
[03:07:20.161] Build status: SCHEDULED
[03:07:20.161] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:27:0) after 2m4s
[03:09:24.185] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:27:0)
[03:09:24.237] Build status: SCHEDULED
[03:09:24.237] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:28:0) after 4m6s
[03:13:30.265] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:28:0)
[03:13:30.298] Build status: SCHEDULED
[03:13:30.298] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:29:0) after 8m41s
[03:22:11.319] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:29:0)
[03:22:11.360] Build status: SCHEDULED
[03:22:11.360] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:30:0) after 8m13s
[03:30:24.383] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:30:0)
[03:30:24.411] Build status: SCHEDULED
[03:30:24.411] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:31:0) after 9m16s
[03:39:40.434] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:31:0)
[03:39:40.473] Build status: SCHEDULED
[03:39:40.473] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:32:0) after 3m3s
[03:42:43.497] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:32:0)
[03:42:43.553] Build status: SCHEDULED
[03:42:43.553] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:33:0) after 4m23s
[03:47:06.576] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:33:0)
[03:47:06.709] Build status: SCHEDULED
[03:47:06.709] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:34:0) after 3m43s
[03:50:49.730] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:34:0)
[03:50:49.791] Build status: SCHEDULED
[03:50:49.791] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:35:0) after 2m38s
[03:53:27.813] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:35:0)
[03:53:27.861] Build status: SCHEDULED
[03:53:27.861] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:36:0) after 9m54s
[04:03:21.882] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:36:0)
[04:03:21.947] Build status: SCHEDULED
[04:03:21.947] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:37:0) after 2m46s
[04:06:07.990] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:37:0)
[04:06:08.069] Build status: SCHEDULED
[04:06:08.070] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:38:0) after 4m54s
[04:11:02.090] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:38:0)
[04:11:02.151] Build status: SCHEDULED
[04:11:02.151] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:39:0) after 2m30s
[04:13:32.180] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:39:0)
[04:13:32.237] Build status: SCHEDULED
[04:13:32.237] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:40:0) after 7m32s
[04:21:04.263] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:40:0)
[04:21:04.302] Build status: SCHEDULED
[04:21:04.302] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:41:0) after 7m41s
[04:28:45.322] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:41:0)
[04:28:45.374] Build status: SCHEDULED
[04:28:45.374] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:42:0) after 4m38s
[04:33:23.398] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:42:0)
[04:33:23.452] Build status: SCHEDULED
[04:33:23.452] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:43:0) after 8m56s
[04:42:19.476] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:43:0)
[04:42:19.518] Build status: SCHEDULED
[04:42:19.518] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:44:0) after 1m51s
[04:44:10.540] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:44:0)
[04:44:10.592] Build status: SCHEDULED
[04:44:10.592] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:45:0) after 7m6s
[04:51:16.611] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:45:0)
[04:51:16.661] Build status: SCHEDULED
[04:51:16.661] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:46:0) after 6m52s
[04:52:36.378] Received PubSub notification, asking Buildbucket for the build status
[04:52:36.403] Build status: STARTED
[04:58:08.685] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:46:0)
[04:58:08.725] Build status: STARTED
[04:58:08.725] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:48:0) after 3m0s
[05:01:08.749] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:48:0)
[05:01:08.804] Build status: STARTED
[05:01:08.804] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:49:0) after 5m39s
[05:06:47.825] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:49:0)
[05:06:47.874] Build status: STARTED
[05:06:47.874] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:50:0) after 6m17s
[05:13:04.898] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:50:0)
[05:13:04.940] Build status: STARTED
[05:13:04.941] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8974589757637323536:51:0) after 4m33s
[05:13:49.485] Received PubSub notification, asking Buildbucket for the build status
[05:13:49.588] Build:
{
"id": "8809159695703629201",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win10-64"
},
"number": 22872,
"createdBy": "project:infra",
"createTime": "2022-07-09T00:47:51.294285015Z",
"startTime": "2022-07-09T04:52:34.659824Z",
"endTime": "2022-07-09T05:13:47.898792658Z",
"updateTime": "2022-07-09T05:13:47.898792658Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "165ff7f17032081b2ce04c6e164cef6e2ec5273e",
"ref": "refs/heads/main"
}
},
"canary": true
}
[05:13:49.588] Invocation finished in 4h25m59.522785445s with status SUCCEEDED