[20:31:37.139] New invocation is queued and will start shortly
[20:31:38.213] Starting the invocation (attempt 1)
[20:31:38.250] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/v8/v8/+/c246574ad4a40641603efa842f7ba997d8a88cd3"
[20:31:38.250] Popped gitiles commit info from properties and tags
[20:31:38.250] Preparing PubSub topic for "https://cr-buildbucket-dev.appspot.com"
[20:31:38.250] PubSub topic is "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
[20:31:38.250] Buildbucket request:
{
"requestId": "8970529013850073904",
"builder": {
"project": "v8",
"bucket": "ci",
"builder": "V8 Win64 - dev image"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler-dev.appspot.com",
"invocation": "8970529013850073904",
"job": "v8/V8 Win64 - dev image",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/v8/v8",
"revision": "ce9b1b2ab098d595ad40d546aa268465ba9d8d31"
},
"id": "https://chromium.googlesource.com/v8/v8/+/refs/heads/main@ce9b1b2ab098d595ad40d546aa268465ba9d8d31",
"title": "ce9b1b2ab098d595ad40d546aa268465ba9d8d31",
"url": "https://chromium.googlesource.com/v8/v8/+/ce9b1b2ab098d595ad40d546aa268465ba9d8d31"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/v8/v8",
"revision": "3615ae691dd2dd0ce2333a822d9c1411e04d0ec2"
},
"id": "https://chromium.googlesource.com/v8/v8/+/refs/heads/main@3615ae691dd2dd0ce2333a822d9c1411e04d0ec2",
"title": "3615ae691dd2dd0ce2333a822d9c1411e04d0ec2",
"url": "https://chromium.googlesource.com/v8/v8/+/3615ae691dd2dd0ce2333a822d9c1411e04d0ec2"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/v8/v8",
"revision": "9569f3415d54bd5b6e8006d30856b3c94f21f243"
},
"id": "https://chromium.googlesource.com/v8/v8/+/refs/heads/main@9569f3415d54bd5b6e8006d30856b3c94f21f243",
"title": "9569f3415d54bd5b6e8006d30856b3c94f21f243",
"url": "https://chromium.googlesource.com/v8/v8/+/9569f3415d54bd5b6e8006d30856b3c94f21f243"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/v8/v8",
"revision": "b5145bb6b01f346d9f355da3ecee3eeade7c02aa"
},
"id": "https://chromium.googlesource.com/v8/v8/+/refs/heads/main@b5145bb6b01f346d9f355da3ecee3eeade7c02aa",
"title": "b5145bb6b01f346d9f355da3ecee3eeade7c02aa",
"url": "https://chromium.googlesource.com/v8/v8/+/b5145bb6b01f346d9f355da3ecee3eeade7c02aa"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/v8/v8",
"revision": "41738ca95ee1884114ffaa0e0a7aa1acda7030db"
},
"id": "https://chromium.googlesource.com/v8/v8/+/refs/heads/main@41738ca95ee1884114ffaa0e0a7aa1acda7030db",
"title": "41738ca95ee1884114ffaa0e0a7aa1acda7030db",
"url": "https://chromium.googlesource.com/v8/v8/+/41738ca95ee1884114ffaa0e0a7aa1acda7030db"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://chromium.googlesource.com/v8/v8",
"revision": "c246574ad4a40641603efa842f7ba997d8a88cd3"
},
"id": "https://chromium.googlesource.com/v8/v8/+/refs/heads/main@c246574ad4a40641603efa842f7ba997d8a88cd3",
"title": "c246574ad4a40641603efa842f7ba997d8a88cd3",
"url": "https://chromium.googlesource.com/v8/v8/+/c246574ad4a40641603efa842f7ba997d8a88cd3"
}
]
}
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "v8/v8",
"id": "c246574ad4a40641603efa842f7ba997d8a88cd3",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8970529013850073904"
},
{
"key": "scheduler_job_id",
"value": "v8/V8 Win64 - dev image"
},
{
"key": "user_agent",
"value": "luci-scheduler-dev"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler-dev/topics/scheduler.buildbucket.cr-buildbucket-dev~appspot.gserviceaccount.com"
}
}
[20:31:38.634] Scheduled build:
{
"id": "8805098951936022689",
"builder": {
"project": "v8",
"bucket": "ci",
"builder": "V8 Win64 - dev image"
},
"number": 5336,
"createdBy": "project:v8",
"createTime": "2022-08-22T20:31:38.331604846Z",
"updateTime": "2022-08-22T20:31:38.331604846Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "v8/v8",
"id": "c246574ad4a40641603efa842f7ba997d8a88cd3",
"ref": "refs/heads/main"
}
}
}
[20:31:38.634] Task URL: https://cr-buildbucket-dev.appspot.com/build/8805098951936022689
[20:31:38.634] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:2:0) after 4m57s
[20:36:35.700] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:2:0)
[20:36:35.975] Build status: SCHEDULED
[20:36:35.975] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:3:0) after 7m16s
[20:43:52.000] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:3:0)
[20:43:52.022] Build status: SCHEDULED
[20:43:52.022] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:4:0) after 1m2s
[20:44:54.043] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:4:0)
[20:44:54.087] Build status: SCHEDULED
[20:44:54.087] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:5:0) after 1m51s
[20:46:45.108] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:5:0)
[20:46:45.291] Build status: SCHEDULED
[20:46:45.292] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:6:0) after 1m1s
[20:47:46.312] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:6:0)
[20:47:46.351] Build status: SCHEDULED
[20:47:46.351] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:7:0) after 9m56s
[20:57:42.372] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:7:0)
[20:57:42.410] Build status: SCHEDULED
[20:57:42.410] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:8:0) after 1m36s
[20:59:18.429] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:8:0)
[20:59:18.470] Build status: SCHEDULED
[20:59:18.470] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:9:0) after 6m0s
[21:05:18.498] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:9:0)
[21:05:18.794] Build status: SCHEDULED
[21:05:18.794] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:10:0) after 8m9s
[21:13:27.827] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:10:0)
[21:13:27.865] Build status: SCHEDULED
[21:13:27.865] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:11:0) after 2m54s
[21:16:21.886] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:11:0)
[21:16:21.910] Build status: SCHEDULED
[21:16:21.910] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:12:0) after 7m47s
[21:24:08.932] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:12:0)
[21:24:08.957] Build status: SCHEDULED
[21:24:08.957] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:13:0) after 3m56s
[21:28:04.975] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:13:0)
[21:28:05.002] Build status: SCHEDULED
[21:28:05.002] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:14:0) after 3m0s
[21:31:05.022] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:14:0)
[21:31:05.062] Build status: SCHEDULED
[21:31:05.062] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:15:0) after 1m13s
[21:32:18.084] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:15:0)
[21:32:18.141] Build status: SCHEDULED
[21:32:18.141] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:16:0) after 8m16s
[21:40:34.162] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:16:0)
[21:40:34.209] Build status: SCHEDULED
[21:40:34.209] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:17:0) after 5m34s
[21:46:08.231] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:17:0)
[21:46:08.267] Build status: SCHEDULED
[21:46:08.267] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:18:0) after 8m20s
[21:54:28.287] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:18:0)
[21:54:28.325] Build status: SCHEDULED
[21:54:28.325] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:19:0) after 2m27s
[21:56:55.346] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:19:0)
[21:56:55.386] Build status: SCHEDULED
[21:56:55.386] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:20:0) after 8m28s
[22:05:23.411] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:20:0)
[22:05:23.449] Build status: SCHEDULED
[22:05:23.449] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:21:0) after 3m31s
[22:08:54.472] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:21:0)
[22:08:54.501] Build status: SCHEDULED
[22:08:54.501] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:22:0) after 2m41s
[22:11:35.522] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:22:0)
[22:11:35.719] Build status: SCHEDULED
[22:11:35.720] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:23:0) after 1m9s
[22:12:44.740] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:23:0)
[22:12:44.780] Build status: SCHEDULED
[22:12:44.780] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:24:0) after 3m2s
[22:15:46.819] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:24:0)
[22:15:46.889] Build status: SCHEDULED
[22:15:46.889] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:25:0) after 4m51s
[22:20:38.906] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:25:0)
[22:20:38.929] Build status: SCHEDULED
[22:20:38.929] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:26:0) after 1m15s
[22:21:53.962] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:26:0)
[22:21:53.999] Build status: SCHEDULED
[22:21:53.999] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:27:0) after 7m30s
[22:29:24.049] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:27:0)
[22:29:24.089] Build status: SCHEDULED
[22:29:24.089] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:28:0) after 4m8s
[22:33:32.109] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:28:0)
[22:33:32.139] Build status: SCHEDULED
[22:33:32.139] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:29:0) after 5m12s
[22:38:44.161] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:29:0)
[22:38:44.186] Build status: SCHEDULED
[22:38:44.186] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:30:0) after 6m28s
[22:45:12.210] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:30:0)
[22:45:12.243] Build status: SCHEDULED
[22:45:12.243] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:31:0) after 7m31s
[22:52:43.347] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:31:0)
[22:52:43.375] Build status: SCHEDULED
[22:52:43.375] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:32:0) after 2m37s
[22:55:20.396] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:32:0)
[22:55:20.433] Build status: SCHEDULED
[22:55:20.433] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:33:0) after 1m57s
[22:57:17.461] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:33:0)
[22:57:17.483] Build status: SCHEDULED
[22:57:17.483] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:34:0) after 6m6s
[23:01:07.730] Received PubSub notification, asking Buildbucket for the build status
[23:01:07.755] Build status: STARTED
[23:03:23.507] Handling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:34:0)
[23:03:23.529] Build status: STARTED
[23:03:23.529] Scheduling timer "check-buildbucket-build-status" (v8/V8 Win64 - dev image:8970529013850073904:36:0) after 5m4s
[23:05:12.542] Received PubSub notification, asking Buildbucket for the build status
[23:05:12.602] Build:
{
"id": "8805098951936022689",
"builder": {
"project": "v8",
"bucket": "ci",
"builder": "V8 Win64 - dev image"
},
"number": 5336,
"createdBy": "project:v8",
"createTime": "2022-08-22T20:31:38.331604846Z",
"startTime": "2022-08-22T23:01:07.130188Z",
"endTime": "2022-08-22T23:05:12.148189766Z",
"updateTime": "2022-08-22T23:05:12.148189766Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "v8/v8",
"id": "c246574ad4a40641603efa842f7ba997d8a88cd3",
"ref": "refs/heads/main"
}
}
}
[23:05:12.602] Invocation finished in 2h33m35.479661663s with status SUCCEEDED