search

wal-g / wal-g

Archival and Restoration for databases in the Cloud
Other
3.2k stars 455 forks source link

wal-g can't iterate over s3 swift bucket #1017

Open yurchenkosv opened 3 years ago

yurchenkosv commented 3 years ago

Database name

postgresql 11.9

Issue description

wal-g can't iterate over wal_005 folder in s3(swift)

Describe your problem

When I try to do delete retain FULL 7 command, I've got an arror message 

ERROR: 2021/06/21 11:47:15.216373 Failed to get WAL folder filenames Swift error : Unable to iterate wal_005/: Object Not Found

The same error apearse when I try to do wal-verify But postgres archive_command works as expected and new objects uploads to bucket Full backup works as well

Please provide steps to reproduce

// it can really help This is happened second time after month work without problem, I can't realy understand what happened.

Please add config and wal-g stdout/stderr logs for debug purpose

also you can use WALG_LOG_LEVEL=DEVEL for logs collecting

If you can, provide logs

```bash DEBUG: 2021/06/21 12:50:01.541331 --- COMPILED ENVIRONMENT VARS --- DEBUG: 2021/06/21 12:50:01.541362 SHELL=/bin/bash DEBUG: 2021/06/21 12:50:01.541370 WALG_COMPRESSION_METHOD=brotli DEBUG: 2021/06/21 12:50:01.541376 SUDO_GID=1004 DEBUG: 2021/06/21 12:50:01.541382 OS_REGION_NAME=GRA DEBUG: 2021/06/21 12:50:01.541389 SUDO_COMMAND=/usr/bin/su DEBUG: 2021/06/21 12:50:01.541395 SUDO_USER=yurchenko DEBUG: 2021/06/21 12:50:01.541401 PWD=/home/yurchenko DEBUG: 2021/06/21 12:50:01.541417 WALG_DOWNLOAD_CONCURRENCY=4 DEBUG: 2021/06/21 12:50:01.541423 LOGNAME=root DEBUG: 2021/06/21 12:50:01.541429 OS_AUTH_URL=https://auth.cloud.ovh.net/v3/ DEBUG: 2021/06/21 12:50:01.541436 OS_PROJECT_DOMAIN_NAME=Default DEBUG: 2021/06/21 12:50:01.541442 HOME=/root DEBUG: 2021/06/21 12:50:01.541448 LANG=en_US.UTF-8 DEBUG: 2021/06/21 12:50:01.541469 PGUSER=postgres DEBUG: 2021/06/21 12:50:01.541487 TERM=xterm-256color DEBUG: 2021/06/21 12:50:01.541493 USER=root DEBUG: 2021/06/21 12:50:01.541499 WALG_LOG_LEVEL=DEVEL DEBUG: 2021/06/21 12:50:01.541511 SHLVL=2 DEBUG: 2021/06/21 12:50:01.541523 OS_USER_DOMAIN_NAME=Default DEBUG: 2021/06/21 12:50:01.541530 PGHOST=/var/lib/postgresql-socket DEBUG: 2021/06/21 12:50:01.541536 PGDATA=/var/lib/pgsql/11.9/data DEBUG: 2021/06/21 12:50:01.541548 WALG_UPLOAD_DISK_CONCURRENCY=3 DEBUG: 2021/06/21 12:50:01.541554 PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin DEBUG: 2021/06/21 12:50:01.541560 SUDO_UID=1003 DEBUG: 2021/06/21 12:50:01.541566 MAIL=/var/mail/root DEBUG: 2021/06/21 12:50:01.541572 WALG_UPLOAD_CONCURRENCY=1 DEBUG: 2021/06/21 12:50:01.541578 OS_IDENTITY_API_VERSION=3 DEBUG: 2021/06/21 12:50:01.541584 _=/usr/local/bin/wal-g DEBUG: 2021/06/21 12:50:01.541590 WALG_USE_REVERSE_UNPACK=false DEBUG: 2021/06/21 12:50:01.541596 SSH_PORT= DEBUG: 2021/06/21 12:50:01.541601 WALG_PGP_KEY_PATH= DEBUG: 2021/06/21 12:50:01.541607 PGPASSFILE= DEBUG: 2021/06/21 12:50:01.541614 AWS_ROLE_SESSION_NAME= DEBUG: 2021/06/21 12:50:01.541619 TOTAL_BG_UPLOADED_LIMIT=32 DEBUG: 2021/06/21 12:50:01.541626 S3_ENDPOINT_SOURCE= DEBUG: 2021/06/21 12:50:01.541632 WALG_GPG_KEY_ID= DEBUG: 2021/06/21 12:50:01.541638 OPLOG_PUSH_WAIT_FOR_BECOME_PRIMARY=false DEBUG: 2021/06/21 12:50:01.541644 WALG_S3_STORAGE_CLASS= DEBUG: 2021/06/21 12:50:01.541650 S3_ENDPOINT_PORT= DEBUG: 2021/06/21 12:50:01.541656 WALG_MYSQL_BACKUP_PREPARE_COMMAND= DEBUG: 2021/06/21 12:50:01.541663 WALG_S3_CA_CERT_FILE= DEBUG: 2021/06/21 12:50:01.541669 OPLOG_ARCHIVE_AFTER_SIZE=16777216 DEBUG: 2021/06/21 12:50:01.541676 AZURE_STORAGE_SAS_TOKEN= DEBUG: 2021/06/21 12:50:01.541682 AWS_DEFAULT_OUTPUT= DEBUG: 2021/06/21 12:50:01.541688 OPLOG_PUSH_STATS_UPDATE_INTERVAL=30s DEBUG: 2021/06/21 12:50:01.541694 OPLOG_ARCHIVE_TIMEOUT_INTERVAL=60s DEBUG: 2021/06/21 12:50:01.541700 WALG_PREVENT_WAL_OVERWRITE=false DEBUG: 2021/06/21 12:50:01.541707 WALG_S3_SSE_KMS_ID= DEBUG: 2021/06/21 12:50:01.541713 WALG_STREAM_CREATE_COMMAND= DEBUG: 2021/06/21 12:50:01.541719 WALG_AZURE_MAX_BUFFERS= DEBUG: 2021/06/21 12:50:01.541725 WALG_AZURE_BUFFER_SIZE= DEBUG: 2021/06/21 12:50:01.541732 WALG_STORE_ALL_CORRUPT_BLOCKS=false DEBUG: 2021/06/21 12:50:01.541738 SQLSERVER_BLOB_CERT_FILE= DEBUG: 2021/06/21 12:50:01.541744 WALG_PGP_KEY_PASSPHRASE= DEBUG: 2021/06/21 12:50:01.541750 OPLOG_PUSH_STATS_EXPOSE_HTTP= DEBUG: 2021/06/21 12:50:01.541756 AWS_SECRET_ACCESS_KEY= DEBUG: 2021/06/21 12:50:01.541762 AWS_CONFIG_FILE= DEBUG: 2021/06/21 12:50:01.541768 PGPORT= DEBUG: 2021/06/21 12:50:01.541775 WALG_FILE_PREFIX= DEBUG: 2021/06/21 12:50:01.541781 MONGODB_URI= DEBUG: 2021/06/21 12:50:01.541788 SQLSERVER_BLOB_HOSTNAME= DEBUG: 2021/06/21 12:50:01.541794 WALG_SSH_PREFIX= DEBUG: 2021/06/21 12:50:01.541800 GOMAXPROCS= DEBUG: 2021/06/21 12:50:01.541806 HTTP_EXPOSE_EXPVAR= DEBUG: 2021/06/21 12:50:01.541813 SQLSERVER_CONNECTION_STRING= DEBUG: 2021/06/21 12:50:01.541819 SSH_PRIVATE_KEY_PATH= DEBUG: 2021/06/21 12:50:01.541825 AWS_CA_BUNDLE= DEBUG: 2021/06/21 12:50:01.541831 WALG_MYSQL_BINLOG_REPLAY_COMMAND= DEBUG: 2021/06/21 12:50:01.541837 PGDATABASE= DEBUG: 2021/06/21 12:50:01.541843 WALG_S3_PREFIX= DEBUG: 2021/06/21 12:50:01.541849 WALG_STREAM_RESTORE_COMMAND= DEBUG: 2021/06/21 12:50:01.541856 AWS_SESSION_TOKEN= DEBUG: 2021/06/21 12:50:01.541862 WALG_VERIFY_PAGE_CHECKSUMS=false DEBUG: 2021/06/21 12:50:01.541868 OPLOG_PUSH_STATS_ENABLED= DEBUG: 2021/06/21 12:50:01.541874 SQLSERVER_BLOB_KEY_FILE= DEBUG: 2021/06/21 12:50:01.541881 WALG_MYSQL_SSL_CA= DEBUG: 2021/06/21 12:50:01.541887 AWS_DEFAULT_REGION= DEBUG: 2021/06/21 12:50:01.541906 WALG_SENTINEL_USER_DATA= DEBUG: 2021/06/21 12:50:01.541913 WALG_MYSQL_TAKE_BINLOGS_FROM_MASTER= DEBUG: 2021/06/21 12:50:01.541925 WALG_GS_PREFIX= DEBUG: 2021/06/21 12:50:01.541932 WALG_DISK_RATE_LIMIT= DEBUG: 2021/06/21 12:50:01.541939 AWS_ENDPOINT= DEBUG: 2021/06/21 12:50:01.541945 OPLOG_PUSH_STATS_LOGGING_INTERVAL=30s DEBUG: 2021/06/21 12:50:01.541952 WALG_S3_SSE= DEBUG: 2021/06/21 12:50:01.541958 PGSSLMODE= DEBUG: 2021/06/21 12:50:01.541965 HTTP_EXPOSE_PPROF= DEBUG: 2021/06/21 12:50:01.541971 OPLOG_PITR_DISCOVERY_INTERVAL= DEBUG: 2021/06/21 12:50:01.541977 WALG_AZ_PREFIX= DEBUG: 2021/06/21 12:50:01.541983 WALG_USE_WAL_DELTA=false DEBUG: 2021/06/21 12:50:01.541989 WALG_CSE_KMS_ID= DEBUG: 2021/06/21 12:50:01.541995 WALE_S3_PREFIX= DEBUG: 2021/06/21 12:50:01.542001 AWS_SHARED_CREDENTIALS_FILE= DEBUG: 2021/06/21 12:50:01.542008 MONGODB_LAST_WRITE_UPDATE_INTERVAL=3s DEBUG: 2021/06/21 12:50:01.542014 WALG_MYSQL_BINLOG_DST= DEBUG: 2021/06/21 12:50:01.542020 WALG_TAR_SIZE_THRESHOLD=1073741823 DEBUG: 2021/06/21 12:50:01.542026 WALG_NETWORK_RATE_LIMIT= DEBUG: 2021/06/21 12:50:01.542033 AZURE_STORAGE_ACCOUNT= DEBUG: 2021/06/21 12:50:01.542039 WALG_PG_WAL_SIZE=16 DEBUG: 2021/06/21 12:50:01.542045 WALE_GPG_KEY_ID= DEBUG: 2021/06/21 12:50:01.542051 WALG_MYSQL_DATASOURCE_NAME= DEBUG: 2021/06/21 12:50:01.542057 AWS_S3_FORCE_PATH_STYLE= DEBUG: 2021/06/21 12:50:01.542064 OPLOG_PUSH_PRIMARY_CHECK_INTERVAL=30s DEBUG: 2021/06/21 12:50:01.542070 AWS_ACCESS_KEY_ID= DEBUG: 2021/06/21 12:50:01.542076 WALG_S3_MAX_PART_SIZE= DEBUG: 2021/06/21 12:50:01.542082 HTTP_LISTEN= DEBUG: 2021/06/21 12:50:01.542088 AZURE_STORAGE_KEY= DEBUG: 2021/06/21 12:50:01.542094 AWS_PROFILE= DEBUG: 2021/06/21 12:50:01.542101 SSH_PASSWORD= DEBUG: 2021/06/21 12:50:01.542107 WALG_CSE_KMS_REGION= DEBUG: 2021/06/21 12:50:01.542113 WALG_PGP_KEY= DEBUG: 2021/06/21 12:50:01.542119 PGPASSWORD= DEBUG: 2021/06/21 12:50:01.542125 WALG_SLOTNAME= DEBUG: 2021/06/21 12:50:01.542132 GOOGLE_APPLICATION_CREDENTIALS= DEBUG: 2021/06/21 12:50:01.542138 AWS_REGION= DEBUG: 2021/06/21 12:50:01.542144 WALG_USE_RATING_COMPOSER=false DEBUG: 2021/06/21 12:50:01.542150 WALG_SKIP_REDUNDANT_TARS=false DEBUG: 2021/06/21 12:50:01.542157 WALG_DELTA_ORIGIN= DEBUG: 2021/06/21 12:50:01.542163 WALG_UPLOAD_QUEUE=2 DEBUG: 2021/06/21 12:50:01.542169 SSH_USERNAME= DEBUG: 2021/06/21 12:50:01.542175 WALG_DELTA_MAX_STEPS=0 ERROR: 2021/06/21 12:50:03.382151 Failed to get WAL folder filenames Object Not Found Swift error : Unable to iterate wal_005/ github.com/wal-g/storages/storage.NewError /home/travis/gopath/src/github.com/wal-g/wal-g/vendor/github.com/wal-g/storages/storage/errors.go:26 github.com/wal-g/storages/swift.NewError /home/travis/gopath/src/github.com/wal-g/wal-g/vendor/github.com/wal-g/storages/swift/folder.go:24 github.com/wal-g/storages/swift.(*Folder).ListFolder /home/travis/gopath/src/github.com/wal-g/wal-g/vendor/github.com/wal-g/storages/swift/folder.go:111 github.com/wal-g/wal-g/internal.getFolderFilenames /home/travis/gopath/src/github.com/wal-g/wal-g/internal/wal_segment_runner.go:104 github.com/wal-g/wal-g/internal.HandleWalVerify /home/travis/gopath/src/github.com/wal-g/wal-g/internal/wal_verify_handler.go:114 github.com/wal-g/wal-g/cmd/pg.glob..func13 /home/travis/gopath/src/github.com/wal-g/wal-g/cmd/pg/wal_verify.go:36 github.com/spf13/cobra.(*Command).execute /home/travis/gopath/src/github.com/wal-g/wal-g/vendor/github.com/spf13/cobra/command.go:830 github.com/spf13/cobra.(*Command).ExecuteC /home/travis/gopath/src/github.com/wal-g/wal-g/vendor/github.com/spf13/cobra/command.go:914 github.com/spf13/cobra.(*Command).Execute /home/travis/gopath/src/github.com/wal-g/wal-g/vendor/github.com/spf13/cobra/command.go:864 github.com/wal-g/wal-g/cmd/pg.Execute /home/travis/gopath/src/github.com/wal-g/wal-g/cmd/pg/pg.go:39 main.main /home/travis/gopath/src/github.com/wal-g/wal-g/main/pg/main.go:8 runtime.main /home/travis/.gimme/versions/go1.13.15.linux.amd64/src/runtime/proc.go:203 runtime.goexit /home/travis/.gimme/versions/go1.13.15.linux.amd64/src/runtime/asm_amd64.s:1357 ```

