[MDEV-15436] If log_bin and log_bin_index is different SST with rsync fails. - Jira

XML

Word

Printable

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.2.13, 10.1(EOL)
Fix Version/s: 10.1.36, 10.2.18, 10.3.11
Component/s: Galera SST
Labels:
- galera
- log_bin
- log_bin_index
- rsync
- sst
Environment:
Ubuntu 14.04 (n.a.)

Description

If the SST donor is configured with log_bin and log_bin_index differently the SST with rsync will fail.

Config of donor:

log_bin                        = /home/mysql/database/magal-102-b/binlog/laptop4_magal-102-b_binlog

log_bin_index                  = /home/mysql/database/magal-102-b/binlog/different.index

Config of joiner:

wsrep_sst_method               = rsync

Error Log of joiner:

2018-02-28 19:47:08 139733535151872 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (ac9c693b-0c24-11e8-bbd0-1e63d6801ac1): 1 (Operation not permitted)

         at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.

2018-02-28 19:47:08 139733229344512 [Note] WSREP: Member 1.0 (Node A) requested state transfer from '*any*'. Selected 0.0 (Node B)(SYNCED) as donor.

2018-02-28 19:47:08 139733229344512 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 0)

2018-02-28 19:47:08 139733535151872 [Note] WSREP: Requesting state transfer: success, donor: 0

2018-02-28 19:47:08 139733535151872 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> ac9c693b-0c24-11e8-bbd0-1e63d6801ac1:0

2018-02-28 19:47:08 139733229344512 [Warning] WSREP: 0.0 (Node B): State transfer to 1.0 (Node A) failed: -1 (Operation not permitted)

2018-02-28 19:47:08 139733229344512 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():737: Will never receive state. Need to abort.

2018-02-28 19:47:08 139733229344512 [Note] WSREP: gcomm: terminating thread

2018-02-28 19:47:08 139733229344512 [Note] WSREP: gcomm: joining thread

2018-02-28 19:47:08 139733229344512 [Note] WSREP: gcomm: closing backend

2018-02-28 19:47:10 139733229344512 [Note] WSREP: (c68162be, 'tcp://127.0.0.1:5690') turning message relay requesting off

2018-02-28 19:47:11 139733229344512 [Note] WSREP: (c68162be, 'tcp://127.0.0.1:5690') connection to peer 7b19fa32 with addr tcp://127.0.0.1:5691 timed out, no messages seen in PT3S

2018-02-28 19:47:11 139733229344512 [Note] WSREP: (c68162be, 'tcp://127.0.0.1:5690') turning message relay requesting on, nonlive peers: tcp://127.0.0.1:5691

2018-02-28 19:47:12 139733229344512 [Note] WSREP: (c68162be, 'tcp://127.0.0.1:5690') reconnecting to 7b19fa32 (tcp://127.0.0.1:5691), attempt 0

2018-02-28 19:47:13 139733229344512 [Note] WSREP: evs::proto(c68162be, LEAVING, view_id(REG,7b19fa32,4)) suspecting node: 7b19fa32

2018-02-28 19:47:13 139733229344512 [Note] WSREP: evs::proto(c68162be, LEAVING, view_id(REG,7b19fa32,4)) suspected node without join message, declaring inactive

2018-02-28 19:47:13 139733229344512 [Note] WSREP: view(view_id(NON_PRIM,7b19fa32,4) memb {

        c68162be,0

} joined {

} left {

} partitioned {

        7b19fa32,0

})

2018-02-28 19:47:13 139733229344512 [Note] WSREP: view((empty))

2018-02-28 19:47:13 139733229344512 [Note] WSREP: gcomm: closed

2018-02-28 19:47:13 139733229344512 [Note] WSREP: /home/mysql/product/mariadb-10.2/bin/mysqld: Terminated.

WSREP_SST: [ERROR] Parent mysqld process (PID:12826) terminated unexpectedly. (20180228 19:47:14.212)

WSREP_SST: [INFO] Joiner cleanup. rsync PID: 12882 (20180228 19:47:14.212)

WSREP_SST: [INFO] Joiner cleanup done. (20180228 19:47:14.720)

Error Log of donor:

2018-02-28 19:47:08 140650095822592 [Note] WSREP: Member 1.0 (Node A) requested state transfer from '*any*'. Selected 0.0 (Node B)(SYNCED) as donor.

2018-02-28 19:47:08 140650095822592 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 0)

2018-02-28 19:47:08 140650401990400 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.

