[Pacemaker] Oracle instance problem

Sucheta sucheta at ee.iitb.ac.in
Wed Jan 9 05:08:08 EST 2013


Hi,

Following is the oracle instance startup problem.

I am able to successfully start oracle listener using LCMC. However when i
tried to start oracle instance the start process seems to continue for ever
and ever. The database version used is oracle 10gR2. Please find the logs
and version details specified below. Please help me in this regards.


pacemaker : pacemaker 1.1.7-6-el6.x86_64
corosync : corosync 1.4.1-7.el6_3.1.x86_64
LCMC : 1.4.5



*following is the system log.*

Jan  9 09:23:18 VirtKirchoff pengine[7561]:   notice: LogActions: Start
res_oracle_1#011(VirtKirchoff)
Jan  9 09:23:18 VirtKirchoff crmd[7562]:     info: te_rsc_command:
Initiating action 71: start res_oracle_1_start_0 on VirtKirchoff (local)
Jan  9 09:23:18 VirtKirchoff lrmd: [7559]: info: rsc:res_oracle_1:33: start
Jan  9 09:23:18 VirtKirchoff crmd[7562]:     info: handle_failcount_op:
Removing failcount for res_oracle_1
Jan  9 09:23:18 VirtKirchoff attrd[7560]:   notice: attrd_trigger_update:
Sending flush op to all hosts for: fail-count-res_oracle_1 (<null>)
Jan  9 09:23:18 VirtKirchoff cib[7557]:     info: cib_process_request:
Operation complete: op cib_delete for section
//node_state[@uname='VirtKirchoff']//lrm_resource[@id='res_oracle_1']/lrm_rsc_op[@id='res_oracle_1_last_failure_0']
(origin=local/crmd/99, version=0.267.12): ok (rc=0)
Jan  9 09:23:18 VirtKirchoff crmd[7562]:     info: abort_transition_graph:
te_update_diff:320 - Triggered transition abort (complete=0,
tag=lrm_rsc_op, id=res_oracle_1_last_failure_0,
magic=0:1;71:8:0:b1f3b4d6-6433-4642-91c6-810b06f62afc, cib=0.267.12) :
Resource op removal
Jan  9 09:23:18 VirtKirchoff attrd[7560]:   notice: attrd_perform_update:
Sent delete 47: node=VirtKirchoff, attr=fail-count-res_oracle_1, id=<n/a>,
set=(null), section=status
Jan  9 09:23:18 VirtKirchoff attrd[7560]:   notice: attrd_trigger_update:
Sending flush op to all hosts for: last-failure-res_oracle_1 (<null>)
Jan  9 09:23:18 VirtKirchoff attrd[7560]:   notice: attrd_perform_update:
Sent delete 49: node=VirtKirchoff, attr=last-failure-res_oracle_1,
id=<n/a>, set=(null), section=status
Jan  9 09:23:18 VirtKirchoff attrd[7560]:   notice: attrd_perform_update:
Sent delete -22: node=VirtKirchoff, attr=fail-count-res_oracle_1, id=<n/a>,
set=(null), section=status
Jan  9 09:23:18 VirtKirchoff attrd[7560]:   notice: attrd_perform_update:
Sent delete -22: node=VirtKirchoff, attr=last-failure-res_oracle_1,
id=<n/a>, set=(null), section=status
Jan  9 09:23:19 VirtKirchoff oracle(res_oracle_1)[13746]: INFO: ORA-01081
error found, trying to cleanup oracle (dbstart_mount output: ORA-01081:
cannot start already-running ORACLE - shut it down first)
Jan  9 09:23:19 VirtKirchoff lrmd: [7559]: info: RA output:
(res_oracle_1:start:stderr) ls: cannot access
/u01/app/oracle/product/10.2.0/db_1/dbs/lk*: No such file or directory
Jan  9 09:23:19 VirtKirchoff oracle(res_oracle_1)[13746]: ERROR: oracle
ORCL can not be mounted (status: OPEN)
Jan  9 09:23:19 VirtKirchoff crmd[7562]:     info: process_lrm_event: LRM
operation res_oracle_1_start_0 (call=33, rc=1, cib-update=100,
confirmed=true) unknown error
Jan  9 09:23:19 VirtKirchoff crmd[7562]:  warning: status_from_rc: Action
71 (res_oracle_1_start_0) on VirtKirchoff failed (target: 0 vs. rc: 1):
Error
Jan  9 09:23:19 VirtKirchoff crmd[7562]:  warning: update_failcount:
Updating failcount for res_oracle_1 on VirtKirchoff after failed start:
rc=1 (update=value++, time=1357703599)
Jan  9 09:23:19 VirtKirchoff crmd[7562]:     info: abort_transition_graph:
match_graph_event:277 - Triggered transition abort (complete=0,
tag=lrm_rsc_op, id=res_oracle_1_last_failure_0,
magic=0:1;71:12:0:b1f3b4d6-6433-4642-91c6-810b06f62afc, cib=0.267.15) :
Event failed
Jan  9 09:23:19 VirtKirchoff attrd[7560]:   notice: attrd_trigger_update:
Sending flush op to all hosts for: fail-count-res_oracle_1 (1)
Jan  9 09:23:19 VirtKirchoff attrd[7560]:   notice: attrd_perform_update:
Sent update 54: fail-count-res_oracle_1=1
Jan  9 09:23:19 VirtKirchoff attrd[7560]:   notice: attrd_trigger_update:
Sending flush op to all hosts for: last-failure-res_oracle_1 (1357703599)
Jan  9 09:23:19 VirtKirchoff crmd[7562]:     info: abort_transition_graph:
te_update_diff:176 - Triggered transition abort (complete=1, tag=nvpair,
id=status-VirtKirchoff-fail-count-res_oracle_1,
name=fail-count-res_oracle_1, value=1, magic=NA, cib=0.267.16) : Transient
attribute: update
Jan  9 09:23:19 VirtKirchoff attrd[7560]:   notice: attrd_perform_update:
Sent update 57: last-failure-res_oracle_1=1357703599
Jan  9 09:23:19 VirtKirchoff crmd[7562]:     info: abort_transition_graph:
te_update_diff:176 - Triggered transition abort (complete=1, tag=nvpair,
id=status-VirtKirchoff-last-failure-res_oracle_1,
name=last-failure-res_oracle_1, value=1357703599, magic=NA, cib=0.267.17) :
Transient attribute: update
Jan  9 09:23:19 VirtKirchoff pengine[7561]:  warning: unpack_rsc_op:
Processing failed op res_oracle_1_last_failure_0 on VirtKirchoff: unknown
error (1)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:   notice: LogActions: Recover
res_oracle_1#011(Started VirtKirchoff)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:  warning: unpack_rsc_op:
Processing failed op res_oracle_1_last_failure_0 on VirtKirchoff: unknown
error (1)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:  warning:
common_apply_stickiness: Forcing res_oracle_1 away from VirtKirchoff after
1 failures (max=1)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:   notice: LogActions: Stop
res_oracle_1#011(VirtKirchoff)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:  warning: unpack_rsc_op:
Processing failed op res_oracle_1_last_failure_0 on VirtKirchoff: unknown
error (1)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:  warning:
common_apply_stickiness: Forcing res_oracle_1 away from VirtKirchoff after
1 failures (max=1)
Jan  9 09:23:19 VirtKirchoff pengine[7561]:   notice: LogActions: Stop
res_oracle_1#011(VirtKirchoff)
Jan  9 09:23:19 VirtKirchoff crmd[7562]:     info: te_rsc_command:
Initiating action 4: stop res_oracle_1_stop_0 on VirtKirchoff (local)
Jan  9 09:23:19 VirtKirchoff lrmd: [7559]: info: rsc:res_oracle_1:34: stop
Jan  9 09:23:19 VirtKirchoff oracle(res_oracle_1)[13870]: INFO: Oracle
instance ORCL already stopped
Jan  9 09:23:19 VirtKirchoff crmd[7562]:     info: process_lrm_event: LRM
operation res_oracle_1_stop_0 (call=34, rc=0, cib-update=104,
confirmed=true) ok

