wal-g icon indicating copy to clipboard operation
wal-g copied to clipboard
verified publisher icon wal-g

Error reading binlog after upgrading wal-g from v3.0.3 to v3.0.5

Open johnbizokk opened this issue 9 months ago • 7 comments

Description

After updating wal-g from version 3.0.3 to 3.0.5, running the command below results in an error:

wal-g backup-push --turbo

Error Message

Failed to get last uploaded binlog: failed to read binlog beginning

Environment Details

  • MariaDB Image: registry-1.docker.io/library/mariadb:11.6.2@sha256:a9547599cd87d7242435aea6fda22a9d83e2c06d16c658ef70d2868b3d3f6a80
  • Wal-g release: https://github.com/wal-g/wal-g/releases/download/v3.0.5/wal-g-mysql-ubuntu-20.04-amd64.tar.gz

Expected Behavior

The backup should complete successfully without any binlog read errors.

Actual Behavior

The process fails with the error message mentioned above. Rolling back to v3.0.3 resolves the issue, indicating that the problem is likely related to changes introduced in v3.0.5.

johnbizokk avatar Mar 07 '25 11:03 johnbizokk

@teem0n @ostinru please take a look

x4m avatar Mar 07 '25 11:03 x4m

There was no major changes in this code for couple years, so I don't know why version downgrade helps.

Let's do 2 things:

  1. wal-g st ls binlog_005/ - check file sizes (if there is files with less that 128kb)
  2. check that in the working directory (where wal-g was started) whether there are binlog files
  3. try to reproduce it with v3.0.4 (if you can) - this will reduce search erea in half

ostinru avatar Mar 07 '25 12:03 ostinru

v3.0.3

  • wal-g backup-push: no error
  • wal-g binlog-push: no error
  • working directory is fs root which does not contain any binlog files
root@walg-mariadb:/# wal-g --version
mysql version v3.0.3    3f88f3c 2024.08.08_17:52:48     MySQL
root@walg-mariadb:/# wal-g st ls binlog_005/
WARNING: 2025/03/07 13:28:55.644454 WALG_FAILOVER_STORAGES_CACHE_LIFETIME is unknown
WARNING: 2025/03/07 13:28:55.644501 WALG_FAILOVER_STORAGES_CHECK_TIMEOUT is unknown
WARNING: 2025/03/07 13:28:55.644531 We found that some variables in your config file detected as 'Unknown'.
  If this is not right, please create issue https://github.com/wal-g/wal-g/issues/new
type size last modified                     name
obj  1067 2025-01-24 21:40:01.329 +0000 UTC mysqld-bin.000003.br
obj  192  2025-01-28 10:40:00.982 +0000 UTC mysqld-bin.000004.br
obj  198  2025-02-19 18:20:01.192 +0000 UTC mysqld-bin.000005.br
obj  195  2025-02-25 18:10:01.058 +0000 UTC mysqld-bin.000006.br
obj  196  2025-03-07 09:40:00.873 +0000 UTC mysqld-bin.000007.br
root@walg-mariadb:/# wal-g backup-push --turbo
WARNING: 2025/03/07 13:29:05.663390 WALG_FAILOVER_STORAGES_CACHE_LIFETIME is unknown
WARNING: 2025/03/07 13:29:05.663444 WALG_FAILOVER_STORAGES_CHECK_TIMEOUT is unknown
WARNING: 2025/03/07 13:29:05.663460 We found that some variables in your config file detected as 'Unknown'.
  If this is not right, please create issue https://github.com/wal-g/wal-g/issues/new
INFO: 2025/03/07 13:29:12.124282 FILE PATH: stream_20250307T132905Z/stream.br
INFO: 2025/03/07 13:29:12.166576 Backup sentinel: {"Tool":"WALG_UNSPECIFIED_STREAM_BACKUP_TOOL","BinLogStart":"mysqld-bin.000007","BinLogEnd":"mysqld-bin.000007","StartLocalTime":"2025-03-07T13:29:05.801081Z","StopLocalTime":"2025-03-07T13:29:12.1665Z","UncompressedSize":73083779,"CompressedSize":1784487,"Hostname":"walg-mariadb","ServerVersion":"11.6.2-MariaDB-ubu2404-log","IsPermanent":false,"IsIncremental":false,"LSN":null,"DeltaCount":0}

