[00:04:09.141] New invocation is queued and will start shortly
[00:04:10.379] Starting the invocation (attempt 1)
[00:04:10.432] Popped buildset tag "buildset:commit/gitiles/chromium.googlesource.com/chromium/src/+/d2d9a18fff9606d7867fdc999db115524f3c9e7b"
[00:04:10.432] Popped gitiles commit info from properties and tags
[00:04:10.432] Preparing PubSub topic for "https://cr-buildbucket.appspot.com"
[00:04:10.432] PubSub topic is "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
[00:04:10.432] Buildbucket request:
{
"requestId": "9007026219865716784",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "fuchsia-fyi-arm64-dbg"
},
"properties": {
},
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d2d9a18fff9606d7867fdc999db115524f3c9e7b",
"ref": "refs/heads/main"
},
"tags": [
{
"key": "scheduler_invocation_id",
"value": "9007026219865716784"
},
{
"key": "scheduler_job_id",
"value": "chromium/fuchsia-fyi-arm64-dbg"
},
{
"key": "user_agent",
"value": "luci-scheduler"
}
],
"notify": {
"pubsubTopic": "projects/luci-scheduler/topics/scheduler.buildbucket.cr-buildbucket~appspot.gserviceaccount.com"
}
}
[00:04:11.080] Scheduled build:
{
"id": "8841596157694130784",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "fuchsia-fyi-arm64-dbg"
},
"number": 2173,
"createdBy": "project:chromium",
"createTime": "2021-07-16T00:04:10.578951Z",
"updateTime": "2021-07-16T00:04:10.999543Z",
"status": "SCHEDULED",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d2d9a18fff9606d7867fdc999db115524f3c9e7b",
"ref": "refs/heads/main"
}
}
}
[00:04:11.080] Task URL: https://cr-buildbucket.appspot.com/build/8841596157694130784
[00:04:11.080] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:2:0) after 1m36s
[00:05:01.138] Received PubSub notification, asking Buildbucket for the build status
[00:05:01.167] Build status: STARTED
[00:05:47.133] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:2:0)
[00:05:47.164] Build status: STARTED
[00:05:47.164] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:4:0) after 8m10s
[00:13:57.195] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:4:0)
[00:13:57.226] Build status: STARTED
[00:13:57.226] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:5:0) after 3m21s
[00:17:18.572] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:5:0)
[00:17:18.599] Build status: STARTED
[00:17:18.599] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:6:0) after 1m28s
[00:18:46.632] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:6:0)
[00:18:46.685] Build status: STARTED
[00:18:46.685] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:7:0) after 8m22s
[00:27:08.767] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:7:0)
[00:27:08.796] Build status: STARTED
[00:27:08.796] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:8:0) after 5m59s
[00:33:07.857] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:8:0)
[00:33:07.887] Build status: STARTED
[00:33:07.887] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:9:0) after 3m9s
[00:36:16.912] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:9:0)
[00:36:16.940] Build status: STARTED
[00:36:16.940] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:10:0) after 9m47s
[00:46:04.619] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:10:0)
[00:46:04.786] Build status: STARTED
[00:46:04.786] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:11:0) after 8m20s
[00:54:25.061] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:11:0)
[00:54:25.094] Build status: STARTED
[00:54:25.094] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:12:0) after 9m18s
[01:03:43.267] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:12:0)
[01:03:43.294] Build status: STARTED
[01:03:43.294] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:13:0) after 8m24s
[01:12:07.844] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:13:0)
[01:12:07.913] Build status: STARTED
[01:12:07.913] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:14:0) after 6m36s
[01:18:43.937] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:14:0)
[01:18:43.984] Build status: STARTED
[01:18:43.984] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:15:0) after 1m42s
[01:20:26.240] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:15:0)
[01:20:26.270] Build status: STARTED
[01:20:26.270] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:16:0) after 2m42s
[01:23:08.298] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:16:0)
[01:23:08.328] Build status: STARTED
[01:23:08.328] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:17:0) after 1m22s
[01:24:30.364] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:17:0)
[01:24:30.456] Build status: STARTED
[01:24:30.456] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:18:0) after 2m14s
[01:26:44.609] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:18:0)
[01:26:44.656] Build status: STARTED
[01:26:44.656] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:19:0) after 8m30s
[01:35:14.784] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:19:0)
[01:35:14.815] Build status: STARTED
[01:35:14.815] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:20:0) after 6m53s
[01:42:07.840] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:20:0)
[01:42:07.874] Build status: STARTED
[01:42:07.874] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:21:0) after 5m5s
[01:47:13.016] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:21:0)
[01:47:13.056] Build status: STARTED
[01:47:13.056] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:22:0) after 9m37s
[01:56:50.163] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:22:0)
[01:56:50.219] Build status: STARTED
[01:56:50.219] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:23:0) after 8m17s
[02:05:07.316] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:23:0)
[02:05:07.346] Build status: STARTED
[02:05:07.346] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:24:0) after 4m33s
[02:09:40.398] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:24:0)
[02:09:40.457] Build status: STARTED
[02:09:40.457] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:25:0) after 4m59s
[02:14:40.076] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:25:0)
[02:14:40.105] Build status: STARTED
[02:14:40.105] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:26:0) after 8m0s
[02:22:40.141] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:26:0)
[02:22:40.183] Build status: STARTED
[02:22:40.183] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:27:0) after 5m59s
[02:28:39.482] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:27:0)
[02:28:39.509] Build status: STARTED
[02:28:39.509] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:28:0) after 6m26s
[02:35:05.641] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:28:0)
[02:35:05.669] Build status: STARTED
[02:35:05.669] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:29:0) after 1m0s
[02:36:05.760] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:29:0)
[02:36:05.792] Build status: STARTED
[02:36:05.792] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:30:0) after 6m2s
[02:42:07.879] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:30:0)
[02:42:07.906] Build status: STARTED
[02:42:07.906] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:31:0) after 5m37s
[02:47:44.998] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:31:0)
[02:47:45.032] Build status: STARTED
[02:47:45.032] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:32:0) after 1m38s
[02:49:23.029] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:32:0)
[02:49:23.090] Build status: STARTED
[02:49:23.090] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:33:0) after 8m13s
[02:57:36.359] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:33:0)
[02:57:36.393] Build status: STARTED
[02:57:36.393] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:34:0) after 2m46s
[03:00:22.694] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:34:0)
[03:00:22.722] Build status: STARTED
[03:00:22.722] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:35:0) after 8m47s
[03:09:09.753] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:35:0)
[03:09:09.812] Build status: STARTED
[03:09:09.812] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:36:0) after 9m26s
[03:18:35.839] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:36:0)
[03:18:35.874] Build status: STARTED
[03:18:35.874] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:37:0) after 1m21s
[03:19:57.059] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:37:0)
[03:19:57.088] Build status: STARTED
[03:19:57.088] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:38:0) after 3m34s
[03:23:31.606] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:38:0)
[03:23:31.648] Build status: STARTED
[03:23:31.648] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:39:0) after 4m53s
[03:28:24.717] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:39:0)
[03:28:24.750] Build status: STARTED
[03:28:24.750] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:40:0) after 9m47s
[03:38:11.847] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:40:0)
[03:38:11.878] Build status: STARTED
[03:38:11.878] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:41:0) after 9m6s
[03:47:17.899] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:41:0)
[03:47:17.935] Build status: STARTED
[03:47:17.935] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:42:0) after 2m33s
[03:49:50.927] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:42:0)
[03:49:50.964] Build status: STARTED
[03:49:50.964] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:43:0) after 1m25s
[03:51:16.084] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:43:0)
[03:51:16.118] Build status: STARTED
[03:51:16.118] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:44:0) after 1m27s
[03:52:43.147] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:44:0)
[03:52:43.184] Build status: STARTED
[03:52:43.184] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:45:0) after 2m34s
[03:55:17.431] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:45:0)
[03:55:17.465] Build status: STARTED
[03:55:17.465] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:46:0) after 7m23s
[04:02:40.490] Handling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:46:0)
[04:02:40.524] Build status: STARTED
[04:02:40.524] Scheduling timer "check-buildbucket-build-status" (chromium/fuchsia-fyi-arm64-dbg:9007026219865716784:47:0) after 8m34s
[04:03:23.766] Received PubSub notification, asking Buildbucket for the build status
[04:03:23.797] Build:
{
"id": "8841596157694130784",
"builder": {
"project": "chromium",
"bucket": "ci",
"builder": "fuchsia-fyi-arm64-dbg"
},
"number": 2173,
"createdBy": "project:chromium",
"createTime": "2021-07-16T00:04:10.578951Z",
"startTime": "2021-07-16T00:05:00.504383Z",
"endTime": "2021-07-16T04:03:23.398112293Z",
"updateTime": "2021-07-16T04:03:23.398767644Z",
"status": "FAILURE",
"input": {
"gitilesCommit": {
"host": "chromium.googlesource.com",
"project": "chromium/src",
"id": "d2d9a18fff9606d7867fdc999db115524f3c9e7b",
"ref": "refs/heads/main"
}
}
}
[04:03:23.797] Invocation finished in 3h59m14.673073399s with status FAILED