2018-02-28 19:47:08 140648686540544 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'donor' --address '127.0.0.1:4444/rsync_sst' --socket '/var/run/mysqld/mysql-3334.sock' --datadir '/home/mysql/database/magal-102-b/data/'  --defaults-file '/home/mysql/database/magal-102-b/etc/my.cnf'   --binlog '/home/mysql/database/magal-102-b/binlog/laptop4_magal-102-b_binlog' --gtid 'ac9c693b-0c24-11e8-bbd0-1e63d6801ac1:0' --gtid-domain-id '42''

2018-02-28 19:47:08 140650401990400 [Note] WSREP: sst_donor_thread signaled with 0

2018-02-28 19:47:08 140648686540544 [Note] WSREP: Flushing tables for SST...

2018-02-28 19:47:08 140648686540544 [Note] WSREP: Provider paused at ac9c693b-0c24-11e8-bbd0-1e63d6801ac1:0 (7)

2018-02-28 19:47:08 140648686540544 [Note] WSREP: Tables flushed.

tail: cannot open 'laptop4_magal-102-b_binlog.index' for reading: No such file or directory

2018-02-28 19:47:08 140648686540544 [ERROR] WSREP: Failed to read from: wsrep_sst_rsync --role 'donor' --address '127.0.0.1:4444/rsync_sst' --socket '/var/run/mysqld/mysql-3334.sock' --datadir '/home/mysql/database/magal-102-b/data/'  --defaults-file '/home/mysql/database/magal-102-b/etc/my.cnf'   --binlog '/home/mysql/database/magal-102-b/binlog/laptop4_magal-102-b_binlog' --gtid 'ac9c693b-0c24-11e8-bbd0-1e63d6801ac1:0' --gtid-domain-id '42'

2018-02-28 19:47:08 140648686540544 [ERROR] WSREP: Process completed with error: wsrep_sst_rsync --role 'donor' --address '127.0.0.1:4444/rsync_sst' --socket '/var/run/mysqld/mysql-3334.sock' --datadir '/home/mysql/database/magal-102-b/data/'  --defaults-file '/home/mysql/database/magal-102-b/etc/my.cnf'   --binlog '/home/mysql/database/magal-102-b/binlog/laptop4_magal-102-b_binlog' --gtid 'ac9c693b-0c24-11e8-bbd0-1e63d6801ac1:0' --gtid-domain-id '42': 1 (Operation not permitted)

2018-02-28 19:47:08 140648686540544 [Note] WSREP: resuming provider at 7

2018-02-28 19:47:08 140648686540544 [Note] WSREP: Provider resumed.

2018-02-28 19:47:08 140648686540544 [ERROR] WSREP: Command did not run: wsrep_sst_rsync --role 'donor' --address '127.0.0.1:4444/rsync_sst' --socket '/var/run/mysqld/mysql-3334.sock' --datadir '/home/mysql/database/magal-102-b/data/'  --defaults-file '/home/mysql/database/magal-102-b/etc/my.cnf'   --binlog '/home/mysql/database/magal-102-b/binlog/laptop4_magal-102-b_binlog' --gtid 'ac9c693b-0c24-11e8-bbd0-1e63d6801ac1:0' --gtid-domain-id '42'

2018-02-28 19:47:08 140650095822592 [Warning] WSREP: 0.0 (Node B): State transfer to 1.0 (Node A) failed: -1 (Operation not permitted)

2018-02-28 19:47:08 140650095822592 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 0)

2018-02-28 19:47:09 140650095822592 [Note] WSREP: Member 0.0 (Node B) synced with group.

2018-02-28 19:47:09 140650104215296 [Note] WSREP: forgetting c68162be (tcp://127.0.0.1:5690)

2018-02-28 19:47:09 140650095822592 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 0)

the important part is this:

tail: cannot open 'laptop4_magal-102-b_binlog.index' for reading: No such file or directory

Instead of evaluating log_bin_index log_bin is used and '.index' was just added. Which is IMHO wrong.
We can reproduce this at will and have tested it at least twice.

Attachments

Issue Links

relates to

MDEV-8735 galera rsync sst - tar of binlog to file before transfer waste of IO and space

Closed

MDEV-15466 SST not working after upgrade from 10.2.11

Closed

MDEV-10754 wsrep_sst_rsync does not support innodb_data_home_dir

Closed

Activity

People

Assignee:: Jan Lindström (Inactive)

Reporter:: Oli Sennhauser

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2018-02-28 19:01

Updated:: 2018-09-05 15:12

Resolved:: 2018-09-05 15:12

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.