log.txt

% AWS_SHARED_CREDENTIALS_FILE=credentials-ark-aws ./_output/bin/linux/amd64/ark server --log-level debug
INFO[0000] setting log-level to DEBUG
INFO[0000] Starting Ark server v0.9.0-alpha.2-14-gf0e8c93-dirty  logSource="pkg/cmd/server/server.go:100"
INFO[0000] Ensuring namespace exists for backups         logSource="pkg/cmd/server/server.go:258" namespace=heptio-ark
INFO[0000] Namespace already exists                      logSource="pkg/cmd/server/server.go:270" namespace=heptio-ark
INFO[0000] Retrieving Ark configuration                  logSource="pkg/cmd/server/server.go:275"
INFO[0000] Successfully retrieved Ark configuration      logSource="pkg/cmd/server/server.go:293"
INFO[0000] Using default resource priorities             logSource="pkg/cmd/server/server.go:343" priorities="[namespaces persistentvolumes persistentvolumeclaims secrets configmaps serviceaccounts limitranges pods]"
INFO[0000] Configuring cloud provider for backup service  logSource="pkg/cmd/server/server.go:392"
DEBU[0000] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin cloudprovider aws]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0000] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0000] plugin address                                address=/tmp/plugin661304034 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
INFO[0000] Configuring cloud provider for snapshot service  logSource="pkg/cmd/server/server.go:409"
INFO[0000] Starting controllers                          logSource="pkg/cmd/server/server.go:495"
INFO[0000] Caching cloud backups every 30m0s             logSource="pkg/cmd/server/server.go:501"
DEBU[0000] refreshing all cached backup lists from object storage  logSource="pkg/cloudprovider/backup_cache.go:69"
INFO[0000] Starting metric server at address [:8085]     logSource="pkg/cmd/server/server.go:512"
INFO[0000] Running backup sync controller                logSource="pkg/controller/backup_sync_controller.go:70"
INFO[0000] Syncing backups from object storage           logSource="pkg/controller/backup_sync_controller.go:78"
DEBU[0000] Bucket is not in cache - doing a live lookup  bucket=<REDACTED>u logSource="pkg/cloudprovider/backup_cache.go:89"
ERRO[0001] error listing backups                         error="rpc error: code = Unknown desc = AccessDenied: Access Denied\n\tstatus code: 403, request id: 0ECE2691DB48024F, host id: r/BPChP6uGqC+Y7qIR0SbpQ1q9VFh+Gl0jRIJG20zaIRfyW4a0fpbEEwaFyPtgHXY57CUKf1ITY=" logSource="pkg/controller/backup_sync_controller.go:81"
INFO[0005] Starting ScheduleController                   logSource="pkg/controller/schedule_controller.go:135"
INFO[0005] Waiting for caches to sync                    logSource="pkg/controller/schedule_controller.go:138"
INFO[0005] Starting BackupController                     logSource="pkg/controller/backup_controller.go:153"
INFO[0005] Waiting for caches to sync                    logSource="pkg/controller/backup_controller.go:156"
INFO[0005] Starting controller                           controller=gc-controller logSource="pkg/controller/generic_controller.go:77"
INFO[0005] Waiting for caches to sync                    controller=gc-controller logSource="pkg/controller/generic_controller.go:80"
INFO[0005] Starting controller                           controller=backup-deletion logSource="pkg/controller/generic_controller.go:77"
INFO[0005] Waiting for caches to sync                    controller=backup-deletion logSource="pkg/controller/generic_controller.go:80"
INFO[0005] Starting RestoreController                    logSource="pkg/controller/restore_controller.go:154"
INFO[0005] Waiting for caches to sync                    logSource="pkg/controller/restore_controller.go:157"
INFO[0005] Starting DownloadRequestController            logSource="pkg/controller/download_request_controller.go:122"
INFO[0005] Waiting for caches to sync                    logSource="pkg/controller/download_request_controller.go:125"
INFO[0005] Starting controller                           controller=restic-repository logSource="pkg/controller/generic_controller.go:77"
INFO[0005] Waiting for caches to sync                    controller=restic-repository logSource="pkg/controller/generic_controller.go:80"
INFO[0005] Caches are synced                             controller=restic-repository logSource="pkg/controller/generic_controller.go:84"
DEBU[0005] resticRepositoryController.enqueueAllRepositories  controller=restic-repository logSource="pkg/controller/restic_repository_controller.go:88"
DEBU[0005] Backup is not new, skipping                   backup=heptio-ark/nginx-logs logSource="pkg/controller/backup_controller.go:116" phase=Failed
DEBU[0005] Backup is not new, skipping                   backup=heptio-ark/nginx-logs2 logSource="pkg/controller/backup_controller.go:116" phase=Failed
INFO[0005] Caches are synced                             logSource="pkg/controller/backup_controller.go:160"
DEBU[0005] backup doesn't have deprecated finalizer - skipping  backup=heptio-ark/nginx-logs2 logSource="pkg/cmd/server/server.go:721"
DEBU[0005] backup doesn't have deprecated finalizer - skipping  backup=heptio-ark/nginx-logs logSource="pkg/cmd/server/server.go:721"
INFO[0005] Server started successfully                   logSource="pkg/cmd/server/server.go:698"
INFO[0005] Caches are synced                             controller=gc-controller logSource="pkg/controller/generic_controller.go:84"
INFO[0005] Caches are synced                             controller=backup-deletion logSource="pkg/controller/generic_controller.go:84"
INFO[0005] Checking for expired DeleteBackupRequests     controller=backup-deletion logSource="pkg/controller/backup_deletion_controller.go:310"
DEBU[0005] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs expiration="2018-07-19 13:00:52 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
INFO[0005] Done checking for expired DeleteBackupRequests  controller=backup-deletion logSource="pkg/controller/backup_deletion_controller.go:338"
DEBU[0005] gcController.enqueueAllBackups                logSource="pkg/controller/gc_controller.go:88"
DEBU[0005] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs2 expiration="2018-07-19 13:25:37 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
DEBU[0005] Running processItem                           controller=backup-deletion key=heptio-ark/nginx-logs-xhmx5 logSource="pkg/controller/backup_deletion_controller.go:116"
DEBU[0005] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs expiration="2018-07-19 13:00:52 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
DEBU[0005] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs2 expiration="2018-07-19 13:25:37 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
DEBU[0005] Running processItem                           controller=backup-deletion key=heptio-ark/nginx-logs-qcpgb logSource="pkg/controller/backup_deletion_controller.go:116"
INFO[0005] Caches are synced                             logSource="pkg/controller/download_request_controller.go:129"
DEBU[0005] Running processItem                           controller=backup-deletion key=heptio-ark/nginx-logs-q4z8g logSource="pkg/controller/backup_deletion_controller.go:116"
INFO[0005] Caches are synced                             logSource="pkg/controller/restore_controller.go:161"
INFO[0005] Caches are synced                             logSource="pkg/controller/schedule_controller.go:142"
DEBU[0023] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs3 expiration="0001-01-01 00:00:00 +0000 UTC" logSource="pkg/controller/gc_controller.go:129"
DEBU[0023] Running processBackup                         key=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:210"
DEBU[0023] Getting backup                                key=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:216"
DEBU[0023] Cloning backup                                key=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:237"
DEBU[0023] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs3 expiration="2018-07-19 13:30:34 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
DEBU[0023] Running backup                                key=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:274"
INFO[0023] Starting backup                               backup=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:339"
DEBU[0023] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin backupitemaction serviceaccount]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0023] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0023] plugin address                                address=/tmp/plugin997521484 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
DEBU[0023] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin backupitemaction pv]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0023] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0023] plugin address                                address=/tmp/plugin947621501 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
DEBU[0023] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin backupitemaction pod]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0023] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0023] plugin address                                address=/tmp/plugin048892252 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
INFO[0034] Backup completed                              backup=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:395"
DEBU[0034] plugin process exited                         logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
ERRO[0034] backup failed                                 error="restic repository not found: resticrepository.ark.heptio.com \"nginx-example\" not found" key=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:280"
DEBU[0034] Updating backup's final status                key=heptio-ark/nginx-logs3 logSource="pkg/controller/backup_controller.go:287"
DEBU[0034] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs3 expiration="2018-07-19 13:30:34 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
DEBU[0461] Running processQueueItem                      controller=restic-repository key=heptio-ark/nginx-example logSource="pkg/controller/restic_repository_controller.go:103"
INFO[0461] Initializing restic repository                controller=restic-repository logSource="pkg/controller/restic_repository_controller.go:138" name=nginx-example namespace=heptio-ark
DEBU[0461] Ran restic command                            command="/restic check --repo=s3:s3.amazonaws.com/<REDACTED>restic/nginx-example --password-file=/tmp/ark-restic-credentials-nginx-example069952081" logSource="pkg/restic/repository_manager.go:212" repository=nginx-example stderr= stdout=
DEBU[0461] Ran restic command                            command="/restic init --repo=s3:s3.amazonaws.com/<REDACTED>restic/nginx-example --password-file=/tmp/ark-restic-credentials-nginx-example272636796" logSource="pkg/restic/repository_manager.go:212" repository=nginx-example stderr= stdout=
DEBU[0501] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs4 expiration="0001-01-01 00:00:00 +0000 UTC" logSource="pkg/controller/gc_controller.go:129"
DEBU[0501] Running processBackup                         key=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:210"
DEBU[0501] Getting backup                                key=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:216"
DEBU[0501] Cloning backup                                key=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:237"
DEBU[0501] Running backup                                key=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:274"
INFO[0501] Starting backup                               backup=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:339"
DEBU[0501] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin backupitemaction pv]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0501] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs4 expiration="2018-07-19 13:38:32 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"
DEBU[0501] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0501] plugin address                                address=/tmp/plugin791216626 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
DEBU[0501] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin backupitemaction pod]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0501] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0501] plugin address                                address=/tmp/plugin378336319 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
DEBU[0501] starting plugin                               args="[./_output/bin/linux/amd64/ark run-plugin backupitemaction serviceaccount]" logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0501] waiting for RPC address                       logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
DEBU[0501] plugin address                                address=/tmp/plugin842789348 logSource="pkg/plugin/logrus_adapter.go:74" network=unix pluginName=ark
INFO[0512] Backup completed                              backup=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:395"
DEBU[0512] plugin process exited                         logSource="pkg/plugin/logrus_adapter.go:74" path=./_output/bin/linux/amd64/ark
ERRO[0512] backup failed                                 error="restic repository not ready" key=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:280"
DEBU[0512] Updating backup's final status                key=heptio-ark/nginx-logs4 logSource="pkg/controller/backup_controller.go:287"
DEBU[0513] Backup has not expired yet, skipping          backup=heptio-ark/nginx-logs4 expiration="2018-07-19 13:38:32 -0400 EDT" logSource="pkg/controller/gc_controller.go:129"