v3.0.4

  • wal-g backup-push: no error
  • wal-g binlog-push: no error
  • working directory is fs root which does not contain any binlog files
root@walg-mariadb:/# wal-g --version
mysql version v3.0.4    f20428f 2024.10.30_17:59:17     MySQL
root@walg-mariadb:/# wal-g st ls binlog_005/
WARNING: 2025/03/07 13:35:37.641657 WALG_FAILOVER_STORAGES_CACHE_LIFETIME is unknown
WARNING: 2025/03/07 13:35:37.641692 WALG_FAILOVER_STORAGES_CHECK_TIMEOUT is unknown
WARNING: 2025/03/07 13:35:37.641703 We found that some variables in your config file detected as 'Unknown'.
  If this is not right, please create issue https://github.com/wal-g/wal-g/issues/new
type size last modified                     name
obj  1067 2025-01-24 21:40:01.329 +0000 UTC mysqld-bin.000003.br
obj  192  2025-01-28 10:40:00.982 +0000 UTC mysqld-bin.000004.br
obj  198  2025-02-19 18:20:01.192 +0000 UTC mysqld-bin.000005.br
obj  195  2025-02-25 18:10:01.058 +0000 UTC mysqld-bin.000006.br
obj  196  2025-03-07 09:40:00.873 +0000 UTC mysqld-bin.000007.br
root@walg-mariadb:/# wal-g backup-push --turbo
WARNING: 2025/03/07 13:35:44.144532 WALG_FAILOVER_STORAGES_CACHE_LIFETIME is unknown
WARNING: 2025/03/07 13:35:44.144592 WALG_FAILOVER_STORAGES_CHECK_TIMEOUT is unknown
WARNING: 2025/03/07 13:35:44.144604 We found that some variables in your config file detected as 'Unknown'.
  If this is not right, please create issue https://github.com/wal-g/wal-g/issues/new
INFO: 2025/03/07 13:35:50.723681 FILE PATH: stream_20250307T133544Z/stream.br
INFO: 2025/03/07 13:35:50.765454 Backup sentinel: {"Tool":"WALG_UNSPECIFIED_STREAM_BACKUP_TOOL","BinLogStart":"mysqld-bin.000007","BinLogEnd":"mysqld-bin.000007","StartLocalTime":"2025-03-07T13:35:44.280741Z","StopLocalTime":"2025-03-07T13:35:50.765341Z","UncompressedSize":73083779,"CompressedSize":1784486,"Hostname":"walg-mariadb","ServerVersion":"11.6.2-MariaDB-ubu2404-log","IsPermanent":false,"IsIncremental":false,"LSN":null,"DeltaCount":0}
INFO: 2025/03/07 13:35:50.914360 binlog counting mode is disabled: option is disabled

v3.0.5

  • wal-g backup-push: error
  • wal-g binlog-push: no error
  • working directory is fs root which does not contain any binlog files
root@walg-mariadb:/# wal-g --version
mysql version v3.0.5    94bf839 2025.01.10_13:12:30     MySQL
root@walg-mariadb:/# wal-g st ls binlog_005/
WARNING: 2025/03/07 13:34:25.579137 WALG_FAILOVER_STORAGES_CACHE_LIFETIME is unknown
WARNING: 2025/03/07 13:34:25.579175 WALG_FAILOVER_STORAGES_CHECK_TIMEOUT is unknown
WARNING: 2025/03/07 13:34:25.579186 We found that some variables in your config file detected as 'Unknown'.
  If this is not right, please create issue https://github.com/wal-g/wal-g/issues/new
