Coordinator failover is taking longer because VERIFY_SUSPECT runs twice ----------------------------------------------------------------------- Key: JGRP-2082 URL: https://issues.jboss.org/browse/JGRP-2082 Project: JGroups Issue Type: Bug Affects Versions: 3.6.3 Reporter: Osamu Nagano Assignee: Bela Ban Fix For: 3.6.10, 4.0 There are 4 machines (m03, ..., m06) and 7 nodes (n001, ..., n007) on each. To test the coordinator failover behaviour, nodes on m03 are all killed at the same time. These are suspected and verified in sequence at the first time (line 9 to 18, only m03_n007 is verified as dead and others are just queued), while these are verified as a whole at the second time (line 19 to 34). Since the coordinator is in the queued at the first time, view change is not triggered and causing a delay. - m03_n001 is the original coordinator. - m05_n001 is the next coordinator and the owner of the following log messages. {code} 8 12:04:10,997 TRACE [org.jgroups.protocols.FD_SOCK] (FD_SOCK acceptor,m05_n001/clustered) m05_n001/clustered: accepted connection from /172.20.66.36:29702 9 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n001/clustered] 10 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n002/clustered] 11 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n003/clustered] 12 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n004/clustered] 13 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n005/clustered] 14 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n006/clustered] 15 12:04:10,999 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n007/clustered] 16 12:04:10,999 DEBUG [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: suspecting [m03_n001/clustered, m03_n002/clustered, m03_n003/clustered, m03_n004/clustered, m03_n005/clustered, m03_n006/clustered, m03_n007/clustered] 17 12:04:11,000 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n007/clustered is dead 18 12:04:12,000 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n007/clustered is dead (passing up SUSPECT event) 19 12:04:16,000 TRACE [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: received SUSPECT message from m06_n007/clustered: suspects=[m03_n003/clustered, m03_n004/clustered, m03_n005/clustered, m03_n002/clustered, m03_n001/clustered, m03_n007/clustered, m03_n006/clustered] 20 12:04:16,000 DEBUG [org.jgroups.protocols.FD_SOCK] (INT-28,shared=udp) m05_n001/clustered: suspecting [m03_n001/clustered, m03_n002/clustered, m03_n003/clustered, m03_n004/clustered, m03_n005/clustered, m03_n006/clustered, m03_n007/clustered] 21 12:04:16,000 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n003/clustered is dead 22 12:04:16,000 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n004/clustered is dead 23 12:04:16,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n005/clustered is dead 24 12:04:16,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n002/clustered is dead 25 12:04:16,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n001/clustered is dead 26 12:04:16,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n007/clustered is dead 27 12:04:16,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (INT-28,shared=udp) verifying that m03_n006/clustered is dead 28 12:04:17,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n003/clustered is dead (passing up SUSPECT event) 29 12:04:17,001 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n004/clustered is dead (passing up SUSPECT event) 30 12:04:17,002 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n007/clustered is dead (passing up SUSPECT event) 31 12:04:17,002 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n001/clustered is dead (passing up SUSPECT event) 32 12:04:17,002 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n002/clustered is dead (passing up SUSPECT event) 33 12:04:17,003 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n005/clustered is dead (passing up SUSPECT event) 34 12:04:17,003 TRACE [org.jgroups.protocols.VERIFY_SUSPECT] (VERIFY_SUSPECT.TimerThread,m05_n001/clustered) m03_n006/clustered is dead (passing up SUSPECT event) {code}