[Pacemaker] TOTEM Retransmit list in logs when a node gets up

Daniel Dehennin daniel.dehennin at baby-gnu.org
Fri Nov 14 04:34:33 EST 2014


Christine Caulfield <ccaulfie at redhat.com> writes:


[...]

> If its only happening at startup it could be the switch/router
> learning the ports for the nodes and building its routing
> tables. Switching to udpu will then get rid of the message if it's
> annoying

When I start the corosync process of the VM, nothing happen in logs
execpt the new membership, here are logs for two bare metal hosts
(nebula3 is DC):

#+begin_src
Nov 14 08:29:29 nebula1 corosync[4242]:   [TOTEM ] A new membership (192.168.231.70:80696) was formed. Members joined: 1084811119
Nov 14 08:29:29 nebula1 corosync[4242]:   [QUORUM] Members[5]: 1084811078 1084811079 1084811080 1084811118 1084811119
Nov 14 08:29:29 nebula1 pacemakerd[4251]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now member (was lost)
Nov 14 08:29:29 nebula1 crmd[4258]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now member (was lost)
Nov 14 08:29:29 nebula1 corosync[4242]:   [MAIN  ] Completed service synchronization, ready to provide service.
#+end_src

#+begin_src
Nov 14 08:29:29 nebula3 corosync[5345]:   [TOTEM ] A new membership (192.168.231.70:80696) was formed. Members joined: 1084811119
Nov 14 08:29:29 nebula3 corosync[5345]:   [QUORUM] Members[5]: 1084811078 1084811079 1084811080 1084811118 1084811119
Nov 14 08:29:29 nebula3 corosync[5345]:   [MAIN  ] Completed service synchronization, ready to provide service.
Nov 14 08:29:29 nebula3 crmd[5423]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now member (was lost)
Nov 14 08:29:29 nebula3 pacemakerd[5416]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now member (was lost)
#+end_src

I let the corosync process for some time and then start pacemaker, the
logs start when pacemaker starts:

#+begin_src
Nov 14 09:26:30 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 
Nov 14 09:26:30 nebula1 corosync[4242]: message repeated 8 times: [   [TOTEM ] Retransmit List: 24 ]
Nov 14 09:26:30 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 
Nov 14 09:26:46 nebula1 corosync[4242]: message repeated 101 times: [   [TOTEM ] Retransmit List: 24 25 26 ]
Nov 14 09:26:46 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 
Nov 14 09:26:46 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 
Nov 14 09:26:46 nebula1 corosync[4242]: message repeated 44 times: [   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b ]
Nov 14 09:26:46 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 
Nov 14 09:26:46 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 
Nov 14 09:26:47 nebula1 corosync[4242]: message repeated 35 times: [   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 ]
Nov 14 09:26:47 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 
Nov 14 09:26:47 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 
Nov 14 09:26:48 nebula1 corosync[4242]: message repeated 43 times: [   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c ]
Nov 14 09:26:48 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 
Nov 14 09:26:48 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 41 42 
Nov 14 09:27:08 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_NOT_DC -> S_ELECTION [ input=I_ELECTION cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:27:08 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:27:08 nebula1 corosync[4242]: message repeated 119 times: [   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 41 42 ]
Nov 14 09:27:08 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 41 42 44 45 46 
Nov 14 09:27:08 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 41 42 44 45 46 47 48 49 4a 4b 4c 4d 4e 
Nov 14 09:27:08 nebula1 corosync[4242]:   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 41 42 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f 
Nov 14 09:27:28 nebula1 crmd[4258]:  warning: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING
Nov 14 09:27:28 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:27:48 nebula1 crmd[4258]:  warning: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING
Nov 14 09:27:48 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:27:55 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:28:15 nebula1 crmd[4258]:  warning: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING
Nov 14 09:28:15 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:28:35 nebula1 crmd[4258]:  warning: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING
Nov 14 09:28:35 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
Nov 14 09:28:43 nebula1 corosync[4242]: message repeated 628 times: [   [TOTEM ] Retransmit List: 24 25 26 28 29 2a 2b 34 35 36 38 3a 3b 3c 3f 40 41 42 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f ]
#+end_src

#+begin_src
Nov 14 09:26:30 nebula3 crmd[5423]:   notice: run_graph: Transition 114 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-250.bz2): Complete
Nov 14 09:26:30 nebula3 crmd[5423]:   notice: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
Nov 14 09:26:30 nebula3 pengine[5422]:   notice: process_pe_message: Calculated Transition 114: /var/lib/pacemaker/pengine/pe-input-250.bz2
Nov 14 09:26:47 nebula3 crmd[5423]:   notice: do_state_transition: State transition S_IDLE -> S_INTEGRATION [ input=I_NODE_JOIN cause=C_FSA_INTERNAL origin=peer_update_callback ]
Nov 14 09:27:28 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 46 47 48 49 4a 4b 4c 4d 4e 4f 
Nov 14 09:27:28 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 47 48 49 4a 4b 4c 4d 4e 4f 
Nov 14 09:27:28 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4e 4f 
Nov 14 09:27:28 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4b 4c 4d 4e 4f 
Nov 14 09:27:48 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 45 46 47 48 49 4a 4b 4c 4d 4e 4f 
Nov 14 09:27:48 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 46 47 48 49 4a 4b 4c 4d 4e 4f 
Nov 14 09:27:48 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4b 4c 4d 4e 4f 
Nov 14 09:27:55 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4c 4d 4e 4f 
Nov 14 09:27:55 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4c 4d 4e 4f 
Nov 14 09:27:55 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4e 4f 
Nov 14 09:27:55 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4f 
Nov 14 09:28:35 nebula3 corosync[5345]: message repeated 5 times: [   [TOTEM ] Retransmit List: 4f ]
Nov 14 09:28:35 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4e 4f 
Nov 14 09:28:35 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4f 
#+end_src

