Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Won't Fix
-
10.0.21-galera
Description
This was a galera node acting as an async sync slave to another non-galera server. This server had log-slave-updates enabled.
The slave status before the start:
MariaDB [(none)]> show slave status\G
|
*************************** 1. row ***************************
|
Slave_IO_State: Waiting for master to send event
|
Master_Host: localhost
|
Master_User: replication
|
Master_Port: 63306
|
Connect_Retry: 60
|
Master_Log_File: mysql-bin.034995
|
Read_Master_Log_Pos: 51689463
|
Relay_Log_File: mysqld-relay-bin.000201
|
Relay_Log_Pos: 53798956
|
Relay_Master_Log_File: mysql-bin.034775
|
Slave_IO_Running: Yes
|
Slave_SQL_Running: No
|
Replicate_Do_DB:
|
Replicate_Ignore_DB:
|
Replicate_Do_Table:
|
Replicate_Ignore_Table:
|
Replicate_Wild_Do_Table:
|
Replicate_Wild_Ignore_Table:
|
Last_Errno: 0
|
Last_Error:
|
Skip_Counter: 0
|
Exec_Master_Log_Pos: 53798665
|
Relay_Log_Space: 22683519000
|
Until_Condition: None
|
Until_Log_File:
|
Until_Log_Pos: 0
|
Master_SSL_Allowed: No
|
Master_SSL_CA_File:
|
Master_SSL_CA_Path:
|
Master_SSL_Cert:
|
Master_SSL_Cipher:
|
Master_SSL_Key:
|
Seconds_Behind_Master: NULL
|
Master_SSL_Verify_Server_Cert: No
|
Last_IO_Errno: 0
|
Last_IO_Error:
|
Last_SQL_Errno: 0
|
Last_SQL_Error:
|
Replicate_Ignore_Server_Ids:
|
Master_Server_Id: 9
|
Master_SSL_Crl:
|
Master_SSL_Crlpath:
|
Using_Gtid: No
|
Gtid_IO_Pos:
|
1 row in set (0.00 sec)
|
It was started with:
start slave sql_thread until RELAY_LOG_FILE = 'mysqld-relay-bin.000837', RELAY_LOG_POS = 0;
|
636 relay log files is quite large amount so I'm assuming the limit is bypassed for this UNTIL RELAY_LOG_FILE options to start slave.
Seems the limit got exceeded in the binary logs
| max_binlog_size | 104857600 |
|
|
|
-rw-rw---- 1 mysql mysql 107362623 Aug 28 13:13 mysql-bin.000057
|
-rw-rw---- 1 mysql mysql 104866589 Aug 28 13:13 mysql-bin.000058
|
-rw-rw---- 1 mysql mysql 105813602 Aug 28 13:14 mysql-bin.000059
|
-rw-rw---- 1 mysql mysql 105470582 Aug 28 13:14 mysql-bin.000060
|
-rw-rw---- 1 mysql mysql 35721262759 Sep 3 12:30 mysql-bin.000061
|
-rw-rw---- 1 mysql mysql 1952 Aug 28 13:14 mysql-bin.index
|
|
|
mysql]# tail mysql-bin.index
|
/var/lib/mysql/mysql-bin.000052
|
/var/lib/mysql/mysql-bin.000053
|
/var/lib/mysql/mysql-bin.000054
|
/var/lib/mysql/mysql-bin.000055
|
/var/lib/mysql/mysql-bin.000056
|
/var/lib/mysql/mysql-bin.000057
|
/var/lib/mysql/mysql-bin.000058
|
/var/lib/mysql/mysql-bin.000059
|
/var/lib/mysql/mysql-bin.000060
|
/var/lib/mysql/mysql-bin.000061
|
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
MDEV-11610 Logrotate to only FLUSH LOCAL ERROR LOGS, ENGINE LOGS, GENERAL LOGS
-
- Closed
-
Activity
Yes, I tried with until RELAY_LOG_FILE <...> RELAY_LOG_POS = 0, although it's no guarantee, maybe there is some specific set of circumstances that triggers it, e.g. to make it faster i tried to reproduce using non-default max_binlog_size=4096 and max_relay_log_size=4096, while maybe it only happens when values are set to hard max (1G), and so on, there can be various "maybe"s. But it's also possible that it's somehow related to wsrep-specific code, so it's worth checking.
fyi running now with a straight "start slave" and the max_binlog_size is being respected.
-rw-rw---- 1 mysql mysql 104878797 Sep 4 22:58 mysql-bin.000107
|
-rw-rw---- 1 mysql mysql 104871195 Sep 4 23:01 mysql-bin.000108
|
-rw-rw---- 1 mysql mysql 104865248 Sep 4 23:04 mysql-bin.000109
|
-rw-rw---- 1 mysql mysql 105048814 Sep 4 23:05 mysql-bin.000110
|
-rw-rw---- 1 mysql mysql 104885255 Sep 4 23:06 mysql-bin.000111
|
-rw-rw---- 1 mysql mysql 104865257 Sep 4 23:07 mysql-bin.000112
|
-rw-rw---- 1 mysql mysql 97487026 Sep 4 23:09 mysql-bin.000113
|
Have only changed sst method open-file-limit and slave-skip-errors = all (work around from MDEV-8744 - the highest pri for me).
I'm not getting it right away with the "normal" server, could you please take a look to see if it can be galera-specific?
normal async slave, parallel thread setting exists though ra and not in gtid mode.
# Server settings.
|
[mysqld_safe]
|
|
|
open_files_limit = 65536
|
|
|
[mysqld]
|
|
|
#-----------------
|
# System settings.
|
#-----------------
|
user = mysql
|
pid-file = /var/lib/mysql/mysqld.pid
|
socket = /var/lib/mysql/mysql.sock
|
datadir = /var/lib/mysql
|
port = 3306
|
basedir = /usr
|
tmpdir = /tmp
|
slave_load_tmpdir = /tmp
|
|
|
character_set_server = utf8
|
collation_server = utf8_general_ci
|
|
|
max_error_count = 65535
|
|
|
default_storage_engine = InnoDB
|
sql_mode = NO_ENGINE_SUBSTITUTION
|
|
|
#---------------------------------
|
# Connections
|
#--------------------------------
|
|
|
max_connections = 600
|
|
|
thread_cache_size = 600
|
skip_name_resolve
|
|
|
#---------------------------------
|
# Performance and cache settings.
|
#--------------------------------
|
sort_buffer_size = 8M
|
bulk_insert_buffer_size = 16M
|
max_allowed_packet = 64M
|
|
|
wait_timeout = 600
|
open-files-limit = 40000
|
|
|
table_cache = 3000
|
table_definition_cache = 6000
|
|
|
tmp_table_size = 32M
|
max_heap_table_size = 32M
|
|
|
query_cache_limit = 128K
|
query_cache_size = 64M
|
query_cache_strip_comments=ON
|
|
|
#-----------------
|
# Query Planner
|
#-----------------
|
|
|
use_stat_tables = complementary
|
histogram_size = 255
|
join_cache_level = 8
|
optimizer_use_condition_selectivity =4
|
optimizer_switch = mrr=on,mrr_sort_keys=on,optimize_join_buffer_size=on
|
|
|
#-----------------
|
# MyISAM settings.
|
#-----------------
|
myisam_sort_buffer_size = 512M
|
myisam_recover = QUICK,BACKUP
|
key_buffer_size = 128M
|
concurrent_insert = 2
|
read_buffer_size = 8M
|
read_rnd_buffer_size = 1M
|
|
|
#-----------------
|
# InnoDB settings.
|
#-----------------
|
innodb_data_file_path = ibdata1:100M:autoextend
|
innodb_file_format = Barracuda
|
|
|
innodb_log_files_in_group = 8
|
innodb_log_file_size = 64M
|
innodb_log_buffer_size = 16M
|
innodb_buffer_pool_instances = 1
|
innodb_buffer_pool_size = 12G
|
innodb_max_dirty_pages_pct = 70
|
innodb_adaptive_flushing = 1
|
innodb-buffer-pool-dump-at-shutdown = 1
|
innodb-buffer-pool-load-at-startup = 1
|
innodb_io_capacity = 2000
|
innodb_read_io_threads = 8
|
innodb_write_io_threads = 8
|
innodb_flush_log_at_trx_commit = 1
|
innodb_flush_method = O_DIRECT
|
innodb_use_native_aio = 0
|
innodb_file_per_table = 1
|
innodb_open_files = 5000
|
|
|
innodb_stats_traditional = false
|
|
|
#-------------------
|
# Logging settings.
|
#-------------------
|
log-error = /var/log/mysql/error.log
|
log_warnings = 2
|
|
|
slow_query_log_file = /var/log/mysql/slow.log
|
slow_query_log = 1
|
long_query_time = 1
|
min_examined_row_limit = 10000
|
log_slow_verbosity = query_plan,innodb,explain
|
log_queries-not_using_indexes
|
log_slow_admin_statements
|
log_slow_slave_statements
|
|
|
#-------------
|
# Binary Log
|
#-------------
|
|
|
log_bin = /var/lib/mysql/mysql-bin
|
sync_binlog = 1
|
expire_logs_days = 3
|
max_binlog_size = 100M
|
binlog_format = ROW
|
|
|
binlog_checksum = CRC32
|
master_verify_checksum = 1
|
|
|
binlog_annotate_row_events = ON
|
replicate_annotate_row_events = ON
|
|
|
|
|
#-------------
|
# Replication Client
|
#-------------
|
|
|
skip-slave-start
|
log-slave-updates
|
slave-parallel-threads = 20
|
slave_transaction_retries = 20
|
slave-skip-errors = all
|
|
|
server-id=1011
|
|
|
#---------------
|
# Galera Options
|
#---------------
|
|
|
[galera]
|
wsrep_cluster_name = beta
|
wsrep_provider=/usr/lib64/galera/libgalera_smm.so
|
wsrep_cluster_address = gcomm://10.131.27.5:4567,10.131.27.69:4567?pc.wait_prim=no
|
#,10.131.27.6:4567,10.131.27.70:4567,10.131.27.7:4567,10.131.27.71:4567?pc.wait_prim=no
|
#wsrep_sst_method = rsync
|
wsrep_sst_method = xtrabackup-v2
|
wsrep_sst_auth = root:XXXX
|
wsrep_slave_threads = 64
|
wsrep_provider_options='gcache.size=25G;repl.commit_order=1;cert.log_conflicts=1;gcs.fc_limit=1024;repl.key_format=FLAT16A'
|
|
|
wsrep_retry_autocommit = 4
|
|
|
innodb_autoinc_lock_mode=2
|
innodb_locks_unsafe_for_binlog=1
|
Are you using parallel slave or any other non-default replication related options?
Could you please provide the cnf file from the slave?
As pointed out by MG a master with mixed replication may record a binlog as statement however when hitting a binlog_format=ROW its always recorded in the binlog on the slave as a row based event. It seems splitting row based binlog events over multiple files isn't implemented hence getting a larger binlog than the max_binlog_size. It seems is parallel slave operations where in effect multiple versions of these could occur in the same group commit further increasing the size.
| max_binlog_size | 104857600 || max_relay_log_size | 104857600 |# ls -la mysql-bin.* | more-rw-rw---- 1 mysql mysql 104866493 Sep 25 10:42 mysql-bin.000760-rw-rw---- 1 mysql mysql 104968119 Sep 25 10:43 mysql-bin.000761-rw-rw---- 1 mysql mysql 130866348 Sep 25 10:44 mysql-bin.000762-rw-rw---- 1 mysql mysql 104918131 Sep 25 10:46 mysql-bin.000763-rw-rw---- 1 mysql mysql 104858385 Sep 25 10:47 mysql-bin.000764-rw-rw---- 1 mysql mysql 104874296 Sep 25 10:48 mysql-bin.000765mysqlbinlog -v mysql-bin.000762 | grep '^#[^#]' | tail -n 4000#150914 21:00:29 server id 8 end_log_pos 101043363 CRC32 0xd9af389d Table_map: `video_ugc`.`user_progress_ugc` mapped to number 79#150914 21:00:29 server id 8 end_log_pos 101043559 CRC32 0x082395f7 Update_rows: table id 79 flags: STMT_END_F# at 101043559#150914 21:00:29 server id 8 end_log_pos 101043590 CRC32 0x8ea98410 Xid = 37532706# at 101043590#150914 21:00:13 server id 8 end_log_pos 101043634 CRC32 0x25c1cb0f GTID 0-8-1533469209 cid=69553706# at 101043634# at 101043706# at 101151443# at 101699590# at 101802058# at 102299625# at 102402093# at 102899663# at 103007400# at 103555555# at 103658023# at 104155582# at 104258050# at 104755621...# at 110476694# at 110477879# at 110581102# at 110600083# at 110617273# at 110624777# at 110641967# at 110649471# at 110684588# at 110921252# at 111018052# at 111457692# at 111555179# at 111993751...# at 115696789# at 115793824# at 116241642# at 116362609# at 116537696# at 116541043# at 116542228# at 116639263..# at 130307157# at 130405243#150914 21:00:13 server id 8 end_log_pos 101043706 CRC32 0x9b2f63b8 Table_map: `drupal_home_prod`.`cache_form` mapped to number 545#150914 21:00:13 server id 8 end_log_pos 101151443 CRC32 0x2d7f5607 Delete_rows: table id 545#150914 21:00:13 server id 8 end_log_pos 101699590 CRC32 0x78322403 Delete_rows: table id 545...#150914 21:00:13 server id 8 end_log_pos 130405243 CRC32 0x1f5b010a Delete_rows: table id 545#150914 21:00:13 server id 8 end_log_pos 130865968 CRC32 0xdaf57add Delete_rows: table id 545 flags: STMT_END_F# at 130865968#150914 21:00:13 server id 8 end_log_pos 130865999 CRC32 0x624f85d7 Xid = 37532708# at 130865999#150914 21:00:28 server id 8 end_log_pos 130866043 CRC32 0x1ec9a4fd GTID 0-8-1533469210 cid=69553706# at 130866043# at 130866124#150914 21:00:28 server id 8 end_log_pos 130866124 CRC32 0xd3fc4aaa Table_map: `singlesignon`.`device_sessions` mapped to number 80#150914 21:00:28 server id 8 end_log_pos 130866270 CRC32 0x6ee8413d Write_rows: table id 80 flags: STMT_END_F# at 130866270#150914 21:00:28 server id 8 end_log_pos 130866301 CRC32 0xf53bf2cd Xid = 37532698# at 130866301#150914 21:00:13 server id 1011 end_log_pos 130866348 CRC32 0xcaa1803e Rotate to mysql-bin.000763 pos: 4# End of log file