*Following is corosync log*


Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info: cib:diff:
+         </instance_attributes>
Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info: cib:diff:
+       </node>
Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info: cib:diff:
+     </nodes>
Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info: cib:diff:     +
</configuration>
Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info: cib:diff:     +
</cib>
Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info:
cib_process_request:     Operation complete: op cib_modify for section
nodes (origin=local/crm_attribute/4, version=0.269.1): ok (rc=0)
Jan 09 09:30:25 [7557] VirtKirchoff        cib:     info:
set_crm_log_level:     New log level: 3 0
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:   notice: unpack_config:
    On loss of CCM Quorum: Ignore
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:  warning: unpack_nodes:
Blind faith: not fencing unseen nodes
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:   notice: unpack_rsc_op:
    Operation monitor found resource res_drbd_1:0 active on VirtTesla
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:   notice: unpack_rsc_op:
    Operation monitor found resource res_drbd_2:0 active on VirtTesla
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:   notice: LogActions:
Start   res_drbd_1:1    (VirtTesla)
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:   notice: LogActions:
Start   res_drbd_2:1    (VirtTesla)
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_POLICY_ENGINE ->
S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE
origin=handle_response ]
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: do_te_invoke:
Processing graph 26 (ref=pe_calc-dc-1357704025-87) derived from
/var/lib/pengine/pe-input-3344.bz2
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 80: notify res_drbd_1:0_pre_notify_start_0 on
VirtKirchoff (local)
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: rsc:res_drbd_1:0:35: notify
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 91: notify res_drbd_2:0_pre_notify_start_0 on
VirtKirchoff (local)
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: rsc:res_drbd_2:0:36: notify
Jan 09 09:30:25 [7561] VirtKirchoff    pengine:   notice:
process_pe_message:     Transition 26: PEngine Input stored in:
/var/lib/pengine/pe-input-3344.bz2
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: RA output:
(res_drbd_1:0:notify:stdout)

Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info:
process_lrm_event:     LRM operation res_drbd_1:0_notify_0 (call=35, rc=0,
cib-update=0, confirmed=true) ok
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 12: start res_drbd_1:1_start_0 on VirtTesla
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: RA output:
(res_drbd_2:0:notify:stdout) drbdsetup disk-options 1 --set-defaults
--resync-rate=250M --c-max-rate=1024000K --c-min-rate=250M

Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info:
process_lrm_event:     LRM operation res_drbd_2:0_notify_0 (call=36, rc=0,
cib-update=0, confirmed=true) ok
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 44: start res_drbd_2:1_start_0 on VirtTesla
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 81: notify res_drbd_1:0_post_notify_start_0 on
VirtKirchoff (local)
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: rsc:res_drbd_1:0:37: notify
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 82: notify res_drbd_1:1_post_notify_start_0 on
VirtTesla
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 92: notify res_drbd_2:0_post_notify_start_0 on
VirtKirchoff (local)
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: rsc:res_drbd_2:0:38: notify
Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 93: notify res_drbd_2:1_post_notify_start_0 on
VirtTesla
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: RA output:
(res_drbd_1:0:notify:stdout)

Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info:
process_lrm_event:     LRM operation res_drbd_1:0_notify_0 (call=37, rc=0,
cib-update=0, confirmed=true) ok
Jan 09 09:30:25 VirtKirchoff lrmd: [7559]: info: RA output:
(res_drbd_2:0:notify:stdout)

