Issues when running Heartbeat on FreeBSD 8.1 RELEASE

Kevin Mai kma at mrecic.gov.ar
Fri Dec 10 15:36:41 UTC 2010


Hi folks, 

I'm trying to build a failover solution using FreeBSD 8.1-RELEASE and Heartbeat from ports (v2.1.4-10). 

I've already configured heartbeat in the two peers, but once I start the daemon using the /usr/local/etc/rc.d/heartbeat script, either CRM and CIB fail to start. 

I've already found out that the issue is appearing with CIB: when the daemon runs CIB it doesn't start, but if I run it using some flags, it starts, and them I'm able to run CRM too. 

IE: 
heartbeat[12539]: 2010/12/10_14:22:14 info: Starting "/usr/local/lib/heartbeat/cib" as uid 275 gid 275 (pid 12539) 
heartbeat[12540]: 2010/12/10_14:22:14 info: Starting "/usr/local/lib/heartbeat/attrd" as uid 275 gid 275 (pid 12540) 
heartbeat[12482]: 2010/12/10_14:22:14 WARN: Managed /usr/local/lib/heartbeat/cib process 12539 exited with return code 2. 
heartbeat[12482]: 2010/12/10_14:22:14 ERROR: Client /usr/local/lib/heartbeat/cib "respawning too fast" 
heartbeat[12541]: 2010/12/10_14:22:14 info: Starting "/usr/local/lib/heartbeat/crmd" as uid 275 gid 275 (pid 12541) 
heartbeat[12482]: 2010/12/10_14:22:14 WARN: Managed /usr/local/lib/heartbeat/attrd process 12540 exited with return code 2. 
heartbeat[12482]: 2010/12/10_14:22:14 ERROR: Client /usr/local/lib/heartbeat/attrd "respawning too fast" 
heartbeat[12482]: 2010/12/10_14:22:14 WARN: Managed /usr/local/lib/heartbeat/crmd process 12541 exited with return code 2. 
heartbeat[12482]: 2010/12/10_14:22:14 ERROR: Client /usr/local/lib/heartbeat/crmd "respawning too fast" 

but if I run it from command line 

[root at mrefns09 /usr/ports]# /usr/local/lib/heartbeat/cib -s -VVV & 
cib[13338]: 2010/12/10_14:30:49 info: main: Retrieval of a per-action CIB: disabled 
cib[13338]: 2010/12/10_14:30:49 info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.xml (digest: /var/lib/heartbeat/crm/cib.xml.sig) 
cib[13338]: 2010/12/10_14:30:49 debug: debug3: file2xml: Reading 3538 bytes from file 
cib[13338]: 2010/12/10_14:30:49 WARN: validate_cib_digest: No on-disk digest present 
cib[13338]: 2010/12/10_14:30:49 debug: update_quorum: CCM quorum: old=(null), new=false 
cib[13338]: 2010/12/10_14:30:49 debug: update_counters: Counters updated by readCibXmlFile 
cib[13338]: 2010/12/10_14:30:49 notice: readCibXmlFile: Enabling DTD validation on the existing (sane) configuration 
cib[13338]: 2010/12/10_14:30:49 info: startCib: CIB Initialization completed successfully 
cib[13338]: 2010/12/10_14:30:49 debug: debug3: init_server_ipc_comms: Listening on: /var/run/heartbeat/crm/cib_callback 
cib[13338]: 2010/12/10_14:30:49 debug: debug3: init_server_ipc_comms: Listening on: /var/run/heartbeat/crm/cib_ro 
cib[13338]: 2010/12/10_14:30:49 debug: debug3: init_server_ipc_comms: Listening on: /var/run/heartbeat/crm/cib_rw 
cib[13338]: 2010/12/10_14:30:49 debug: debug3: init_server_ipc_comms: Listening on: /var/run/heartbeat/crm/cib_rw_syncronous 
cib[13338]: 2010/12/10_14:30:49 debug: debug3: init_server_ipc_comms: Listening on: /var/run/heartbeat/crm/cib_ro_syncronous 
cib[13338]: 2010/12/10_14:30:49 info: cib_init: Starting cib mainloop 

