[21:07:13.762] New invocation is queued and will start shortly
[21:07:15.023] Starting the invocation (attempt 1)
[21:07:15.055] Popped buildset tag "buildset:commit/gitiles/fuchsia.googlesource.com/integration/+/3fb56abd524283441a0cbc934a2c33f2fac222bd"
[21:07:15.055] Popped gitiles commit info from properties and tags
[21:07:15.055] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[21:07:15.055] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[21:07:15.055] Buildbucket request:
{
"requestId": "8936643508018079968",
"builder": {
"project": "fuchsia",
"bucket": "global.ci",
"builder": "core.x64-debug"
},
"properties": {
"$recipe_engine/scheduler": {
"hostname": "luci-scheduler.appspot.com",
"invocation": "8936643508018079968",
"job": "fuchsia/core.x64-debug-e5a0ec7f",
"triggers": [
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "fd6e95ba7c3513e0408317257a914f94cb0f599c"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@fd6e95ba7c3513e0408317257a914f94cb0f599c",
"title": "fd6e95ba7c3513e0408317257a914f94cb0f599c",
"url": "https://fuchsia.googlesource.com/integration/+/fd6e95ba7c3513e0408317257a914f94cb0f599c"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "bc65f2af6516971f420f1644edb5f70904e24d68"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@bc65f2af6516971f420f1644edb5f70904e24d68",
"title": "bc65f2af6516971f420f1644edb5f70904e24d68",
"url": "https://fuchsia.googlesource.com/integration/+/bc65f2af6516971f420f1644edb5f70904e24d68"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "b07bc37e252f0e52ba7b1658a2ac33c1662a7dcb"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@b07bc37e252f0e52ba7b1658a2ac33c1662a7dcb",
"title": "b07bc37e252f0e52ba7b1658a2ac33c1662a7dcb",
"url": "https://fuchsia.googlesource.com/integration/+/b07bc37e252f0e52ba7b1658a2ac33c1662a7dcb"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "051cdd90478711471201f3c0dd138e35254b2268"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@051cdd90478711471201f3c0dd138e35254b2268",
"title": "051cdd90478711471201f3c0dd138e35254b2268",
"url": "https://fuchsia.googlesource.com/integration/+/051cdd90478711471201f3c0dd138e35254b2268"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "d90fad959c91dcc73feaa65e49bf768735dcd95d"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@d90fad959c91dcc73feaa65e49bf768735dcd95d",
"title": "d90fad959c91dcc73feaa65e49bf768735dcd95d",
"url": "https://fuchsia.googlesource.com/integration/+/d90fad959c91dcc73feaa65e49bf768735dcd95d"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "5458169beb49f75f874b89ac11af37d5b0e5e460"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@5458169beb49f75f874b89ac11af37d5b0e5e460",
"title": "5458169beb49f75f874b89ac11af37d5b0e5e460",
"url": "https://fuchsia.googlesource.com/integration/+/5458169beb49f75f874b89ac11af37d5b0e5e460"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "d219ce4f1eadffcc2d06e93297a6d34ca99a1c90"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@d219ce4f1eadffcc2d06e93297a6d34ca99a1c90",
"title": "d219ce4f1eadffcc2d06e93297a6d34ca99a1c90",
"url": "https://fuchsia.googlesource.com/integration/+/d219ce4f1eadffcc2d06e93297a6d34ca99a1c90"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "af978a913d858511fa972eecdb7e26c50bce438e"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@af978a913d858511fa972eecdb7e26c50bce438e",
"title": "af978a913d858511fa972eecdb7e26c50bce438e",
"url": "https://fuchsia.googlesource.com/integration/+/af978a913d858511fa972eecdb7e26c50bce438e"
},
{
"gitiles": {
"ref": "refs/heads/main",
"repo": "https://fuchsia.googlesource.com/integration",
"revision": "3fb56abd524283441a0cbc934a2c33f2fac222bd"
},
"id": "https://fuchsia.googlesource.com/integration/+/refs/heads/main@3fb56abd524283441a0cbc934a2c33f2fac222bd",
"title": "3fb56abd524283441a0cbc934a2c33f2fac222bd",
"url": "https://fuchsia.googlesource.com/integration/+/3fb56abd524283441a0cbc934a2c33f2fac222bd"
}
]
}
},
"gitilesCommit": {
"host": "fuchsia.googlesource.com",
"project": "integration",
"id": "3fb56abd524283441a0cbc934a2c33f2fac222bd",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "8936643508018079968"
},
{
"key": "scheduler_job_id",
"value": "fuchsia/core.x64-debug-e5a0ec7f"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[21:07:15.611] Scheduled build:
{
"id": "8771213445924567105",
"builder": {
"project": "fuchsia",
"bucket": "global.ci",
"builder": "core.x64-debug"
},
"createdBy": "project:fuchsia",
"createTime": "2023-08-31T21:07:15.112593534Z",
"updateTime": "2023-08-31T21:07:15.112593534Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "fuchsia.googlesource.com",
"project": "integration",
"id": "3fb56abd524283441a0cbc934a2c33f2fac222bd",
"ref": "refs/heads/main"
}
}
}
[21:07:15.611] Task URL: https://cr-buildbucket.appspot.com/build/8771213445924567105
[21:07:15.611] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:2:0) after 9m27s
[21:07:16.242] Received PubSub notification, asking Buildbucket for the build status
[21:07:16.266] Build status: SCHEDULED
[21:07:24.094] Received PubSub notification, asking Buildbucket for the build status
[21:07:24.134] Build status: STARTED
[21:16:42.676] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:2:0)
[21:16:42.698] Build status: STARTED
[21:16:42.698] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:5:0) after 6m31s
[21:23:13.720] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:5:0)
[21:23:13.796] Build status: STARTED
[21:23:13.796] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:6:0) after 7m31s
[21:30:44.863] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:6:0)
[21:30:44.895] Build status: STARTED
[21:30:44.895] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:7:0) after 1m34s
[21:32:18.941] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:7:0)
[21:32:18.980] Build status: STARTED
[21:32:18.980] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:8:0) after 7m32s
[21:39:51.057] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:8:0)
[21:39:51.077] Build status: STARTED
[21:39:51.077] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:9:0) after 3m59s
[21:43:50.126] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:9:0)
[21:43:50.143] Build status: STARTED
[21:43:50.143] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:10:0) after 6m19s
[21:50:09.171] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:10:0)
[21:50:09.282] Build status: STARTED
[21:50:09.282] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:11:0) after 6m42s
[21:56:51.296] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:11:0)
[21:56:51.355] Build status: STARTED
[21:56:51.355] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:12:0) after 3m49s
[22:00:40.371] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:12:0)
[22:00:40.530] Build status: STARTED
[22:00:40.530] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:13:0) after 2m26s
[22:03:06.546] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:13:0)
[22:03:06.564] Build status: STARTED
[22:03:06.564] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:14:0) after 6m11s
[22:09:17.580] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:14:0)
[22:09:17.597] Build status: STARTED
[22:09:17.597] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:15:0) after 1m2s
[22:10:19.614] Handling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:15:0)
[22:10:19.771] Build status: STARTED
[22:10:19.771] Scheduling timer "check-buildbucket-build-status" (fuchsia/core.x64-debug-e5a0ec7f:8936643508018079968:16:0) after 7m52s
[22:15:52.791] Received PubSub notification, asking Buildbucket for the build status
[22:15:52.882] Build:
{
"id": "8771213445924567105",
"builder": {
"project": "fuchsia",
"bucket": "global.ci",
"builder": "core.x64-debug"
},
"createdBy": "project:fuchsia",
"createTime": "2023-08-31T21:07:15.112593534Z",
"startTime": "2023-08-31T21:07:23.364714Z",
"endTime": "2023-08-31T22:15:52.212452567Z",
"updateTime": "2023-08-31T22:15:52.212452567Z",
"status": "SUCCESS",
"input": {
"gitilesCommit": {
"host": "fuchsia.googlesource.com",
"project": "integration",
"id": "3fb56abd524283441a0cbc934a2c33f2fac222bd",
"ref": "refs/heads/main"
}
}
}
[22:15:52.882] Invocation finished in 1h8m39.149140918s with status SUCCEEDED