Details
-
Type:
Bug
-
Status: Open
-
Priority:
Major
-
Resolution: Unresolved
-
Affects Version/s: 10.0.21-galera
-
Fix Version/s: None
-
Component/s: Replication
-
Labels:
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
Gliffy Diagrams
Attachments
Issue Links
- relates to
-
-
- Confirmed
-
Activity
- All
- Comments
- Work Log
- History
- Activity
- Transitions
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
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?
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).
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.
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.000765 mysqlbinlog -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
Daniel Black,
Are you using parallel slave or any other non-default replication related options?
Could you please provide the cnf file from the slave?