At Galera Cluster 5.7.17 GA, wsrep_sst_method=xtrabackup-v2 is not work.
435 views
Skip to first unread message
Wonseok Lee
Jan 31, 2017, 8:06:51 AM1/31/17
to codership
I installed Galera Cluster 5.7.17 on CentOS 6.8.
I have 2 node.
xtrabackup version is 2,4.5.(lastest version)
I set in my.cnf.
...
wsrep_sst_method = xtrabackup-v2
...
fristly, mysql started at node 1.
/etc/init.d/mysqld start --wsrep_cluster_address=gcomm://
mysqld of node 1, normally started.
and so, mysqld started node 2
/etc/init.d/mysqld start
but mysqld of node 2 dont't started.
the bellow errror occured.
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf --defaults-group=mysqld --no-version-check --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20170131 19:38:33.334)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20170131 19:38:33.344)
2017-01-31T10:38:33.361980Z 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.0.10' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '32505' '' : 1 (Operation not permitted)
2017-01-31T10:38:33.362033Z 0 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2017-01-31T10:38:33.362097Z 0 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2017-01-31T10:38:33.362126Z 0 [ERROR] Aborting
Help me about this bug.
cf)
if wsrep_sst_method = xtrabackup set in my.cnf, node 2 normally started.
Philip Stoev
Jan 31, 2017, 8:08:55 AM1/31/17
to Wonseok Lee, codersh...@googlegroups.com
Hello,
The error log on the donor node may contain more information about the
actual cause of the error, along with the innobackup* logs on both nodes.
Philip Stoev
-----Original Message-----
From: Wonseok Lee
Sent: Tuesday, January 31, 2017 14:53
To: codership
Subject: [codership-team] At Galera Cluster 5.7.17 GA,
wsrep_sst_method=xtrabackup-v2 is not work.
I installed Galera Cluster 5.7.17 on CentOS 6.8.
I have 2 node.
xtrabackup version is 2,4.5.(lastest version)
I set in my.cnf.
...
wsrep_sst_method = xtrabackup-v2
...
fristly, mysql started at node 1.
/etc/init.d/mysqld start --wsrep_cluster_address=gcomm://
mysqld of node 1, normally started.
and so, mysqld started node 2
/etc/init.d/mysqld start
but mysqld of node 2 dont't started.
the bellow errror occured.
WSREP_SST: [INFO] Evaluating
You received this message because you are subscribed to the Google Groups
"codership" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to codership-tea...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
The error log on the donor node may contain more information about the
actual cause of the error, along with the innobackup* logs on both nodes.
Philip Stoev
-----Original Message-----
From: Wonseok Lee
Sent: Tuesday, January 31, 2017 14:53
To: codership
Subject: [codership-team] At Galera Cluster 5.7.17 GA,
wsrep_sst_method=xtrabackup-v2 is not work.
I installed Galera Cluster 5.7.17 on CentOS 6.8.
I have 2 node.
xtrabackup version is 2,4.5.(lastest version)
I set in my.cnf.
...
wsrep_sst_method = xtrabackup-v2
...
fristly, mysql started at node 1.
/etc/init.d/mysqld start --wsrep_cluster_address=gcomm://
mysqld of node 1, normally started.
and so, mysqld started node 2
/etc/init.d/mysqld start
but mysqld of node 2 dont't started.
the bellow errror occured.
WSREP_SST: [INFO] Evaluating
nnobackupex --defaults-file=/etc/my.cnf --defaults-group=mysqld --no-version-check
--move-back --force-non-empty-directories ${DATA}
&>${DATA}/innobackup.move.log (20170131 19:38:33.334)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20170131 19:38:33.344)
2017-01-31T10:38:33.361980Z 0 [ERROR] WSREP: Process completed with error:
wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.0.10' --datadir
'/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix
'' --parent '32505' '' : 1 (Operation not permitted)
2017-01-31T10:38:33.362033Z 0 [ERROR] WSREP: Failed to read uuid:seqno from
joiner script.
2017-01-31T10:38:33.362097Z 0 [ERROR] WSREP: SST failed: 1 (Operation not
permitted)
2017-01-31T10:38:33.362126Z 0 [ERROR] Aborting
Help me about this bug.
cf)
if wsrep_sst_method = xtrabackup set in my.cnf, node 2 normally started.
--
--move-back --force-non-empty-directories ${DATA}
&>${DATA}/innobackup.move.log (20170131 19:38:33.334)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20170131 19:38:33.344)
2017-01-31T10:38:33.361980Z 0 [ERROR] WSREP: Process completed with error:
wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.0.10' --datadir
'/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix
'' --parent '32505' '' : 1 (Operation not permitted)
2017-01-31T10:38:33.362033Z 0 [ERROR] WSREP: Failed to read uuid:seqno from
joiner script.
2017-01-31T10:38:33.362097Z 0 [ERROR] WSREP: SST failed: 1 (Operation not
permitted)
2017-01-31T10:38:33.362126Z 0 [ERROR] Aborting
Help me about this bug.
cf)
if wsrep_sst_method = xtrabackup set in my.cnf, node 2 normally started.
You received this message because you are subscribed to the Google Groups
"codership" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to codership-tea...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Wonseok Lee
Jan 31, 2017, 9:53:38 AM1/31/17
to codership, ajaa...@gmail.com
Thanks Philip your reply.
at innobackup.backup.log, nothing err.
only mysqld.err of nod2 has error.
I doubt xtrabackup bug in mysql 5.7.
(for reference, if set 'wsrep_sst_method=xtrabackup-v2', not work,
if 'wsrep_sst_method=xtrabackup' old format, normall work.)
===============================
innobackup.backup.log of node1
==============================
170131 22:42:59 innobackupex: Starting the backup operation
IMPORTANT: Please check that the backup run completes successfully.
At the end of a successful backup run innobackupex
prints "completed OK!".
170131 22:42:59 Connecting to MySQL server host: localhost, user: xtrabackup, password: set, port: 3306, socket: /var/lib/mysql/mysql.sock
Using server version 5.7.17-log
innobackupex version 2.4.5 based on MySQL server 5.7.13 Linux (x86_64) (revision id: e41c0be)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 65535, set to 65535
xtrabackup: using the following InnoDB configuration:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 3
xtrabackup: innodb_log_file_size = 134217728
xtrabackup: using O_DIRECT
InnoDB: Number of pools: 1
170131 22:42:59 >> log scanned up to (7069332046)
xtrabackup: Generating a list of tablespaces
InnoDB: Allocated tablespace ID 10 for mysql/time_zone_transition, old maximum was 0
170131 22:42:59 [01] Streaming ./ibdata1
170131 22:43:00 >> log scanned up to (7069332046)
170131 22:43:01 >> log scanned up to (7069332046)
170131 22:43:02 >> log scanned up to (7069332046)
170131 22:43:02 [01] ...done
170131 22:43:03 >> log scanned up to (7069332046)
170131 22:43:03 [01] Streaming ./mysql/time_zone_transition.ibd
170131 22:43:03 [01] ...done
..........
(omission)
..........
170131 22:45:05 [01] Streaming ./test/sbtest1.frm to <STDOUT>
170131 22:45:05 [01] ...done
170131 22:45:05 [01] Streaming ./test/db.opt to <STDOUT>
170131 22:45:05 [01] ...done
170131 22:45:05 Finished backing up non-InnoDB tables and files
170131 22:45:05 [00] Streaming xtrabackup_galera_info
170131 22:45:05 [00] ...done
170131 22:45:05 [00] Streaming xtrabackup_binlog_info
170131 22:45:05 [00] ...done
170131 22:45:05 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
xtrabackup: The latest check point (for incremental): '7069332037'
xtrabackup: Stopping log copying thread.
.170131 22:45:05 >> log scanned up to (7069332046)
170131 22:45:05 Executing UNLOCK TABLES
170131 22:45:05 All tables unlocked
170131 22:45:05 [00] Streaming ib_buffer_pool to <STDOUT>
170131 22:45:05 [00] ...done
170131 22:45:05 Backup created in directory '/tmp/tmp.aE3Fb5zJUa'
MySQL binlog position: filename 'mysql-bin.000006', position '173600154'
170131 22:45:05 [00] Streaming backup-my.cnf
170131 22:45:05 [00] ...done
170131 22:45:05 [00] Streaming xtrabackup_info
170131 22:45:05 [00] ...done
xtrabackup: Transaction log of lsn (7069332037) to (7069332046) was copied.
170131 22:45:05 completed OK!
===============================
innobackup.backup.log of node2
==============================
this log is not exist.
===============================
mysqld.err of node1
==============================
2017-01-31T13:42:47.775294Z 0 [Note] WSREP: (48b10af1, 'tcp://0.0.0.0:4567') connection established to 26d4156b tcp://192.168.1.11:4567
2017-01-31T13:42:47.775739Z 0 [Note] WSREP: (48b10af1, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2017-01-31T13:42:48.275157Z 0 [Note] WSREP: declaring 26d4156b at tcp://192.168.1.11:4567 stable
2017-01-31T13:42:48.275667Z 0 [Note] WSREP: Node 48b10af1 state prim
2017-01-31T13:42:48.276169Z 0 [Note] WSREP: view(view_id(PRIM,26d4156b,8) memb {
26d4156b,0
48b10af1,0
} joined {
} left {
} partitioned {
})
2017-01-31T13:42:48.276203Z 0 [Note] WSREP: save pc into disk
2017-01-31T13:42:48.276442Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2017-01-31T13:42:48.276487Z 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2017-01-31T13:42:48.775613Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 276d073d-e7bb-11e6-b474-d31e3d66d72f
2017-01-31T13:42:48.775800Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 276d073d-e7bb-11e6-b474-d31e3d66d72f from 0 (node2)
2017-01-31T13:42:48.776100Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 276d073d-e7bb-11e6-b474-d31e3d66d72f from 1 (node1)
2017-01-31T13:42:48.776135Z 0 [Note] WSREP: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 7,
members = 1/2 (joined/total),
act_id = 707489,
last_appl. = 707403,
protocols = 0/7/3 (gcs/repl/appl),
group UUID = 65e1414f-e786-11e6-9e37-4b92593a4edd
2017-01-31T13:42:48.776164Z 0 [Note] WSREP: Flow-control interval: [23, 23]
2017-01-31T13:42:48.776297Z 2 [Note] WSREP: New cluster view: global state: 65e1414f-e786-11e6-9e37-4b92593a4edd:707489, view# 8: Primary, number of nodes: 2, my index: 1, protocol version 3
2017-01-31T13:42:48.776338Z 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-01-31T13:42:48.776364Z 2 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-01-31T13:42:48.776381Z 2 [Note] WSREP: Assign initial position for certification: 707489, protocol version: 3
2017-01-31T13:42:48.776481Z 0 [Note] WSREP: Service thread queue flushed.
2017-01-31T13:42:49.092274Z 0 [Note] WSREP: Member 0.0 (node2) requested state transfer from '*any*'. Selected 1.0 (node1)(SYNCED) as donor.
2017-01-31T13:42:49.092302Z 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 707489)
2017-01-31T13:42:49.092398Z 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-01-31T13:42:49.092540Z 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.1.11:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' '' --gtid '65e1414f-e786-11e6-9e37-4b92593a4edd:707489''
2017-01-31T13:42:49.092987Z 2 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (20170131 22:42:49.193)
WSREP_SST: [INFO] Using socat as streamer (20170131 22:42:49.194)
WSREP_SST: [INFO] Using /tmp/tmp.6Cloa8lfk7 as xtrabackup temporary directory (20170131 22:42:49.204)
WSREP_SST: [INFO] Using /tmp/tmp.aE3Fb5zJUa as innobackupex temporary directory (20170131 22:42:49.207)
WSREP_SST: [INFO] Streaming GTID file before SST (20170131 22:42:49.210)
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio TCP:192.168.1.11:4444; RC=( ${PIPESTATUS[@]} ) (20170131 22:42:49.212)
WSREP_SST: [INFO] Rate-limiting SST to 20M (20170131 22:42:49.218)
WSREP_SST: [INFO] Sleeping before data transfer for SST (20170131 22:42:49.220)
2017-01-31T13:42:50.878150Z 0 [Note] WSREP: (48b10af1, 'tcp://0.0.0.0:4567') turning message relay requesting off
WSREP_SST: [INFO] Streaming the backup to joiner at 192.168.1.11 4444 (20170131 22:42:59.222)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf --defaults-group=mysqld --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | pv -q -L $rlimit | socat -u stdio TCP:192.168.1.11:4444; RC=( ${PIPESTATUS[@]} ) (20170131 22:42:59.224)
2017-01-31T13:45:05.493571Z 111 [Note] WSREP: Provider paused at 65e1414f-e786-11e6-9e37-4b92593a4edd:707489 (203064)
2017-01-31T13:45:05.752792Z 111 [Note] WSREP: resuming provider at 203064
2017-01-31T13:45:05.752809Z 111 [Note] WSREP: Provider resumed.
2017-01-31T13:45:05.957428Z 0 [Note] WSREP: 1.0 (node1): State transfer to 0.0 (node2) complete.
2017-01-31T13:45:05.957472Z 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 707489)
2017-01-31T13:45:05.957817Z 0 [Note] WSREP: Member 1.0 (node1) synced with group.
2017-01-31T13:45:05.957840Z 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 707489)
2017-01-31T13:45:05.957876Z 6 [Note] WSREP: Synchronized with group, ready for connections
2017-01-31T13:45:05.957898Z 6 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
WSREP_SST: [INFO] Total time on donor: 0 seconds (20170131 22:45:05.958)
WSREP_SST: [INFO] Cleaning up temporary directories (20170131 22:45:05.960)
2017-01-31T13:45:14.383758Z 0 [Note] WSREP: forgetting 26d4156b (tcp://192.168.1.11:4567)
2017-01-31T13:45:14.383811Z 0 [Note] WSREP: Node 48b10af1 state prim
2017-01-31T13:45:14.383841Z 0 [Note] WSREP: view(view_id(PRIM,48b10af1,9) memb {
48b10af1,0
} joined {
} left {
} partitioned {
26d4156b,0
})
2017-01-31T13:45:14.383853Z 0 [Note] WSREP: save pc into disk
2017-01-31T13:45:14.384009Z 0 [Note] WSREP: forgetting 26d4156b (tcp://192.168.1.11:4567)
2017-01-31T13:45:14.384083Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2017-01-31T13:45:14.384653Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 7e376d78-e7bb-11e6-aa7c-834fa78fcefc
2017-01-31T13:45:14.384678Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 7e376d78-e7bb-11e6-aa7c-834fa78fcefc
2017-01-31T13:45:14.384689Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7e376d78-e7bb-11e6-aa7c-834fa78fcefc from 0 (node1)
2017-01-31T13:45:14.384702Z 0 [Note] WSREP: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 8,
members = 1/1 (joined/total),
act_id = 707489,
last_appl. = 707403,
protocols = 0/7/3 (gcs/repl/appl),
group UUID = 65e1414f-e786-11e6-9e37-4b92593a4edd
2017-01-31T13:45:14.384710Z 0 [Note] WSREP: Flow-control interval: [16, 16]
2017-01-31T13:45:14.384844Z 5 [Note] WSREP: New cluster view: global state: 65e1414f-e786-11e6-9e37-4b92593a4edd:707489, view# 9: Primary, number of nodes: 1, my index: 0, protocol version 3
2017-01-31T13:45:14.384882Z 5 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-01-31T13:45:14.384908Z 5 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-01-31T13:45:14.384928Z 5 [Note] WSREP: Assign initial position for certification: 707489, protocol version: 3
2017-01-31T13:45:14.385021Z 0 [Note] WSREP: Service thread queue flushed.
2017-01-31T13:45:18.294118Z 0 [Note] WSREP: (48b10af1, 'tcp://0.0.0.0:4567') connection established to 26d4156b tcp://192.168.1.11:4567
2017-01-31T13:45:18.294144Z 0 [Warning] WSREP: discarding established (time wait) 26d4156b (tcp://192.168.1.11:4567)
2017-01-31T13:45:19.398358Z 0 [Note] WSREP: cleaning up 26d4156b (tcp://192.168.1.11:4567)
===============================
mysqld.err of node2
==============================
2017-01-31T13:42:43.093908Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-01-31T13:42:43.093932Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2017-01-31T13:42:43.128530Z 0 [Warning] InnoDB: Using innodb_file_format is deprecated and the parameter may be removed in future releases. See http://dev.mysql.com/doc/refman/5.7/en/innodb-file-format.html
2017-01-31T13:42:43.128551Z 0 [Warning] InnoDB: Using innodb_file_format_max is deprecated and the parameter may be removed in future releases. See http://dev.mysql.com/doc/refman/5.7/en/innodb-file-format.html
2017-01-31T13:42:43.128563Z 0 [Warning] InnoDB: Using innodb_locks_unsafe_for_binlog is DEPRECATED. This option may be removed in future releases. Please use READ COMMITTED transaction isolation level instead; Please refer to http://dev.mysql.com/doc/refman/5.7/en/set-transaction.html
100
100
100
2017-01-31T13:42:44.440462Z 0 [Warning] InnoDB: New log files created, LSN=45790
2017-01-31T13:42:44.467516Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
2017-01-31T13:42:44.522910Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 24e46bbb-e7bb-11e6-b077-984be17a85e8.
2017-01-31T13:42:44.523668Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
2017-01-31T13:42:44.524814Z 1 [Note] A temporary password is generated for root@localhost: uGr:Lelx?03;
2017-01-31T13:42:44.681111Z 1 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2017-01-31T13:42:44.681143Z 1 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-01-31T13:42:44.681163Z 1 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-01-31T13:42:44.681175Z 1 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2017-01-31T13:42:44.681207Z 1 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-01-31T13:42:47.740166Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-01-31T13:42:47.740195Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2017-01-31T13:42:47.741635Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-log) starting as process 14684 ...
2017-01-31T13:42:47.744402Z 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-01-31T13:42:47.744417Z 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera-3/libgalera_smm.so'
2017-01-31T13:42:47.750075Z 0 [Note] WSREP: wsrep_load(): Galera 3.20(r7e383f7) by Codership Oy <in...@codership.com> loaded successfully.
2017-01-31T13:42:47.750103Z 0 [Note] WSREP: CRC-32C: using hardware acceleration.
2017-01-31T13:42:47.750345Z 0 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
2017-01-31T13:42:47.750392Z 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootsrap: 1
2017-01-31T13:42:47.759205Z 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.1.11; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.igno
2017-01-31T13:42:47.770057Z 0 [Note] WSREP: GCache history reset: old(00000000-0000-0000-0000-000000000000:0) -> new(00000000-0000-0000-0000-000000000000:-1)
2017-01-31T13:42:47.770692Z 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2017-01-31T13:42:47.770737Z 0 [Note] WSREP: wsrep_sst_grab()
2017-01-31T13:42:47.770755Z 0 [Note] WSREP: Start replication
2017-01-31T13:42:47.770778Z 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2017-01-31T13:42:47.770871Z 0 [Note] WSREP: protonet asio version 0
2017-01-31T13:42:47.771003Z 0 [Note] WSREP: Using CRC-32C for message checksums.
2017-01-31T13:42:47.771037Z 0 [Note] WSREP: backend: asio
2017-01-31T13:42:47.771103Z 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
2017-01-31T13:42:47.771233Z 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
2017-01-31T13:42:47.771246Z 0 [Note] WSREP: restore pc from disk failed
2017-01-31T13:42:47.771918Z 0 [Note] WSREP: GMCast version 0
2017-01-31T13:42:47.772152Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2017-01-31T13:42:47.772167Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2017-01-31T13:42:47.772690Z 0 [Note] WSREP: EVS version 0
2017-01-31T13:42:47.772791Z 0 [Note] WSREP: gcomm: connecting to group 'mysgcacluster', peer '192.168.1.10:'
2017-01-31T13:42:47.774680Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') connection established to 48b10af1 tcp://192.168.1.10:4567
2017-01-31T13:42:47.774786Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2017-01-31T13:42:48.274088Z 0 [Note] WSREP: declaring 48b10af1 at tcp://192.168.1.10:4567 stable
2017-01-31T13:42:48.274638Z 0 [Note] WSREP: Node 48b10af1 state prim
2017-01-31T13:42:48.275061Z 0 [Note] WSREP: view(view_id(PRIM,26d4156b,8) memb {
26d4156b,0
48b10af1,0
} joined {
} left {
} partitioned {
})
2017-01-31T13:42:48.275100Z 0 [Note] WSREP: save pc into disk
2017-01-31T13:42:48.773350Z 0 [Note] WSREP: gcomm: connected
2017-01-31T13:42:48.773391Z 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2017-01-31T13:42:48.773442Z 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2017-01-31T13:42:48.773457Z 0 [Note] WSREP: Opened channel 'mysgcacluster'
2017-01-31T13:42:48.773583Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2017-01-31T13:42:48.773625Z 0 [Note] WSREP: Waiting for SST to complete.
2017-01-31T13:42:48.774172Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 276d073d-e7bb-11e6-b474-d31e3d66d72f
2017-01-31T13:42:48.774546Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 276d073d-e7bb-11e6-b474-d31e3d66d72f
2017-01-31T13:42:48.774878Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 276d073d-e7bb-11e6-b474-d31e3d66d72f from 0 (node2)
2017-01-31T13:42:48.775346Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 276d073d-e7bb-11e6-b474-d31e3d66d72f from 1 (node1)
2017-01-31T13:42:48.775377Z 0 [Note] WSREP: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 7,
members = 1/2 (joined/total),
act_id = 707489,
last_appl. = -1,
protocols = 0/7/3 (gcs/repl/appl),
group UUID = 65e1414f-e786-11e6-9e37-4b92593a4edd
2017-01-31T13:42:48.775400Z 0 [Note] WSREP: Flow-control interval: [23, 23]
2017-01-31T13:42:48.775414Z 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 707489)
2017-01-31T13:42:48.775548Z 1 [Note] WSREP: State transfer required:
Group state: 65e1414f-e786-11e6-9e37-4b92593a4edd:707489
Local state: 00000000-0000-0000-0000-000000000000:-1
2017-01-31T13:42:48.775586Z 1 [Note] WSREP: New cluster view: global state: 65e1414f-e786-11e6-9e37-4b92593a4edd:707489, view# 8: Primary, number of nodes: 2, my index: 0, protocol version 3
2017-01-31T13:42:48.775596Z 1 [Warning] WSREP: Gap in state sequence. Need state transfer.
2017-01-31T13:42:48.775717Z 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.1.11' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '14684' '' '
WSREP_SST: [INFO] Streaming with xbstream (20170131 22:42:48.868)
WSREP_SST: [INFO] Using socat as streamer (20170131 22:42:48.870)
WSREP_SST: [INFO] Evaluating timeout -s9 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20170131 22:42:48.889)
2017-01-31T13:42:49.090479Z 1 [Note] WSREP: Prepared SST request: xtrabackup-v2|192.168.1.11:4444/xtrabackup_sst//1
2017-01-31T13:42:49.090514Z 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-01-31T13:42:49.090545Z 1 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-01-31T13:42:49.090557Z 1 [Note] WSREP: Assign initial position for certification: 707489, protocol version: 3
2017-01-31T13:42:49.090600Z 0 [Note] WSREP: Service thread queue flushed.
2017-01-31T13:42:49.090714Z 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (65e1414f-e786-11e6-9e37-4b92593a4edd): 1 (Operation not permitted)
at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
2017-01-31T13:42:49.091366Z 0 [Note] WSREP: Member 0.0 (node2) requested state transfer from '*any*'. Selected 1.0 (node1)(SYNCED) as donor.
2017-01-31T13:42:49.091410Z 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 707489)
2017-01-31T13:42:49.091480Z 1 [Note] WSREP: Requesting state transfer: success, donor: 1
2017-01-31T13:42:49.091519Z 1 [Note] WSREP: GCache history reset: old(00000000-0000-0000-0000-000000000000:0) -> new(65e1414f-e786-11e6-9e37-4b92593a4edd:707489)
WSREP_SST: [INFO] Proceeding with SST (20170131 22:42:49.234)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20170131 22:42:49.235)
WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20170131 22:42:49.236)
removed `/var/lib/mysql/ib_logfile2'
removed `/var/lib/mysql/auto.cnf'
removed `/var/lib/mysql/mysql/server_cost.ibd'
removed `/var/lib/mysql/mysql/user.MYI'
..........
(omission)
..........
removed `/var/lib/mysql/performance_schema/events_stages_history_long.frm'
removed directory: `/var/lib/mysql/performance_schema'
removed `/var/lib/mysql/mysql-bin.000001'
removed `/var/lib/mysql/ib_logfile1'
WSREP_SST: [INFO] Waiting for SST streaming to complete! (20170131 22:42:49.312)
2017-01-31T13:42:51.273791Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') turning message relay requesting off
2017-01-31T13:45:05.956680Z 0 [Note] WSREP: 1.0 (node1): State transfer to 0.0 (node2) complete.
2017-01-31T13:45:05.957171Z 0 [Note] WSREP: Member 1.0 (node1) synced with group.
WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql//.sst (20170131 22:45:07.505)
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20170131 22:45:07.506)
rm: cannot remove `/var/lib/mysql//innobackup.prepare.log': No such file or directory
rm: cannot remove `/var/lib/mysql//innobackup.move.log': No such file or directory
WSREP_SST: [INFO] Moving the backup to /var/lib/mysql/ (20170131 22:45:11.351)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf --defaults-group=mysqld --no-version-check --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20170131 22:45:11.353)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20170131 22:45:11.363)
2017-01-31T13:45:11.381485Z 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.1.11' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '14684' '' : 1 (Operation not permitted)
2017-01-31T13:45:11.381542Z 0 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2017-01-31T13:45:11.381595Z 0 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2017-01-31T13:45:11.381628Z 0 [ERROR] Aborting
2017-01-31T13:45:11.381646Z 0 [Note] Giving 2 client threads a chance to die gracefully
2017-01-31T13:45:13.382004Z 0 [Note] WSREP: Closing send monitor...
2017-01-31T13:45:13.382032Z 0 [Note] WSREP: Closed send monitor.
2017-01-31T13:45:13.382059Z 2 [Note] WSREP: rollbacker thread exiting
2017-01-31T13:45:13.382064Z 0 [Note] WSREP: gcomm: terminating thread
2017-01-31T13:45:13.382137Z 0 [Note] WSREP: gcomm: joining thread
2017-01-31T13:45:13.382477Z 0 [Note] WSREP: gcomm: closing backend
2017-01-31T13:45:16.791887Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') connection to peer 48b10af1 with addr tcp://192.168.1.10:4567 timed out, no messages seen in PT3S
2017-01-31T13:45:16.791952Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://192.168.1.10:4567
2017-01-31T13:45:18.291883Z 0 [Note] WSREP: (26d4156b, 'tcp://0.0.0.0:4567') reconnecting to 48b10af1 (tcp://192.168.1.10:4567), attempt 0
2017-01-31T13:45:18.882577Z 0 [Note] WSREP: evs::proto(26d4156b, LEAVING, view_id(REG,26d4156b,8)) suspecting node: 48b10af1
2017-01-31T13:45:18.882594Z 0 [Note] WSREP: evs::proto(26d4156b, LEAVING, view_id(REG,26d4156b,8)) suspected node without join message, declaring inactive
2017-01-31T13:45:18.882621Z 0 [Note] WSREP: view(view_id(NON_PRIM,26d4156b,8) memb {
26d4156b,0
} joined {
} left {
} partitioned {
48b10af1,0
})
2017-01-31T13:45:18.882648Z 0 [Note] WSREP: view((empty))
2017-01-31T13:45:18.882743Z 0 [Note] WSREP: gcomm: closed
2017-01-31T13:45:18.882824Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2017-01-31T13:45:18.882874Z 0 [Note] WSREP: Flow-control interval: [16, 16]
2017-01-31T13:45:18.882891Z 0 [Note] WSREP: Received NON-PRIMARY.
2017-01-31T13:45:18.882901Z 0 [Note] WSREP: Shifting JOINER -> OPEN (TO: 707489)
2017-01-31T13:45:18.882921Z 0 [Note] WSREP: Received self-leave message.
2017-01-31T13:45:18.882937Z 0 [Note] WSREP: Flow-control interval: [0, 0]
2017-01-31T13:45:18.882947Z 0 [Note] WSREP: Received SELF-LEAVE. Closing connection.
2017-01-31T13:45:18.882956Z 0 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 707489)
2017-01-31T13:45:18.882971Z 0 [Note] WSREP: RECV thread exiting 0: Success
2017-01-31T13:45:18.882998Z 0 [Note] WSREP: recv_thread() joined.
2017-01-31T13:45:18.883008Z 0 [Note] WSREP: Closing replication queue.
2017-01-31T13:45:18.883013Z 0 [Note] WSREP: Closing slave action queue.
pure virtual method called
terminate called without an active exception
13:45:18 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=0
read_buffer_size=4194304
max_used_connections=0
max_threads=500
thread_count=1
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4102953 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0xf6d725]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x7d5d34]
/lib64/libpthread.so.0[0x3c4ba0f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3c4b6325e5]
/lib64/libc.so.6(abort+0x175)[0x3c4b633dc5]
/usr/lib64/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x12d)[0x3c4f6bea7d]
/usr/lib64/libstdc++.so.6[0x3c4f6bcbd6]
/usr/lib64/libstdc++.so.6[0x3c4f6bcc03]
/usr/lib64/libstdc++.so.6[0x3c4f6bd55f]
/usr/sbin/mysqld(_ZN18Global_THD_manager14do_for_all_thdEP11Do_THD_Impl+0x90)[0x7d4110]
/usr/sbin/mysqld(_Z25wsrep_wait_appliers_closeP3THD+0x75)[0x7c6905]
/usr/sbin/mysqld(unireg_abort+0x107)[0x7ca6d7]
/usr/sbin/mysqld(_Z18wsrep_init_startupb+0xb3)[0x7dfb23]
/usr/sbin/mysqld[0x7cbbfb]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x576)[0x7ced76]
/lib64/libc.so.6(__libc_start_main+0xfd)[0x3c4b61ed1d]
/usr/sbin/mysqld[0x7c3ee1]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Wonseok Lee
Jan 31, 2017, 10:17:57 AM1/31/17
to codership, ajaa...@gmail.com
On Tuesday, January 31, 2017 at 10:08:55 PM UTC+9, Philip Stoev wrote:
Thanks Philip your reply.
at innobackup.backup.log, nothing err.only mysqld.err of nod2 has error.I doubt xtrabackup bug in mysql 5.7.
(ㄹor reference, if set "wsrep_sst_method=xtrabackup-v2", not work,
Wonseok Lee
Jan 31, 2017, 10:17:58 AM1/31/17
to codership, ajaa...@gmail.com
Thanks Philip your reply.
at innobackup.backup.log, nothing err.
only mysqld.err of nod2 has error.
I doubt xtrabackup bug in mysql 5.7.
(for reference, if set 'wsrep_sst_method=xtrabackup-v2', not work,
On Tuesday, January 31, 2017 at 10:08:55 PM UTC+9, Philip Stoev wrote:
Wonseok Lee
Jan 31, 2017, 11:07:10 AM1/31/17
to codership, ajaa...@gmail.com
thanks, your confirm.
I noticed that innobackup.move.log exist in /var/lib/mysq/.sst
[root@node2 ~]# cd /var/lib/mysql/.sst
[root@node2 .sst]# cat innobackup.move.log
170131 22:45:11 innobackupex: Starting the move-back operation
IMPORTANT: Please check that the move-back run completes successfully.
At the end of a successful move-back run innobackupex
prints "completed OK!".
innobackupex version 2.4.5 based on MySQL server 5.7.13 Linux (x86_64) (revision id: e41c0be)
Error: datadir must be specified.
innbackupex is runned automation in processing of /etc/init.d/mysqld start
How can i sepcify this datadir?
On Tuesday, January 31, 2017 at 10:08:55 PM UTC+9, Philip Stoev wrote:
Wonseok Lee
Jan 31, 2017, 7:39:02 PM1/31/17
to codership, ajaa...@gmail.com
Thanks youre advice.
first, I sloved.
I missed set datadir in my.cnf.
After set datadir in my.cnf, the error is nothing.
datadir = /var/lib/mysql
Good job!
On Tuesday, January 31, 2017 at 10:08:55 PM UTC+9, Philip Stoev wrote:
Reply all
Reply to author
Forward
0 new messages