[root at mrefns09 /usr/local/lib/heartbeat]# /usr/local/lib/heartbeat/crmd -VVV 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: main: Enabling coredumps 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: digraph "g" { 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: size = "30,30" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: graph [ 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontsize = "12" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontname = "Times-Roman" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontcolor = "black" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: bb = "0,0,398.922306,478.927856" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: color = "black" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: node [ 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontsize = "12" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontname = "Times-Roman" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontcolor = "black" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: shape = "ellipse" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: color = "black" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: edge [ 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontsize = "12" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontname = "Times-Roman" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontcolor = "black" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: color = "black" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: // special nodes 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_PENDING" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: [ 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: color = "blue" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontcolor = "blue" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_TERMINATE" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: [ 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: color = "red" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: fontcolor = "red" 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: // DC only nodes 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_INTEGRATION" [ fontcolor = "green" ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_POLICY_ENGINE" [ fontcolor = "green" ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_TRANSITION_ENGINE" [ fontcolor = "green" ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_RELEASE_DC" [ fontcolor = "green" ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: init_dotfile: actions:trace: "S_IDLE" [ fontcolor = "green" ] 
crmd[14877]: 2010/12/10_15:14:28 info: crmd_init: Starting crmd 
crmd[14877]: 2010/12/10_15:14:28 debug: register_fsa_input_adv: crmd_init appended FSA input 1 (I_STARTUP) (cause=C_STARTUP) without data 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: register_fsa_input_adv: Queue len: 1 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: s_crmd_fsa: FSA invoked with Cause: C_STARTUP State: S_STARTING 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: s_crmd_fsa: Checking messages (1 remaining) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: get_message: Processing input 1 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: log_fsa_input: Processing queued input 1 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: log_fsa_input: FSA processing input from crmd_init 
crmd[14877]: 2010/12/10_15:14:28 debug: s_crmd_fsa: Processing I_STARTUP: [ state=S_STARTING cause=C_STARTUP origin=crmd_init ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_LOG (1000000000000000) 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_LOG 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: do_log: [[FSA]] Input I_STARTUP from crmd_init() received in state (S_STARTING) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_LOG (1000000000000000) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: s_crmd_fsa: actions:trace: // FSA input: State=S_STARTING Cause=C_STARTUP Input=I_STARTUP Origin=crmd_init() id=1 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_STARTUP (0000000000000001) 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_STARTUP 
crmd[14877]: 2010/12/10_15:14:28 debug: do_startup: Registering Signal Handlers 
crmd[14877]: 2010/12/10_15:14:28 info: G_main_add_SignalHandler: Added signal handler for signal 15 
crmd[14877]: 2010/12/10_15:14:28 info: G_main_add_TriggerHandler: Added signal manual handler 
crmd[14877]: 2010/12/10_15:14:28 debug: do_startup: Creating CIB and LRM objects 
crmd[14877]: 2010/12/10_15:14:28 info: G_main_add_SignalHandler: Added signal handler for signal 20 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_STARTUP (0000000000000001) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_CIB_START (0000020000000000) 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_CIB_START 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/heartbeat/crm/cib_rw 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: init_client_ipc_comms_nodispatch: Processing of /var/run/heartbeat/crm/cib_rw complete 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/heartbeat/crm/cib_callback 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: init_client_ipc_comms_nodispatch: Processing of /var/run/heartbeat/crm/cib_callback complete 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: init_client_ipc_comms: Adding dispatch method to channel 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_client_connect_common: Connecting channel 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_client_connect_common: Created channel 0x802841958 for channel cib_rw 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_client_connect_common: Channel cib_rw connected for client (null) 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= IPC[outbound] message start ==========# 
cib[14871]: 2010/12/10_15:14:28 debug: MSG: Dumping message with 3 fields 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[0] : [cib_op=register] 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[1] : [cib_clientid=4821470c-0aac-4bd6-9d5b-f4a15fdd063c] 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[2] : [cib_callback_token=e87ceee6-3043-4c2d-b183-b3adeca43683] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= IPC[outbound] message start ==========# 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: debug3: cib_client_connect_common: Connecting channel 
debug: MSG: Dumping message with 3 fields 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[0] : [cib_op=register] 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_client_connect_common: Created channel 0x802841dd8 for channel cib_callback 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[1] : [cib_callback_token=e87ceee6-3043-4c2d-b183-b3adeca43683] 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[2] : [cib_clientname=crmd] 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_client_connect_common: Channel cib_callback connected for client (null) 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_null_callback: Registered e87ceee6-3043-4c2d-b183-b3adeca43683 on cib_callback channel 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= IPC[outbound] message start ==========# 
cib[14871]: 2010/12/10_15:14:28 debug: MSG: Dumping message with 2 fields 
crmd[14877]: 2010/12/10_15:14:28 debug: cib_native_signon: Connection to CIB successful 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[0] : [cib_op=register] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: cib_native_set_connection_dnotify: Setting dnotify 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[1] : [cib_clientid=e87ceee6-3043-4c2d-b183-b3adeca43683] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: cib_client_add_notify_callback: Adding callback for cib_refresh_notify events (0) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= IPC[outbound] message start ==========# 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG: Dumping message with 3 fields 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[0] : [cib_op=cib_notify] 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 info: cib_null_callback: Setting cib_refresh_notify callbacks for crmd: on 
debug: MSG[1] : [cib_notify_type=cib_refresh_notify] 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[2] : [cib_notify_activate=1] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: cib_client_add_notify_callback: Callback added (1) 
crmd[14877]: 2010/12/10_15:14:28 info: do_cib_control: CIB connection established 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: cib_native_perform_op: Sending cib_query message to CIB service 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= IPC[outbound] message start ==========# 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG: Dumping message with 5 fields 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[0] : [__name__=cib_command] 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_common_callback: Callback for 4821470c-0aac-4bd6-9d5b-f4a15fdd063c on cib_rw channel 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[1] : [t=cib] 
crmd[14877]: 2010/12/10_15:14:28 debug: MSG[2] : [cib_op=cib_query] 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= Client[inbound] message start ==========# 
debug: MSG[3] : [cib_callid=2] 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: MSG: Dumping message with 5 fields 
debug: MSG[4] : [cib_callopt=256] 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: MSG[0] : [__name__=cib_command] 
debug: debug3: cib_native_perform_op: Message sent 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: MSG[1] : [t=cib] 
debug: debug3: cib_native_perform_op: Async call, returning 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[2] : [cib_op=cib_query] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_CIB_START (0000020000000000) 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[3] : [cib_callid=2] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_HA_CONNECT (0000000000000004) 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[4] : [cib_callopt=256] 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_HA_CONNECT 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_common_callback_worker: Processing cib_query operation from -1/cib_rw 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: register_with_ha: Signing in with Heartbeat 
debug: debug2: cib_process_request: Processing local message (localhost) for master... 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: parse_local_options: Processing locally scoped cib_query op from -1 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_process_request: Finished determining processing actions 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_process_request: Performing local processing: op=cib_query origin=(null)/4821470c-0aac-4bd6-9d5b-f4a15fdd063c,2 (update=(null)) 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_process_query: Processing "cib_query" event for section=<null> 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_process_request: Processing complete 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_process_request: processing response cases 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: do_local_notify: Performing notification 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: do_local_notify: Sending callback to request originator 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: do_local_notify: Sending an a-sync response to -1 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: send_via_callback_channel: Delivering msg 0x802895538 to client e87ceee6-3043-4c2d-b183-b3adeca43683 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: send_via_callback_channel: Delivering reply to client e87ceee6-3043-4c2d-b183-b3adeca43683 
crmd[14877]: 2010/12/10_15:14:28 ERROR: register_with_ha: Cannot sign on with heartbeat: 
crmd[14877]: 2010/12/10_15:14:28 debug: register_fsa_input_adv: register_fsa_error_adv prepended FSA input 2 (I_NULL) (cause=C_STARTUP) without data 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: register_fsa_input_adv: Adding actions 0180001000000002 to input 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: register_fsa_input_adv: Prepending input 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: register_fsa_input_adv: Queue len: 1 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv 
crmd[14877]: 2010/12/10_15:14:28 debug: register_fsa_input_adv: do_ha_control prepended FSA input 3 (I_FAIL) (cause=C_FSA_INTERNAL) without data 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: register_fsa_input_adv: Prepending input 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: register_fsa_input_adv: Queue len: 2 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: register_fsa_input_adv: Triggering FSA: register_fsa_input_adv 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_HA_CONNECT (0000000000000004) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: s_crmd_fsa: Checking messages (2 remaining) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: get_message: Processing input 3 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: log_fsa_input: Processing queued input 3 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: log_fsa_input: FSA processing input from do_ha_control 
crmd[14877]: 2010/12/10_15:14:28 debug: s_crmd_fsa: Processing I_FAIL: [ state=S_STARTING cause=C_FSA_INTERNAL origin=do_ha_control ] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_WARN (4000000000000000) 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_WARN 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: crm_log_message_adv: #========= IPC[outbound] message start ==========# 
crmd[14877]: 2010/12/10_15:14:28 WARN: do_log: [[FSA]] Input I_FAIL from do_ha_control() received in state (S_STARTING) 
cib[14871]: 2010/12/10_15:14:28 debug: MSG: Dumping message with 7 fields 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_WARN (4000000000000000) 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[0] : [t=cib] 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: debug2: do_state_transition: actions:trace: S_STARTING -> S_STOPPING [ label=I_FAIL cause=C_FSA_INTERNAL origin=do_ha_control ] 
debug: MSG[1] : [cib_clientid=4821470c-0aac-4bd6-9d5b-f4a15fdd063c] 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 info: do_state_transition: State transition S_STARTING -> S_STOPPING [ input=I_FAIL cause=C_FSA_INTERNAL origin=do_ha_control ] 
debug: MSG[2] : [cib_callopt=256] 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: debug2: crm_timer_stop: Election Timeout (I_ELECTION_DC:-1ms) already stopped 
debug: MSG[3] : [cib_callid=2] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: crm_timer_stop: PEngine Recheck Timer (I_PE_CALC:-1ms) already stopped 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[4] : [cib_op=cib_query] 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: debug3: fsa_dump_actions: Action 0000000000000200 (A_DC_TIMER_STOP) New actions 
debug: MSG[5] : [cib_rc=0] 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: fsa_dump_actions: Action 0000000000000020 (A_INTEGRATE_TIMER_STOP) New actions 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: fsa_dump_actions: Action 0000000000000080 (A_FINALIZE_TIMER_STOP) New actions 
cib[14871]: 2010/12/10_15:14:28 debug: MSG[6] : [(2)cib_calldata=0x8028a65f8(4108 5133)] 
cib[14871]: 2010/12/10_15:14:28 debug: <cib admin_epoch="0" epoch="0" num_updates="0" generated="false" have_quorum="false" ignore_dtd="false"> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_DC_TIMER_STOP (0000000000000200) 
cib[14871]: 2010/12/10_15:14:28 debug: <configuration> 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_DC_TIMER_STOP 
debug: <crm_config> 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: debug2: crm_timer_stop: Election Trigger (I_DC_TIMEOUT:-1ms) already stopped 
debug: <cluster_property_set id="cib-bootstrap-options"> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_DC_TIMER_STOP (0000000000000200) 
cib[14871]: 2010/12/10_15:14:28 debug: <attributes> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_INTEGRATE_TIMER_STOP (0000000000000020) 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-symmetric-cluster" name="symmetric-cluster" value="true"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_INTEGRATE_TIMER_STOP 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-no-quorum-policy" name="no-quorum-policy" value="stop"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: crm_timer_stop: Integration Timer (I_INTEGRATED:-1ms) already stopped 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-default-resource-stickiness" name="default-resource-stickiness" value="0"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Action complete: A_INTEGRATE_TIMER_STOP (0000000000000020) 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-default-resource-failure-stickiness" name="default-resource-failure-stickiness" value="0"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: do_fsa_action: Invoking action A_FINALIZE_TIMER_STOP (0000000000000080) 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-stonith-enabled" name="stonith-enabled" value="false"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: do_fsa_action: actions:trace: // A_FINALIZE_TIMER_STOP 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-stonith-action" name="stonith-action" value="reboot"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: crm_timer_stop: Finalization Timer (I_ELECTION:-1ms) already stopped 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-startup-fencing" name="startup-fencing" value="true"/> 
debug: debug3: do_fsa_action: Action complete: A_FINALIZE_TIMER_STOP (0000000000000080) 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-stop-orphan-resources" name="stop-orphan-resources" value="true"/> 
debug: debug2: s_crmd_fsa: Checking messages (1 remaining) 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: get_message: Processing input 2 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-stop-orphan-actions" name="stop-orphan-actions" value="true"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: log_fsa_input: Processing queued input 2 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-remove-after-stop" name="remove-after-stop" value="false"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: log_fsa_input: FSA processing input from register_fsa_error_adv 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-short-resource-names" name="short-resource-names" value="true"/> 
debug: debug3: fsa_dump_actions: Action 0080000000000000 (A_READCONFIG) Cleared Actions 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: debug3: fsa_dump_actions: Action 0000000000000002 (A_STARTED) Cleared Actions 
debug: <nvpair id="cib-bootstrap-options-transition-idle-timeout" name="transition-idle-timeout" value="5min"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: fsa_dump_actions: Action 0100000000000000 (A_LRM_CONNECT) Cleared Actions 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-default-action-timeout" name="default-action-timeout" value="20s"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug3: fsa_dump_actions: Action 0000001000000000 (A_CCM_CONNECT) Cleared Actions 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-is-managed-default" name="is-managed-default" value="true"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: s_crmd_fsa: actions:trace: // FSA input: State=S_STOPPING Cause=C_STARTUP Input=I_NULL Origin=register_fsa_error_adv() id=2 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-cluster-delay" name="cluster-delay" value="60s"/> 
crmd[14877]: 2010/12/10_15:14:28 debug: debug2: s_crmd_fsa: Exiting the FSA 
cib[14871]: 2010/12/10_15:14:28 crmd[14877]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-pe-error-series-max" name="pe-error-series-max" value="-1"/> 
debug: fsa_dump_inputs: Added input: 0000000000000004 (R_SHUTDOWN) 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="cib-bootstrap-options-pe-warn-series-max" name="pe-warn-series-max" value="-1"/> 
debug: fsa_dump_inputs: Added input: 0000000000000100 (R_CIB_CONNECTED) 
crmd[14877]: 2010/12/10_15:14:28 cib[14871]: 2010/12/10_15:14:28 ERROR: crmd_init: Startup of crmd failed. Current state: S_STOPPING 
debug: <nvpair id="cib-bootstrap-options-pe-input-series-max" name="pe-input-series-max" value="-1"/> 
crmd[14877]: 2010/12/10_15:14:28 info: crmd_init: [crmd] stopped (1) 
cib[14871]: 2010/12/10_15:14:28 debug: </attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: </cluster_property_set> 
cib[14871]: 2010/12/10_15:14:28 debug: </crm_config> 
cib[14871]: 2010/12/10_15:14:28 debug: <nodes/> 
cib[14871]: 2010/12/10_15:14:28 debug: <resources> 
cib[14871]: 2010/12/10_15:14:28 debug: <group id="group_1"> 
cib[14871]: 2010/12/10_15:14:28 debug: <primitive class="ocf" id="IPaddr_200_16_97_6" provider="heartbeat" type="IPaddr"> 
cib[14871]: 2010/12/10_15:14:28 debug: <operations> 
cib[14871]: 2010/12/10_15:14:28 debug: <op id="IPaddr_200_16_97_6_mon" interval="5s" name="monitor" timeout="5s"/> 
cib[14871]: 2010/12/10_15:14:28 debug: </operations> 
cib[14871]: 2010/12/10_15:14:28 debug: <instance_attributes id="IPaddr_200_16_97_6_inst_attr"> 
cib[14871]: 2010/12/10_15:14:28 debug: <attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="IPaddr_200_16_97_6_attr_0" name="ip" value="200.16.97.6"/> 
cib[14871]: 2010/12/10_15:14:28 debug: </attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: </instance_attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: </primitive> 
cib[14871]: 2010/12/10_15:14:28 debug: <primitive class="ocf" id="IPaddr_200_16_98_6" provider="heartbeat" type="IPaddr"> 
cib[14871]: 2010/12/10_15:14:28 debug: <operations> 
cib[14871]: 2010/12/10_15:14:28 debug: <op id="IPaddr_200_16_98_6_mon" interval="5s" name="monitor" timeout="5s"/> 
cib[14871]: 2010/12/10_15:14:28 debug: </operations> 
cib[14871]: 2010/12/10_15:14:28 debug: <instance_attributes id="IPaddr_200_16_98_6_inst_attr"> 
cib[14871]: 2010/12/10_15:14:28 debug: <attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: <nvpair id="IPaddr_200_16_98_6_attr_0" name="ip" value="200.16.98.6"/> 
cib[14871]: 2010/12/10_15:14:28 debug: </attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: </instance_attributes> 
cib[14871]: 2010/12/10_15:14:28 debug: </primitive> 
cib[14871]: 2010/12/10_15:14:28 debug: <primitive class="heartbeat" id="jail_3" provider="heartbeat" type="jail"> 
cib[14871]: 2010/12/10_15:14:28 debug: <operations> 
cib[14871]: 2010/12/10_15:14:28 debug: <op id="jail_3_mon" interval="120s" name="monitor" timeout="60s"/> 
cib[14871]: 2010/12/10_15:14:28 debug: </operations> 
cib[14871]: 2010/12/10_15:14:28 debug: </primitive> 
cib[14871]: 2010/12/10_15:14:28 debug: </group> 
cib[14871]: 2010/12/10_15:14:28 debug: </resources> 
cib[14871]: 2010/12/10_15:14:28 debug: <constraints> 
cib[14871]: 2010/12/10_15:14:28 debug: <rsc_location id="rsc_location_group_1" rsc="group_1"> 
cib[14871]: 2010/12/10_15:14:28 debug: <rule id="prefered_location_group_1" score="100"> 
cib[14871]: 2010/12/10_15:14:28 debug: <expression attribute="#uname" id="prefered_location_group_1_expr" operation="eq" value="mrefns09.mrec.ar"/> 
cib[14871]: 2010/12/10_15:14:28 debug: </rule> 
cib[14871]: 2010/12/10_15:14:28 debug: </rsc_location> 
cib[14871]: 2010/12/10_15:14:28 debug: </constraints> 
cib[14871]: 2010/12/10_15:14:28 debug: </configuration> 
cib[14871]: 2010/12/10_15:14:28 debug: <status/> 
cib[14871]: 2010/12/10_15:14:28 debug: </cib> 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_process_request: Completed slave update 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_common_callback: Processed 1 messages 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_common_callback: Callback for 4821470c-0aac-4bd6-9d5b-f4a15fdd063c on cib_rw channel 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_common_callback: Processed 0 messages 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_common_callback: Client disconnected 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_process_disconnect: Cleaning up after client disconnect: -1/cib_rw/4821470c-0aac-4bd6-9d5b-f4a15fdd063c 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_ipc_connection_destroy: Destroying -1 (0x802841958) 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_ipc_connection_destroy: Num unfree'd clients: 1 

[root at mrefns09 /usr/local/lib/heartbeat]# cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_null_callback: Client disconnected 

cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_process_disconnect: Cleaning up after client disconnect: crmd/cib_callback/e87ceee6-3043-4c2d-b183-b3adeca43683 
cib[14871]: 2010/12/10_15:14:28 debug: debug3: cib_ipc_connection_destroy: Destroying crmd (0x802841dd8) 
cib[14871]: 2010/12/10_15:14:28 debug: debug2: cib_ipc_connection_destroy: Num unfree'd clients: 0 


If I'm not mistaken, running as root allos CIB/CRMD to speak through socket, but if they are run through the rc script, they can't, even though the socket has 

[root at mrefns09 /var/run/heartbeat/crm]# ls -lrtah 
total 4 
srwxrwxrwx 1 hacluster haclient 0B Dec 10 15:13 cib_rw_syncronous 
srwxrwxrwx 1 hacluster haclient 0B Dec 10 15:13 cib_rw 
srwxrwxrwx 1 hacluster haclient 0B Dec 10 15:13 cib_ro_syncronous 
srwxrwxrwx 1 hacluster haclient 0B Dec 10 15:13 cib_ro 
srwxrwxrwx 1 hacluster haclient 0B Dec 10 15:13 cib_callback 
drwxr-x--- 2 hacluster haclient 512B Dec 10 15:13 . 
drwxr-xr-x 6 hacluster haclient 512B Dec 10 15:21 .. 

Since both processes are started by the heartbeat binary, it's not an option to change the rc script to run both binaries by hand.. 

Any suggestions? 

Kind Regards, 

Kevin Mai 

Dirección de Tecnologías de la Información 
y las Comunicaciones Asociadas 

Ministerio de Relaciones Exteriores, Comercio Internacional y Culto 
Esmeralda 1212 Piso 3 
Tel: +54 011 5555-8900 (int. 3077) 



More information about the freebsd-questions mailing list