type size last modified                     name
obj  1067 2025-01-24 21:40:01.329 +0000 UTC mysqld-bin.000003.br
obj  192  2025-01-28 10:40:00.982 +0000 UTC mysqld-bin.000004.br
obj  198  2025-02-19 18:20:01.192 +0000 UTC mysqld-bin.000005.br
obj  195  2025-02-25 18:10:01.058 +0000 UTC mysqld-bin.000006.br
obj  196  2025-03-07 09:40:00.873 +0000 UTC mysqld-bin.000007.br
root@walg-mariadb:/# wal-g backup-push --turbo
WARNING: 2025/03/07 13:34:31.357979 WALG_FAILOVER_STORAGES_CACHE_LIFETIME is unknown
WARNING: 2025/03/07 13:34:31.358016 WALG_FAILOVER_STORAGES_CHECK_TIMEOUT is unknown
WARNING: 2025/03/07 13:34:31.358028 We found that some variables in your config file detected as 'Unknown'.
  If this is not right, please create issue https://github.com/wal-g/wal-g/issues/new
ERROR: 2025/03/07 13:34:31.495179 failed to get last uploaded binlog: failed to read binlog beginning

johnbizokk avatar Mar 07 '25 13:03 johnbizokk

There almost no changes in between 3.0.4 and 3.0.5 =/

Triggered run tests with MariaDB 11.6 https://github.com/wal-g/wal-g/pull/1929

ostinru avatar Mar 07 '25 16:03 ostinru

Finally mananged to run tests with MariaDB 11.6. No issues in current master =/ https://github.com/wal-g/wal-g/pull/1929

However no issues observed.

Current theory - there is some issues with one of the uploaded binlogs (or no binlog uploaded).

ostinru avatar Mar 10 '25 12:03 ostinru

Test passed. So, it should work for basic scenarious.

@johnbizokk , Could you please show WALG_STREAM_CREATE_COMMAND and WALG_MYSQL_CHECK_GTIDS from your config?

ostinru avatar Mar 13 '25 17:03 ostinru

envs

MARIADB_DB_HOST='mariadb'
MARIADB_DB_PORT='3306'
MARIADB_DB_DATABASE='db-name'
MARIADB_DB_USERNAME='db-walg-user'
MARIADB_DB_PASSWORD='db-walg-pass'
MARIADB_DB_PATH='/var/lib/mysql'
CONN_OPTIONS="--user=${MARIADB_DB_USERNAME} --password=${MARIADB_DB_PASSWORD} --host=${MARIADB_DB_HOST} --port=${MARIADB_DB_PORT}"
WALG_MYSQL_DATASOURCE_NAME="${MARIADB_DB_USERNAME}:${MARIADB_DB_PASSWORD}@tcp(${MARIADB_DB_HOST}:${MARIADB_DB_PORT})/${MARIADB_DB_DATABASE}"
WALG_STREAM_CREATE_COMMAND="mariabackup --backup --stream=mbstream --datadir=${MARIADB_DB_PATH} ${CONN_OPTIONS}"
WALG_STREAM_RESTORE_COMMAND="mbstream -x -C ${MARIADB_DB_PATH}"
WALG_MYSQL_BACKUP_PREPARE_COMMAND="mariabackup --prepare --target-dir=${MARIADB_DB_PATH} ${CONN_OPTIONS}"
WALG_MYSQL_BINLOG_REPLAY_COMMAND='mariadb-binlog --stop-datetime="${WALG_MYSQL_BINLOG_END_TS}" "${WALG_MYSQL_CURRENT_BINLOG}" | mariadb'
WALG_MYSQL_BINLOG_DST='/tmp'
AWS_ACCESS_KEY_ID='ACCESS_KEY'
AWS_SECRET_ACCESS_KEY='SECRET_KEY'
WALG_COMPRESSION_METHOD='brotli' 
WALG_DELTA_MAX_STEPS='6'
WALG_UPLOAD_CONCURRENCY='10' 
WALG_DISK_RATE_LIMIT='41943040' 
WALG_NETWORK_RATE_LIMIT='10485760'

the WALG_MYSQL_CHECK_GTIDS environment variable is unset

mariadb command

mariadbd --log-bin=mysqld-bin --gtid-strict-mode

johnbizokk avatar Mar 13 '25 19:03 johnbizokk