Mon Oct 29 13:55:18 2018 - [warning] Got error on MySQL
select
ping
: 2006 (MySQL server has gone away)
Mon Oct 29 13:55:18 2018 - [info] Executing secondary network check script:
/usr/local/bin/masterha_secondary_check
-s 192.168.8.58 -s 192.168.8.59 --user=root --master_host=192.168.8.57 --master_ip=192.168.8.57 --master_port=3306 --master_user=root --master_password=mysql --ping_type=SELECT
Mon Oct 29 13:55:18 2018 - [info] Executing SSH check script:
exit
Mon Oct 29 13:55:18 2018 - [info] HealthCheck: SSH to 192.168.8.57 is reachable.
Monitoring server 192.168.8.58 is reachable, Master is not reachable from 192.168.8.58. OK.
Mon Oct 29 13:55:19 2018 - [warning] Got error on MySQL connect: 2003 (Can
't connect to MySQL server on '
192.168.8.57' (111))
Mon Oct 29 13:55:19 2018 - [warning] Connection failed 2
time
(s)..
Monitoring server 192.168.8.59 is reachable, Master is not reachable from 192.168.8.59. OK.
Mon Oct 29 13:55:19 2018 - [info] Master is not reachable from all other monitoring servers. Failover should start.
Mon Oct 29 13:55:20 2018 - [warning] Got error on MySQL connect: 2003 (Can
't connect to MySQL server on '
192.168.8.57' (111))
Mon Oct 29 13:55:20 2018 - [warning] Connection failed 3
time
(s)..
Mon Oct 29 13:55:21 2018 - [warning] Got error on MySQL connect: 2003 (Can
't connect to MySQL server on '
192.168.8.57' (111))
Mon Oct 29 13:55:21 2018 - [warning] Connection failed 4
time
(s)..
Mon Oct 29 13:55:21 2018 - [warning] Master is not reachable from health checker!
Mon Oct 29 13:55:21 2018 - [warning] Master 192.168.8.57(192.168.8.57:3306) is not reachable!
Mon Oct 29 13:55:21 2018 - [warning] SSH is reachable.
Mon Oct 29 13:55:21 2018 - [info] Connecting to a master server failed. Reading configuration
file
/etc/masterha_default
.cnf and
/etc/masterha/app1
.cnf again, and trying to connect to all servers to check server status..
Mon Oct 29 13:55:21 2018 - [warning] Global configuration
file
/etc/masterha_default
.cnf not found. Skipping.
Mon Oct 29 13:55:21 2018 - [info] Reading application default configuration from
/etc/masterha/app1
.cnf..
Mon Oct 29 13:55:21 2018 - [info] Reading server configuration from
/etc/masterha/app1
.cnf..
Mon Oct 29 13:55:22 2018 - [info] GTID failover mode = 1
Mon Oct 29 13:55:22 2018 - [info] Dead Servers:
Mon Oct 29 13:55:22 2018 - [info] 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:22 2018 - [info] Alive Servers:
Mon Oct 29 13:55:22 2018 - [info] 192.168.8.58(192.168.8.58:3306)
Mon Oct 29 13:55:22 2018 - [info] 192.168.8.59(192.168.8.59:3306)
Mon Oct 29 13:55:22 2018 - [info] Alive Slaves:
Mon Oct 29 13:55:22 2018 - [info] 192.168.8.58(192.168.8.58:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:22 2018 - [info] GTID ON
Mon Oct 29 13:55:22 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:22 2018 - [info] Primary candidate
for
the new Master (candidate_master is
set
)
Mon Oct 29 13:55:22 2018 - [info] 192.168.8.59(192.168.8.59:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:22 2018 - [info] GTID ON
Mon Oct 29 13:55:22 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:22 2018 - [info] Checking slave configurations..
Mon Oct 29 13:55:22 2018 - [info] read_only=1 is not
set
on slave 192.168.8.58(192.168.8.58:3306).
Mon Oct 29 13:55:22 2018 - [info] read_only=1 is not
set
on slave 192.168.8.59(192.168.8.59:3306).
Mon Oct 29 13:55:22 2018 - [info] Checking replication filtering settings..
Mon Oct 29 13:55:22 2018 - [info] Replication filtering check ok.
Mon Oct 29 13:55:22 2018 - [info] Master is down!
Mon Oct 29 13:55:22 2018 - [info] Terminating monitoring script.
Mon Oct 29 13:55:22 2018 - [info] Got
exit
code 20 (Master dead).
Mon Oct 29 13:55:22 2018 - [info] MHA::MasterFailover version 0.58.
Mon Oct 29 13:55:22 2018 - [info] Starting master failover.
Mon Oct 29 13:55:22 2018 - [info]
Mon Oct 29 13:55:22 2018 - [info] * Phase 1: Configuration Check Phase..
Mon Oct 29 13:55:22 2018 - [info]
Mon Oct 29 13:55:23 2018 - [info] GTID failover mode = 1
Mon Oct 29 13:55:23 2018 - [info] Dead Servers:
Mon Oct 29 13:55:23 2018 - [info] 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:23 2018 - [info] Checking master reachability via MySQL(double check)...
Mon Oct 29 13:55:23 2018 - [info] ok.
Mon Oct 29 13:55:23 2018 - [info] Alive Servers:
Mon Oct 29 13:55:23 2018 - [info] 192.168.8.58(192.168.8.58:3306)
Mon Oct 29 13:55:23 2018 - [info] 192.168.8.59(192.168.8.59:3306)
Mon Oct 29 13:55:23 2018 - [info] Alive Slaves:
Mon Oct 29 13:55:23 2018 - [info] 192.168.8.58(192.168.8.58:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:23 2018 - [info] GTID ON
Mon Oct 29 13:55:23 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:23 2018 - [info] Primary candidate
for
the new Master (candidate_master is
set
)
Mon Oct 29 13:55:23 2018 - [info] 192.168.8.59(192.168.8.59:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:23 2018 - [info] GTID ON
Mon Oct 29 13:55:23 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:23 2018 - [info] Starting GTID based failover.
Mon Oct 29 13:55:23 2018 - [info]
Mon Oct 29 13:55:23 2018 - [info] ** Phase 1: Configuration Check Phase completed.
Mon Oct 29 13:55:23 2018 - [info]
Mon Oct 29 13:55:23 2018 - [info] * Phase 2: Dead Master Shutdown Phase..
Mon Oct 29 13:55:23 2018 - [info]
Mon Oct 29 13:55:23 2018 - [info] Forcing
shutdown
so that applications never connect to the current master..
Mon Oct 29 13:55:23 2018 - [info] Executing master IP deactivation script:
Mon Oct 29 13:55:23 2018 - [info]
/usr/local/bin/master_ip_failover
--orig_master_host=192.168.8.57 --orig_master_ip=192.168.8.57 --orig_master_port=3306 --
command
=stopssh --ssh_user=root
Mon Oct 29 13:55:24 2018 - [info]
done
.
Mon Oct 29 13:55:24 2018 - [warning] shutdown_script is not
set
. Skipping explicit shutting down of the dead master.
Mon Oct 29 13:55:24 2018 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] * Phase 3: Master Recovery Phase..
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] The latest binary log
file
/position
on all slaves is mysql-bin.000020:375
Mon Oct 29 13:55:24 2018 - [info] Retrieved Gtid Set: a92f70a4-d5ea-11e8-af28-080027c0450d:11-13
Mon Oct 29 13:55:24 2018 - [info] Latest slaves (Slaves that received relay log files to the latest):
Mon Oct 29 13:55:24 2018 - [info] 192.168.8.58(192.168.8.58:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:24 2018 - [info] GTID ON
Mon Oct 29 13:55:24 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:24 2018 - [info] Primary candidate
for
the new Master (candidate_master is
set
)
Mon Oct 29 13:55:24 2018 - [info] 192.168.8.59(192.168.8.59:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:24 2018 - [info] GTID ON
Mon Oct 29 13:55:24 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:24 2018 - [info] The oldest binary log
file
/position
on all slaves is mysql-bin.000020:375
Mon Oct 29 13:55:24 2018 - [info] Retrieved Gtid Set: a92f70a4-d5ea-11e8-af28-080027c0450d:11-13
Mon Oct 29 13:55:24 2018 - [info] Oldest slaves:
Mon Oct 29 13:55:24 2018 - [info] 192.168.8.58(192.168.8.58:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:24 2018 - [info] GTID ON
Mon Oct 29 13:55:24 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:24 2018 - [info] Primary candidate
for
the new Master (candidate_master is
set
)
Mon Oct 29 13:55:24 2018 - [info] 192.168.8.59(192.168.8.59:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:24 2018 - [info] GTID ON
Mon Oct 29 13:55:24 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] * Phase 3.3: Determining New Master Phase..
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] Searching new master from slaves..
Mon Oct 29 13:55:24 2018 - [info] Candidate masters from the configuration
file
:
Mon Oct 29 13:55:24 2018 - [info] 192.168.8.58(192.168.8.58:3306) Version=5.7.23-log (oldest major version between slaves) log-bin:enabled
Mon Oct 29 13:55:24 2018 - [info] GTID ON
Mon Oct 29 13:55:24 2018 - [info] Replicating from 192.168.8.57(192.168.8.57:3306)
Mon Oct 29 13:55:24 2018 - [info] Primary candidate
for
the new Master (candidate_master is
set
)
Mon Oct 29 13:55:24 2018 - [info] Non-candidate masters:
Mon Oct 29 13:55:24 2018 - [info] Searching from candidate_master slaves
which
have received the latest relay log events..
Mon Oct 29 13:55:24 2018 - [info] New master is 192.168.8.58(192.168.8.58:3306)
Mon Oct 29 13:55:24 2018 - [info] Starting master failover..
Mon Oct 29 13:55:24 2018 - [info]
From:
192.168.8.57(192.168.8.57:3306) (current master)
+--192.168.8.58(192.168.8.58:3306)
+--192.168.8.59(192.168.8.59:3306)
To:
192.168.8.58(192.168.8.58:3306) (new master)
+--192.168.8.59(192.168.8.59:3306)
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] * Phase 3.3: New Master Recovery Phase..
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] Waiting all logs to be applied..
Mon Oct 29 13:55:24 2018 - [info]
done
.
Mon Oct 29 13:55:24 2018 - [info] Getting new master's binlog name and position..
Mon Oct 29 13:55:24 2018 - [info] mysql-bin.000021:415
Mon Oct 29 13:55:24 2018 - [info] All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST=
'192.168.8.58'
, MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER=
'repl'
, MASTER_PASSWORD=
'xxx'
;
Mon Oct 29 13:55:24 2018 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: mysql-bin.000021, 415, a92f70a4-d5ea-11e8-af28-080027c0450d:1-13,
a92f70a4-d5ea-11e8-af28-080027c0450f:1-7
Mon Oct 29 13:55:24 2018 - [info] Executing master IP activate script:
Mon Oct 29 13:55:24 2018 - [info]
/usr/local/bin/master_ip_failover
--
command
=start --ssh_user=root --orig_master_host=192.168.8.57 --orig_master_ip=192.168.8.57 --orig_master_port=3306 --new_master_host=192.168.8.58 --new_master_ip=192.168.8.58 --new_master_port=3306 --new_master_user=
'root'
--new_master_password=xxx
Undefined subroutine &main::FIXME_xxx_create_user called at
/usr/local/bin/master_ip_failover
line 94.
Set read_only=0 on the new master.
Creating app user on the new master..
Mon Oct 29 13:55:24 2018 - [error][
/usr/lib/perl5/vendor_perl/MHA/MasterFailover
.pm, ln1612] Failed to activate master IP address
for
192.168.8.58(192.168.8.58:3306) with
return
code 10:0
Mon Oct 29 13:55:24 2018 - [warning] Proceeding.
Mon Oct 29 13:55:24 2018 - [info] ** Finished master recovery successfully.
Mon Oct 29 13:55:24 2018 - [info] * Phase 3: Master Recovery Phase completed.
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] * Phase 4: Slaves Recovery Phase..
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] * Phase 4.1: Starting Slaves
in
parallel..
Mon Oct 29 13:55:24 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] -- Slave recovery on host 192.168.8.59(192.168.8.59:3306) started, pid: 7627. Check tmp log
/var/log/masterha/app1/192
.168.8.59_3306_20181029135522.log
if
it takes
time
..
Mon Oct 29 13:55:25 2018 - [info]
Mon Oct 29 13:55:25 2018 - [info] Log messages from 192.168.8.59 ...
Mon Oct 29 13:55:25 2018 - [info]
Mon Oct 29 13:55:24 2018 - [info] Resetting slave 192.168.8.59(192.168.8.59:3306) and starting replication from the new master 192.168.8.58(192.168.8.58:3306)..
Mon Oct 29 13:55:24 2018 - [info] Executed CHANGE MASTER.
Mon Oct 29 13:55:24 2018 - [info] Slave started.
Mon Oct 29 13:55:24 2018 - [info] gtid_wait(a92f70a4-d5ea-11e8-af28-080027c0450d:1-13,
a92f70a4-d5ea-11e8-af28-080027c0450f:1-7) completed on 192.168.8.59(192.168.8.59:3306). Executed 0 events.
Mon Oct 29 13:55:25 2018 - [info] End of log messages from 192.168.8.59.
Mon Oct 29 13:55:25 2018 - [info] -- Slave on host 192.168.8.59(192.168.8.59:3306) started.
Mon Oct 29 13:55:25 2018 - [info] All new slave servers recovered successfully.
Mon Oct 29 13:55:25 2018 - [info]
Mon Oct 29 13:55:25 2018 - [info] * Phase 5: New master cleanup phase..
Mon Oct 29 13:55:25 2018 - [info]
Mon Oct 29 13:55:25 2018 - [info] Resetting slave info on the new master..
Mon Oct 29 13:55:25 2018 - [info] 192.168.8.58: Resetting slave info succeeded.
Mon Oct 29 13:55:25 2018 - [info] Master failover to 192.168.8.58(192.168.8.58:3306) completed successfully.
Mon Oct 29 13:55:25 2018 - [info] Deleted server1 entry from
/etc/masterha/app1
.cnf .
Mon Oct 29 13:55:25 2018 - [info]
----- Failover Report -----
app1: MySQL Master failover 192.168.8.57(192.168.8.57:3306) to 192.168.8.58(192.168.8.58:3306) succeeded
Master 192.168.8.57(192.168.8.57:3306) is down!
Check MHA Manager logs at manager:
/var/log/masterha/app1/manager
.log
for
details.
Started automated(non-interactive) failover.
Invalidated master IP address on 192.168.8.57(192.168.8.57:3306)
Selected 192.168.8.58(192.168.8.58:3306) as a new master.
192.168.8.58(192.168.8.58:3306): OK: Applying all logs succeeded.
Failed to activate master IP address
for
192.168.8.58(192.168.8.58:3306) with
return
code 10:0
192.168.8.59(192.168.8.59:3306): OK: Slave started, replicating from 192.168.8.58(192.168.8.58:3306)
192.168.8.58(192.168.8.58:3306): Resetting slave info succeeded.
Master failover to 192.168.8.58(192.168.8.58:3306) completed successfully.
Mon Oct 29 13:55:25 2018 - [info] Sending mail..
Unknown option: conf
|