Sep 21 14:00:18.452574 [MAIN ] AIS Executive Service RELEASE 'subrev 1152 version 0.80' Sep 21 14:00:18.452686 [MAIN ] Copyright (C) 2002-2006 MontaVista Software, Inc and contributors. Sep 21 14:00:18.452709 [MAIN ] Copyright (C) 2006 Red Hat, Inc. Sep 21 14:00:18.452728 [MAIN ] AIS Executive Service: started and ready to provide service. Sep 21 14:00:18.458221 [TOTEM] Token Timeout (5000 ms) retransmit timeout (490 ms) Sep 21 14:00:18.458247 [TOTEM] token hold (382 ms) retransmits before loss (10 retrans) Sep 21 14:00:18.458252 [TOTEM] join (1000 ms) send_join (45 ms) consensus (2500 ms) merge (200 ms) Sep 21 14:00:18.458258 [TOTEM] downcheck (1000 ms) fail to recv const (50 msgs) Sep 21 14:00:18.458262 [TOTEM] seqno unchanged const (30 rotations) Maximum network MTU 1500 Sep 21 14:00:18.458266 [TOTEM] window size per rotation (50 messages) maximum messages per rotation (20 messages) Sep 21 14:00:18.458271 [TOTEM] send threads (0 threads) Sep 21 14:00:18.458275 [TOTEM] RRP token expired timeout (490 ms) Sep 21 14:00:18.458279 [TOTEM] RRP token problem counter (2000 ms) Sep 21 14:00:18.458282 [TOTEM] RRP threshold (10 problem count) Sep 21 14:00:18.458286 [TOTEM] RRP mode set to none. Sep 21 14:00:18.458290 [TOTEM] heartbeat_failures_allowed (0) Sep 21 14:00:18.458294 [TOTEM] max_network_delay (50 ms) Sep 21 14:00:18.458327 [TOTEM] HeartBeat is Disabled. To enable set heartbeat_failures_allowed > 0 Sep 21 14:00:18.458546 [TOTEM] Receive multicast socket recv buffer size (262142 bytes). Sep 21 14:00:18.458569 [TOTEM] Transmit multicast socket send buffer size (262142 bytes). Sep 21 14:00:18.462135 [TOTEM] The network interface [10.53.11.102] is now up. Sep 21 14:00:18.462164 [TOTEM] Created or loaded sequence id 652.10.53.11.102 for this ring. Sep 21 14:00:18.477152 [TOTEM] entering GATHER state from 15. Sep 21 14:00:18.478722 [crm ] info: process_ais_conf: Reading configure Sep 21 14:00:18.478741 [MAIN ] info: config_find_next: Processing additional logging options... Sep 21 14:00:18.478749 [MAIN ] info: get_config_opt: Found 'off' for option: debug Sep 21 14:00:18.478761 [MAIN ] info: get_config_opt: Found 'yes' for option: to_file Sep 21 14:00:18.478766 [MAIN ] info: get_config_opt: Found 'yes' for option: to_syslog Sep 21 14:00:18.478771 [MAIN ] info: get_config_opt: Found '/var/log/openais.log' for option: logfile Sep 21 14:00:18.478777 [MAIN ] info: get_config_opt: Found 'daemon' for option: syslog_facility Sep 21 14:00:18.478784 [MAIN ] info: config_find_next: Processing additional service options... Sep 21 14:00:18.478790 [MAIN ] info: get_config_opt: Found 'yes' for option: use_logd Sep 21 14:00:18.478795 [MAIN ] info: get_config_opt: Found 'no' for option: use_mgmtd Sep 21 14:00:18.481221 [crm ] info: pcmk_plugin_init: CRM: Initialized Sep 21 14:00:18.481239 [crm ] Logging: Initialized pcmk_plugin_init Sep 21 14:00:18 oss2 stonithd: [16655]: WARN: Initializing connection to logging daemon failed. Logging daemon may not be running Sep 21 14:00:18 oss2 stonithd: [16655]: info: G_main_add_SignalHandler: Added signal handler for signal 10 Sep 21 14:00:18.481261 [crm ] info: pcmk_plugin_init: Service: 9 Sep 21 14:00:18 oss2 stonithd: [16655]: info: G_main_add_SignalHandler: Added signal handler for signal 12 Sep 21 14:00:18 oss2 lrmd: [16657]: WARN: Initializing connection to logging daemon failed. Logging daemon may not be running Sep 21 14:00:18.481267 [crm ] info: pcmk_plugin_init: Local node id: 1712010506 Sep 21 14:00:18 oss2 stonithd: [16655]: info: Stack hogger failed 0xffffffff Sep 21 14:00:18 oss2 lrmd: [16657]: info: G_main_add_SignalHandler: Added signal handler for signal 15 Sep 21 14:00:18.481272 [crm ] info: pcmk_plugin_init: Local hostname: oss2 Sep 21 14:00:18 oss2 stonithd: [16655]: info: crm_cluster_connect: Connecting to OpenAIS Sep 21 14:00:18 oss2 lrmd: [16657]: info: G_main_add_SignalHandler: Added signal handler for signal 17 Sep 21 14:00:18.481284 [MAIN ] info: update_member: Creating entry for node 1712010506 born on 0 Sep 21 14:00:18 oss2 stonithd: [16655]: info: init_ais_connection: Creating connection to our AIS plugin Sep 21 14:00:18 oss2 lrmd: [16657]: info: G_main_add_SignalHandler: Added signal handler for signal 10 Sep 21 14:00:18.481300 [MAIN ] info: update_member: 0x1d064120 Node 1712010506 now known as oss2 (was: (null)) Sep 21 14:00:18 oss2 lrmd: [16657]: info: G_main_add_SignalHandler: Added signal handler for signal 12 Sep 21 14:00:18.481308 [MAIN ] info: update_member: Node oss2 now has 1 quorum votes (was 0) Sep 21 14:00:18 oss2 lrmd: [16657]: info: Started. Sep 21 14:00:18.481314 [MAIN ] info: update_member: Node 1712010506/oss2 is now: member Sep 21 14:00:18.487121 [MAIN ] info: spawn_child: Forked child 16655 for process stonithd Sep 21 14:00:18.490560 [MAIN ] info: spawn_child: Forked child 16656 for process cib Sep 21 14:00:18.493100 [MAIN ] info: spawn_child: Forked child 16657 for process lrmd Sep 21 14:00:18 oss2 stonithd: [16655]: info: init_ais_connection: AIS connection established Sep 21 14:00:18.494099 [MAIN ] info: spawn_child: Forked child 16658 for process attrd Sep 21 14:00:18 oss2 stonithd: [16655]: info: get_ais_nodeid: Server details: id=1712010506 uname=oss2 Sep 21 14:00:18.495877 [MAIN ] info: spawn_child: Forked child 16659 for process pengine Sep 21 14:00:18 oss2 stonithd: [16655]: info: crm_new_peer: Node oss2 now has id: 1712010506 Sep 21 14:00:18.499095 [MAIN ] info: spawn_child: Forked child 16660 for process crmd Sep 21 14:00:18 oss2 stonithd: [16655]: info: crm_new_peer: Node 1712010506 is now known as oss2 Sep 21 14:00:18.499116 [crm ] info: pcmk_startup: CRM: Initialized Sep 21 14:00:18 oss2 stonithd: [16655]: notice: /usr/lib64/heartbeat/stonithd start up successfully. Sep 21 14:00:18.499130 [MAIN ] Service initialized 'Pacemaker Cluster Manager' Sep 21 14:00:18 oss2 stonithd: [16655]: info: G_main_add_SignalHandler: Added signal handler for signal 17 Sep 21 14:00:18.499852 [SERV ] Service initialized 'openais extended virtual synchrony service' Sep 21 14:00:18.500257 [SERV ] Service initialized 'openais cluster membership service B.01.01' Sep 21 14:00:18.500408 [SERV ] Service initialized 'openais availability management framework B.01.01' Sep 21 14:00:18.500590 [SERV ] Service initialized 'openais checkpoint service B.01.01' Sep 21 14:00:18.500891 [SERV ] Service initialized 'openais event service B.01.01' Sep 21 14:00:18.501205 [SERV ] Service initialized 'openais distributed locking service B.01.01' Sep 21 14:00:18.501587 [SERV ] Service initialized 'openais message service B.01.01' Sep 21 14:00:18.501781 [SERV ] Service initialized 'openais configuration service' Sep 21 14:00:18.501963 [SERV ] Service initialized 'openais cluster closed process group service v1.01' Sep 21 14:00:18.502083 [SERV ] Service initialized 'openais cluster config database access v1.01' Sep 21 14:00:18.502455 [SYNC ] Using virtual synchrony filter openais_vsf_ykd Sep 21 14:00:18.502512 [TOTEM] Creating commit token because I am the rep. Sep 21 14:00:18.502526 [TOTEM] Saving state aru 0 high seq received 0 Sep 21 14:00:18.502542 [TOTEM] Storing new sequence id for ring 290 Sep 21 14:00:18.502596 [TOTEM] entering COMMIT state. Sep 21 14:00:18.502612 [TOTEM] entering RECOVERY state. Sep 21 14:00:18.502666 [TOTEM] position [0] member 10.53.11.102: Sep 21 14:00:18.502673 [TOTEM] previous ring seq 652 rep 10.53.11.102 Sep 21 14:00:18.502677 [TOTEM] aru 0 high delivered 0 received flag 1 Sep 21 14:00:18.502682 [TOTEM] Did not need to originate any messages in recovery. Sep 21 14:00:18.502691 [TOTEM] Sending initial ORF token Sep 21 14:00:18.502756 [CLM ] CLM CONFIGURATION CHANGE Sep 21 14:00:18.502767 [CLM ] New Configuration: Sep 21 14:00:18.502771 [CLM ] Members Left: Sep 21 14:00:18.502775 [CLM ] Members Joined: Sep 21 14:00:18.502793 [crm ] notice: pcmk_peer_update: Transitional membership event on ring 656: memb=0, new=0, lost=0 Sep 21 14:00:18.502801 [CLM ] CLM CONFIGURATION CHANGE Sep 21 14:00:18.502805 [CLM ] New Configuration: Sep 21 14:00:18.502812 [CLM ] r(0) ip(10.53.11.102) Sep 21 14:00:18.502817 [CLM ] Members Left: Sep 21 14:00:18.502820 [CLM ] Members Joined: Sep 21 14:00:18.502825 [CLM ] r(0) ip(10.53.11.102) Sep 21 14:00:18.502833 [crm ] notice: pcmk_peer_update: Stable membership event on ring 656: memb=1, new=1, lost=0 Sep 21 14:00:18.502843 [crm ] info: pcmk_peer_update: NEW: oss2 1712010506 Sep 21 14:00:18.502852 [crm ] info: pcmk_peer_update: MEMB: oss2 1712010506 Sep 21 14:00:18.502865 [MAIN ] info: update_member: Node oss2 now has process list: 00000000000000000000000000013312 (78610) Sep 21 14:00:18.502877 [SYNC ] This node is within the non-primary component and will NOT provide any services. Sep 21 14:00:18.503035 [TOTEM] entering OPERATIONAL state. Sep 21 14:00:18.503804 [YKD ] This processor is within the primary component. Sep 21 14:00:18.503816 [SYNC ] This node is within the primary component and will provide service. Sep 21 14:00:18.503860 [CLM ] got nodejoin message 10.53.11.102 Sep 21 14:00:18.540139 [TOTEM] entering GATHER state from 11. Sep 21 14:00:18.540770 [TOTEM] Saving state aru 12 high seq received 12 Sep 21 14:00:18.540791 [TOTEM] Storing new sequence id for ring 294 Sep 21 14:00:18.540821 [TOTEM] entering COMMIT state. Sep 21 14:00:18.542057 [TOTEM] entering RECOVERY state. Sep 21 14:00:18.542119 [TOTEM] position [0] member 10.53.11.100: Sep 21 14:00:18.542127 [TOTEM] previous ring seq 652 rep 10.53.11.100 Sep 21 14:00:18.542132 [TOTEM] aru 14 high delivered 14 received flag 1 Sep 21 14:00:18.542137 [TOTEM] position [1] member 10.53.11.102: Sep 21 14:00:18.542142 [TOTEM] previous ring seq 656 rep 10.53.11.102 Sep 21 14:00:18.542146 [TOTEM] aru 12 high delivered 12 received flag 1 Sep 21 14:00:18.542151 [TOTEM] Did not need to originate any messages in recovery. Sep 21 14:00:18.547551 [crm ] info: pcmk_ipc: Recorded connection 0x1d073120 for stonithd/16655 Sep 21 14:00:18.549437 [CLM ] CLM CONFIGURATION CHANGE Sep 21 14:00:18.549451 [CLM ] New Configuration: Sep 21 14:00:18.549461 [CLM ] r(0) ip(10.53.11.102) Sep 21 14:00:18.549468 [CLM ] Members Left: Sep 21 14:00:18.549472 [CLM ] Members Joined: Sep 21 14:00:18.549484 [crm ] notice: pcmk_peer_update: Transitional membership event on ring 660: memb=1, new=0, lost=0 Sep 21 14:00:18.549493 [crm ] info: pcmk_peer_update: memb: oss2 1712010506 Sep 21 14:00:18.549500 [CLM ] CLM CONFIGURATION CHANGE Sep 21 14:00:18.549504 [CLM ] New Configuration: Sep 21 14:00:18.549510 [CLM ] r(0) ip(10.53.11.100) Sep 21 14:00:18.549515 [CLM ] r(0) ip(10.53.11.102) Sep 21 14:00:18.549519 [CLM ] Members Left: Sep 21 14:00:18.549523 [CLM ] Members Joined: Sep 21 14:00:18.549547 [CLM ] r(0) ip(10.53.11.100) Sep 21 14:00:18.549560 [crm ] notice: pcmk_peer_update: Stable membership event on ring 660: memb=2, new=1, lost=0 Sep 21 14:00:18.549568 [MAIN ] info: update_member: Creating entry for node 1678456074 born on 660 Sep 21 14:00:18.549576 [MAIN ] info: update_member: Node 1678456074/unknown is now: member Sep 21 14:00:18.549581 [crm ] info: pcmk_peer_update: NEW: .pending. 1678456074 Sep 21 14:00:18.549589 [crm ] info: pcmk_peer_update: MEMB: .pending. 1678456074 Sep 21 14:00:18.549594 [crm ] info: pcmk_peer_update: MEMB: oss2 1712010506 Sep 21 14:00:18.549620 [crm ] info: send_member_notification: Sending membership update 660 to 0 children Sep 21 14:00:18.549630 [MAIN ] info: update_member: 0x1d064120 Node 1712010506 ((null)) born on: 660 Sep 21 14:00:18.549640 [SYNC ] This node is within the non-primary component and will NOT provide any services. Sep 21 14:00:18.549886 [TOTEM] entering OPERATIONAL state. Sep 21 14:00:18.555425 [MAIN ] info: update_member: 0x1d072040 Node 1678456074 (oss1) born on: 660 Sep 21 14:00:18.555455 [MAIN ] info: update_member: 0x1d072040 Node 1678456074 now known as oss1 (was: (null)) Sep 21 14:00:18.555463 [MAIN ] info: update_member: Node oss1 now has process list: 00000000000000000000000000013312 (78610) Sep 21 14:00:18.555469 [MAIN ] info: update_member: Node oss1 now has 1 quorum votes (was 0) Sep 21 14:00:18.555484 [crm ] info: send_member_notification: Sending membership update 660 to 0 children Sep 21 14:00:18.556802 [YKD ] This processor is within the primary component. Sep 21 14:00:18.556813 [SYNC ] This node is within the primary component and will provide service. Sep 21 14:00:18.557310 [CLM ] got nodejoin message 10.53.11.100 Sep 21 14:00:18.557367 [CLM ] got nodejoin message 10.53.11.102 Sep 21 14:00:18.590147 [crm ] info: pcmk_ipc: Recorded connection 0x1d072be0 for cib/16656 Sep 21 14:00:18.590186 [crm ] info: pcmk_ipc: Sending membership update 660 to cib Sep 21 14:00:18.668748 [crm ] WARN: route_ais_message: Sending message to local.crmd failed: unknown (rc=-2) Sep 21 14:00:18.812497 [crm ] WARN: route_ais_message: Sending message to local.crmd failed: unknown (rc=-2) Sep 21 14:00:19.549633 [crm ] info: pcmk_ipc: Recorded connection 0x1d073020 for crmd/16660 Sep 21 14:00:19.549673 [crm ] info: pcmk_ipc: Sending membership update 660 to crmd Sep 21 14:00:19.570223 [crm ] info: update_expected_votes: Expected quorum votes 1024 -> 2 Sep 21 14:00:22.323543 [TOTEM] entering GATHER state from 11. Sep 21 14:00:23.368370 [TOTEM] Saving state aru 2a high seq received 2a Sep 21 14:00:23.368398 [TOTEM] Storing new sequence id for ring 298 Sep 21 14:00:23.368428 [TOTEM] entering COMMIT state. Sep 21 14:00:23.375941 [TOTEM] entering RECOVERY state. Sep 21 14:00:23.375990 [TOTEM] position [0] member 10.53.11.100: Sep 21 14:00:23.376000 [TOTEM] previous ring seq 660 rep 10.53.11.100 Sep 21 14:00:23.376005 [TOTEM] aru 2a high delivered 2a received flag 1 Sep 21 14:00:23.376010 [TOTEM] position [1] member 10.53.11.102: Sep 21 14:00:23.376015 [TOTEM] previous ring seq 660 rep 10.53.11.100 Sep 21 14:00:23.376019 [TOTEM] aru 2a high delivered 2a received flag 1 Sep 21 14:00:23.376024 [TOTEM] position [2] member 10.53.11.103: Sep 21 14:00:23.376029 [TOTEM] previous ring seq 648 rep 10.53.11.103 Sep 21 14:00:23.376033 [TOTEM] aru 12 high delivered 12 received flag 1 Sep 21 14:00:23.376037 [TOTEM] Did not need to originate any messages in recovery. Sep 21 14:00:23.381820 [CLM ] CLM CONFIGURATION CHANGE Sep 21 14:00:23.381835 [CLM ] New Configuration: Sep 21 14:00:23.381844 [CLM ] r(0) ip(10.53.11.100) Sep 21 14:00:23.381851 [CLM ] r(0) ip(10.53.11.102) Sep 21 14:00:23.381855 [CLM ] Members Left: Sep 21 14:00:23.381859 [CLM ] Members Joined: Sep 21 14:00:23.381871 [crm ] notice: pcmk_peer_update: Transitional membership event on ring 664: memb=2, new=0, lost=0 Sep 21 14:00:23.381879 [crm ] info: pcmk_peer_update: memb: oss1 1678456074 Sep 21 14:00:23.381884 [crm ] info: pcmk_peer_update: memb: oss2 1712010506 Sep 21 14:00:23.381890 [CLM ] CLM CONFIGURATION CHANGE Sep 21 14:00:23.381894 [CLM ] New Configuration: Sep 21 14:00:23.381899 [CLM ] r(0) ip(10.53.11.100) Sep 21 14:00:23.381905 [CLM ] r(0) ip(10.53.11.102) Sep 21 14:00:23.381926 [CLM ] r(0) ip(10.53.11.103) Sep 21 14:00:23.381931 [CLM ] Members Left: Sep 21 14:00:23.381935 [CLM ] Members Joined: Sep 21 14:00:23.381940 [CLM ] r(0) ip(10.53.11.103) Sep 21 14:00:23.381947 [crm ] notice: pcmk_peer_update: Stable membership event on ring 664: memb=3, new=1, lost=0 Sep 21 14:00:23.381954 [MAIN ] info: update_member: Creating entry for node 1728787722 born on 664 Sep 21 14:00:23.381962 [MAIN ] info: update_member: Node 1728787722/unknown is now: member Sep 21 14:00:23.381968 [crm ] info: pcmk_peer_update: NEW: .pending. 1728787722 Sep 21 14:00:23.381976 [crm ] info: pcmk_peer_update: MEMB: oss1 1678456074 Sep 21 14:00:23.381981 [crm ] info: pcmk_peer_update: MEMB: oss2 1712010506 Sep 21 14:00:23.381986 [crm ] info: pcmk_peer_update: MEMB: .pending. 1728787722 Sep 21 14:00:23.381991 [crm ] info: update_expected_votes: Expected quorum votes 2 -> 3 Sep 21 14:00:23.382012 [crm ] info: send_member_notification: Sending membership update 664 to 2 children Sep 21 14:00:23.382086 [SYNC ] This node is within the non-primary component and will NOT provide any services. Sep 21 14:00:23.382371 [TOTEM] entering OPERATIONAL state. Sep 21 14:00:23.387684 [MAIN ] info: update_member: 0x1d064590 Node 1728787722 (oss3) born on: 664 Sep 21 14:00:23.387762 [MAIN ] info: update_member: 0x1d064590 Node 1728787722 now known as oss3 (was: (null)) Sep 21 14:00:23.387770 [MAIN ] info: update_member: Node oss3 now has process list: 00000000000000000000000000013312 (78610) Sep 21 14:00:23.387776 [MAIN ] info: update_member: Node oss3 now has 1 quorum votes (was 0) Sep 21 14:00:23.387801 [crm ] info: send_member_notification: Sending membership update 664 to 2 children Sep 21 14:00:23.394000 [YKD ] This processor is within the primary component. Sep 21 14:00:23.394011 [SYNC ] This node is within the primary component and will provide service. Sep 21 14:00:23.399753 [CLM ] got nodejoin message 10.53.11.102 Sep 21 14:00:23.401161 [CLM ] got nodejoin message 10.53.11.103 Sep 21 14:00:23.401401 [CLM ] got nodejoin message 10.53.11.100 Sep 21 14:00:31.551556 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:18.448388 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:18.457584 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:18.472096 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:19.442555 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:19.497311 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:19.537805 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:20.082441 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2) Sep 21 14:06:20.116970 [crm ] WARN: route_ais_message: Sending message to local.attrd failed: unknown (rc=-2)