usernamedt commented 3 years ago

Can you provide a listing of the bucket?

yurchenkosv commented 3 years ago

@usernamedt thanks for your reply. Here the listing of bucket:

wal_005/000000010000013300000090.br | 9 Jun 2021 11:32:14 | 7.18 MB | application/octet-stream |  
wal_005/000000010000013300000091.br | 9 Jun 2021 11:33:57 | 4.34 MB | application/octet-stream |  
wal_005/000000010000013300000092.br | 9 Jun 2021 11:35:00 | 4.97 MB | application/octet-stream |  
wal_005/000000010000013300000093.br | 9 Jun 2021 11:35:35 | 3.58 MB | application/octet-stream |  
wal_005/000000010000013300000094.br | 9 Jun 2021 11:36:16 | 4.09 MB | application/octet-stream |  
wal_005/000000010000013300000095.br | 9 Jun 2021 11:36:42 | 3.71 MB | application/octet-stream |  
wal_005/000000010000013300000096.br | 9 Jun 2021 11:37:03 | 4.94 MB | application/octet-stream |  
wal_005/000000010000013300000097.br | 9 Jun 2021 11:37:29 | 3.2 MB | application/octet-stream |  
wal_005/000000010000013300000098.br | 9 Jun 2021 11:38:58 | 3.82 MB | application/octet-stream |  
wal_005/000000010000013300000099.br | 9 Jun 2021 11:39:53 | 4.22 MB | application/octet-stream |  
wal_005/00000001000001330000009A.br | 9 Jun 2021 11:40:32 | 4.06 MB | application/octet-stream |  
wal_005/00000001000001330000009B.br | 9 Jun 2021 11:40:33 | 5.59 MB | application/octet-stream |  
wal_005/00000001000001330000009C.br | 9 Jun 2021 11:40:35 | 4.78 MB | application/octet-stream |  
wal_005/00000001000001330000009D.br | 9 Jun 2021 11:41:05 | 6.03 MB | application/octet-stream |  
wal_005/00000001000001330000009E.br | 9 Jun 2021 11:41:07 | 4.03 MB | application/octet-stream |  
wal_005/00000001000001330000009F.br | 9 Jun 2021 11:41:08 | 5.74 MB | application/octet-stream |  
wal_005/0000000100000133000000A0.br | 9 Jun 2021 11:42:40 | 4.21 MB | application/octet-stream |  
wal_005/0000000100000133000000A1.br | 9 Jun 2021 11:43:01 | 2.3 MB | application/octet-stream |  
wal_005/0000000100000133000000A2.br | 9 Jun 2021 11:43:12 | 2.23 MB | application/octet-stream |  
wal_005/0000000100000133000000A3.br | 9 Jun 2021 11:44:21 | 3.96 MB | application/octet-stream |  
wal_005/0000000100000133000000A4.br | 9 Jun 2021 11:44:55 | 4.49 MB | application/octet-stream |  
wal_005/0000000100000133000000A5.br | 9 Jun 2021 11:45:25 | 4.62 MB | application/octet-stream

As you can see, there is wal_005 folder, but wal-g couldn't see it.

usernamedt commented 3 years ago

Do you have a config file or env variable to define the WALG_SWIFT_PREFIX? I can't find it in the attached debug output

yurchenkosv commented 3 years ago

Yes, this env variable appears in logs. I've made some review on logs and delete sensitive info (logins, passwords, etc.) Perhaps, WALG_SWIFT_PREFIX was one, that I've deleted.

DEBUG: 2021/07/12 15:19:30.211703 WALG_SWIFT_PREFIX=swift://1c-pg-backup-prod