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
[r...@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
[r...@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
[r...@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
[r...@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)
_______________________________________________
Linux-HA mailing list
Linux-HA@lists.linux-ha.org
http://lists.linux-ha.org/mailman/listinfo/linux-ha
See also: http://linux-ha.org/ReportingProblems