I shutdown one-frontend to avoid crashing my cluster:

#+begin_src
Nov 14 09:28:43 nebula1 corosync[4242]:   [TOTEM ] A new membership (192.168.231.70:80700) was formed. Members left: 1084811119
Nov 14 09:28:43 nebula1 corosync[4242]:   [QUORUM] Members[4]: 1084811078 1084811079 1084811080 1084811118
Nov 14 09:28:43 nebula1 pacemakerd[4251]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now lost (was member)
Nov 14 09:28:43 nebula1 crmd[4258]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now lost (was member)
Nov 14 09:28:43 nebula1 corosync[4242]:   [MAIN  ] Completed service synchronization, ready to provide service.
Nov 14 09:28:43 nebula1 kernel: [84999.302680] dlm: closing connection to node 1084811119
Nov 14 09:28:43 nebula1 crmd[4258]:   notice: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ]
#+end_src

#+begin_src
Nov 14 09:28:43 nebula3 crmd[5423]:  warning: match_down_event: No match for shutdown action on 1084811119
Nov 14 09:28:43 nebula3 crmd[5423]:   notice: peer_update_callback: Stonith/shutdown of one-frontend not matched
Nov 14 09:28:43 nebula3 corosync[5345]:   [TOTEM ] Retransmit List: 4e 4f 
Nov 14 09:28:43 nebula3 corosync[5345]:   [TOTEM ] A new membership (192.168.231.70:80700) was formed. Members left: 1084811119
Nov 14 09:28:43 nebula3 corosync[5345]:   [QUORUM] Members[4]: 1084811078 1084811079 1084811080 1084811118
Nov 14 09:28:43 nebula3 corosync[5345]:   [MAIN  ] Completed service synchronization, ready to provide service.
Nov 14 09:28:43 nebula3 pacemakerd[5416]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now lost (was member)
Nov 14 09:28:43 nebula3 crmd[5423]:   notice: crm_update_peer_state: pcmk_quorum_notification: Node one-frontend[1084811119] - state is now lost (was member)
Nov 14 09:28:43 nebula3 crmd[5423]:  warning: match_down_event: No match for shutdown action on 1084811119
Nov 14 09:28:43 nebula3 crmd[5423]:   notice: peer_update_callback: Stonith/shutdown of one-frontend not matched
Nov 14 09:28:43 nebula3 kernel: [84176.263790] dlm: closing connection to node 1084811119
Nov 14 09:28:44 nebula3 crmd[5423]:   notice: do_state_transition: State transition S_ELECTION -> S_INTEGRATION [ input=I_ELECTION_DC cause=C_FSA_INTERNAL origin=do_election_check ]
#+end_src

Regards.

-- 
Daniel Dehennin
Récupérer ma clef GPG: gpg --recv-keys 0xCC1E9E5B7A6FE2DF
Fingerprint: 3E69 014E 5C23 50E8 9ED6  2AAD CC1E 9E5B 7A6F E2DF
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 342 bytes
Desc: not available
URL: <https://lists.clusterlabs.org/pipermail/pacemaker/attachments/20141114/2d230258/attachment-0003.sig>


More information about the Pacemaker mailing list