[06:20:02.049] New invocation is queued and will start shortly
[06:20:03.188] Starting the invocation (attempt 1)
[06:20:03.237] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/infra/infra/+/bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3"
[06:20:03.237] Popped gitiles commit info from properties and tags
[06:20:03.237] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[06:20:03.237] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[06:20:03.238] Buildbucket request:
{
"requestId": "8994047205231026224",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win10-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": "f58188e7754bc9b87c848ff097cedee9d1983f3d"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@f58188e7754bc9b87c848ff097cedee9d1983f3d",
"title": "f58188e7754bc9b87c848ff097cedee9d1983f3d",
"url": "https://chromium.googlesource.com/infra/infra/+/f58188e7754bc9b87c848ff097cedee9d1983f3d"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "fb57945c53dd397aa94e10b395cd6a88d0142c28"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@fb57945c53dd397aa94e10b395cd6a88d0142c28",
"title": "fb57945c53dd397aa94e10b395cd6a88d0142c28",
"url": "https://chromium.googlesource.com/infra/infra/+/fb57945c53dd397aa94e10b395cd6a88d0142c28"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "0711fec37f77d6f24b4ed9f80639f4700a598347"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@0711fec37f77d6f24b4ed9f80639f4700a598347",
"title": "0711fec37f77d6f24b4ed9f80639f4700a598347",
"url": "https://chromium.googlesource.com/infra/infra/+/0711fec37f77d6f24b4ed9f80639f4700a598347"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "f1d0b162a03d926c118000569a18490c7f929827"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@f1d0b162a03d926c118000569a18490c7f929827",
"title": "f1d0b162a03d926c118000569a18490c7f929827",
"url": "https://chromium.googlesource.com/infra/infra/+/f1d0b162a03d926c118000569a18490c7f929827"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "d693f25641bcec7c5fdc6626e4680ad85c5b85b8"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@d693f25641bcec7c5fdc6626e4680ad85c5b85b8",
"title": "d693f25641bcec7c5fdc6626e4680ad85c5b85b8",
"url": "https://chromium.googlesource.com/infra/infra/+/d693f25641bcec7c5fdc6626e4680ad85c5b85b8"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "1924fa37c62d7f8b8b1325e29d41cb1c8761aa28"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@1924fa37c62d7f8b8b1325e29d41cb1c8761aa28",
"title": "1924fa37c62d7f8b8b1325e29d41cb1c8761aa28",
"url": "https://chromium.googlesource.com/infra/infra/+/1924fa37c62d7f8b8b1325e29d41cb1c8761aa28"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/infra/infra",
"revision": "bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3"
},
"id": "https://chromium.googlesource.com/infra/infra/+/refs/heads/main@bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3",
"title": "bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3",
"url": "https://chromium.googlesource.com/infra/infra/+/bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8994047205231026224"
},
{
"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"
}
}
[06:20:04.097] Scheduled build:
{
"id": "8828617143200024961",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win10-64"
},
"number": 21324,
"createdBy": "project:infra",
"createTime": "2021-12-06T06:20:03.354621245Z",
"updateTime": "2021-12-06T06:20:03.354621245Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3",
"ref": "refs/heads/main"
}
}
}
[06:20:04.097] Task URL: https://cr-buildbucket-dev.appspot.com/build/8828617143200024961
[06:20:04.097] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:2:0) after 7m5s
[06:27:09.115] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:2:0)
[06:27:09.145] Build status: SCHEDULED
[06:27:09.145] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:3:0) after 5m37s
[06:32:46.181] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:3:0)
[06:32:46.224] Build status: SCHEDULED
[06:32:46.225] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:4:0) after 7m8s
[06:39:54.245] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:4:0)
[06:39:54.278] Build status: SCHEDULED
[06:39:54.278] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:5:0) after 7m15s
[06:47:09.296] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:5:0)
[06:47:09.319] Build status: SCHEDULED
[06:47:09.319] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:6:0) after 6m44s
[06:53:53.337] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:6:0)
[06:53:53.358] Build status: SCHEDULED
[06:53:53.358] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:7:0) after 4m56s
[06:58:49.377] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:7:0)
[06:58:49.399] Build status: SCHEDULED
[06:58:49.399] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:8:0) after 6m54s
[07:05:43.430] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:8:0)
[07:05:43.460] Build status: SCHEDULED
[07:05:43.460] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:9:0) after 1m54s
[07:07:37.479] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:9:0)
[07:07:37.510] Build status: SCHEDULED
[07:07:37.510] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:10:0) after 2m16s
[07:09:53.531] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:10:0)
[07:09:53.556] Build status: SCHEDULED
[07:09:53.556] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:11:0) after 5m51s
[07:14:12.479] Received PubSub notification, asking Buildbucket for the build status
[07:14:12.530] Build status: STARTED
[07:15:44.572] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:11:0)
[07:15:44.604] Build status: STARTED
[07:15:44.604] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:13:0) after 5m42s
[07:21:26.625] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:13:0)
[07:21:26.663] Build status: STARTED
[07:21:26.663] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:14:0) after 5m25s
[07:26:51.772] Handling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:14:0)
[07:26:51.809] Build status: STARTED
[07:26:51.809] Scheduling timer "check-buildbucket-build-status" (infra/infra-continuous-win10-64:8994047205231026224:15:0) after 4m2s
[07:27:51.789] Received PubSub notification, asking Buildbucket for the build status
[07:27:51.812] Build:
{
"id": "8828617143200024961",
"builder": {
"project": "infra",
"bucket": "ci",
"builder": "infra-continuous-win10-64"
},
"number": 21324,
"createdBy": "project:infra",
"createTime": "2021-12-06T06:20:03.354621245Z",
"startTime": "2021-12-06T07:14:11.584328Z",
"endTime": "2021-12-06T07:27:46.307164860Z",
"updateTime": "2021-12-06T07:27:46.307164860Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "infra/infra",
"id": "bbfa0fbda9b3a48cfa91f0021cbef870c831b9c3",
"ref": "refs/heads/main"
}
}
}
[07:27:51.812] Invocation finished in 1h7m49.778986587s with status SUCCEEDED