Jan 09 09:30:25 [7562] VirtKirchoff       crmd:     info:
process_lrm_event:     LRM operation res_drbd_2:0_notify_0 (call=38, rc=0,
cib-update=0, confirmed=true) ok
Jan 09 09:30:26 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 13: monitor res_drbd_1:1_monitor_10000 on VirtTesla
Jan 09 09:30:26 [7562] VirtKirchoff       crmd:     info: te_rsc_command:
    Initiating action 45: monitor res_drbd_2:1_monitor_10000 on VirtTesla
Jan 09 09:30:26 [7562] VirtKirchoff       crmd:   notice: run_graph:
==== Transition 26 (Complete=22, Pending=0, Fired=0, Skipped=0,
Incomplete=0, Source=/var/lib/pengine/pe-input-3344.bz2): Complete
Jan 09 09:30:26 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_TRANSITION_ENGINE -> S_IDLE [
input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
Jan 09 09:30:56 [7562] VirtKirchoff       crmd:     info:
abort_transition_graph:     te_update_diff:176 - Triggered transition abort
(complete=1, tag=nvpair, id=status-VirtTesla-master-res_drbd_2.1,
name=master-res_drbd_2:1, value=5, magic=NA, cib=0.269.6) : Transient
attribute: update
Jan 09 09:30:56 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_IDLE -> S_POLICY_ENGINE [
input=I_PE_CALC cause=C_FSA_INTERNAL origin=abort_transition_graph ]
Jan 09 09:30:56 [7561] VirtKirchoff    pengine:   notice: unpack_config:
    On loss of CCM Quorum: Ignore
Jan 09 09:30:56 [7561] VirtKirchoff    pengine:  warning: unpack_nodes:
Blind faith: not fencing unseen nodes
Jan 09 09:30:56 [7561] VirtKirchoff    pengine:   notice: unpack_rsc_op:
    Operation monitor found resource res_drbd_1:0 active on VirtTesla
Jan 09 09:30:56 [7561] VirtKirchoff    pengine:   notice: unpack_rsc_op:
    Operation monitor found resource res_drbd_2:0 active on VirtTesla
Jan 09 09:30:56 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_POLICY_ENGINE ->
S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE
origin=handle_response ]
Jan 09 09:30:56 [7562] VirtKirchoff       crmd:     info: do_te_invoke:
Processing graph 27 (ref=pe_calc-dc-1357704056-102) derived from
/var/lib/pengine/pe-input-3345.bz2
Jan 09 09:30:56 [7562] VirtKirchoff       crmd:   notice: run_graph:
==== Transition 27 (Complete=0, Pending=0, Fired=0, Skipped=0,
Incomplete=0, Source=/var/lib/pengine/pe-input-3345.bz2): Complete
Jan 09 09:30:56 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_TRANSITION_ENGINE -> S_IDLE [
input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
Jan 09 09:30:56 [7561] VirtKirchoff    pengine:   notice:
process_pe_message:     Transition 27: PEngine Input stored in:
/var/lib/pengine/pe-input-3345.bz2
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:     info: crm_timer_popped:
    PEngine Recheck Timer (I_PE_CALC) just popped (60000ms)
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_IDLE -> S_POLICY_ENGINE [
input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ]
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:     info:
do_state_transition:     Progressed to state S_POLICY_ENGINE after
C_TIMER_POPPED
Jan 09 09:31:56 [7561] VirtKirchoff    pengine:   notice: unpack_config:
    On loss of CCM Quorum: Ignore
Jan 09 09:31:56 [7561] VirtKirchoff    pengine:  warning: unpack_nodes:
Blind faith: not fencing unseen nodes
Jan 09 09:31:56 [7561] VirtKirchoff    pengine:   notice: unpack_rsc_op:
    Operation monitor found resource res_drbd_1:0 active on VirtTesla
Jan 09 09:31:56 [7561] VirtKirchoff    pengine:   notice: unpack_rsc_op:
    Operation monitor found resource res_drbd_2:0 active on VirtTesla
Jan 09 09:31:56 [7561] VirtKirchoff    pengine:   notice:
process_pe_message:     Transition 28: PEngine Input stored in:
/var/lib/pengine/pe-input-3345.bz2
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_POLICY_ENGINE ->
S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE
origin=handle_response ]
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:     info: do_te_invoke:
Processing graph 28 (ref=pe_calc-dc-1357704116-103) derived from
/var/lib/pengine/pe-input-3345.bz2
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:   notice: run_graph:
==== Transition 28 (Complete=0, Pending=0, Fired=0, Skipped=0,
Incomplete=0, Source=/var/lib/pengine/pe-input-3345.bz2): Complete
Jan 09 09:31:56 [7562] VirtKirchoff       crmd:   notice:
do_state_transition:     State transition S_TRANSITION_ENGINE -> S_IDLE [
input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]



Thanks & Regards,
sucheta
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.clusterlabs.org/pipermail/pacemaker/attachments/20130109/62bf6b82/attachment-0002.html>


More information about the Pacemaker mailing list