[Pacemaker] Managing DRBD Dual Primary with Pacemaker always initial Split Brains
Felix Zachlod
fz.lists at sis-gmbh.info
Thu Oct 2 13:53:40 UTC 2014
Am 02.10.2014 08:44, schrieb Felix Zachlod:
> Am 01.10.2014 20:46, schrieb Digimer:
>>
>> At some point along the way, both nodes were Primary while not
>> connected, even if for just a moment. Your log snippet above shows the
>> results of this break, they do not appear to speak to the break itself.
>
> Even easier to reproduce is the problem when I try stop stop a drbd
> resource and later restart it this always leads to a split brain.
Here I attach debug log files from pacemaker of both nodes while I ran
resource stop
resource start
As you can see the resource comes indeed up into Standby first but is
immediately promoted to Primary on both hosts (afterwards the brain is
split which you can't see here in the log). I cannot see anywhere in the
log that pacemaker is getting information from the RA about a successful
connection. I asumme this is the problem here (or that pacemaker is not
waiting for the next monitor run at least).
demote resource
(connect)
promote resource does help btw.
It demotes to standby/unknown on both sides. Than my manual connect
triggers a resync and after that the resource can be promoted without a
problem.
Furthermore here is my complete cluster config (for the moment there is
nothing but the DRDB Resources, Stonith and the clvmd/dlm.
node storage-test-c \
attributes standby="off"
node storage-test-d \
attributes standby="off"
node storage-voter
primitive drbd_testdata1 ocf:linbit:drbd \
params drbd_resource="testdata1" adjust_master_score="0 10 1000
10000" stop_outdates_secondary="true" \
op monitor interval="29s" role="Master" \
op monitor interval="31s" role="Slave"
primitive drbd_testdata2 ocf:linbit:drbd \
params drbd_resource="testdata2" adjust_master_score="0 10 1000
10000" stop_outdates_secondary="true" \
op monitor interval="29s" role="Master" \
op monitor interval="31s" role="Slave"
primitive p-clvm ocf:lvm2:clvmd \
params daemon_timeout="30" \
op monitor interval="60" timeout="30" \
op start interval="0" timeout="90" \
op stop interval="0" timeout="100"
primitive p-dlm ocf:pacemaker:controld \
op monitor interval="120" timeout="30" \
op start interval="0" timeout="90" \
op stop interval="0" timeout="100"
primitive st-storage-test-c stonith:external/ipmi \
params hostname="storage-test-c" ipaddr="10.1.22.51"
userid="ADMIN" passwd="ADMIN" \
op monitor interval="30" timeout="20"
primitive st-storage-test-d stonith:external/ipmi \
params hostname="storage-test-d" ipaddr="10.1.22.52"
userid="ADMIN" passwd="ADMIN" \
op monitor interval="30" timeout="20"
group g_locking p-dlm p-clvm
ms ms_drbd_testdata1 drbd_testdata1 \
meta master-max="2" master-node-max="1" clone-max="2"
clone-node-max="1" notify="true" target-role="Slave"
ms ms_drbd_testdata2 drbd_testdata2 \
meta master-max="2" master-node-max="1" clone-max="2"
clone-node-max="1" notify="true" target-role="Started"
clone c_locking g_locking \
meta clone-max="2" clone-node-max="1" globally-unique="false"
interleave="true"
clone cl_st-storage-test-c st-storage-test-c \
meta clone-max="2" clone-node-max="1"
clone cl_st-storage-test-d st-storage-test-d \
meta clone-max="2" clone-node-max="1"
location l-drbd-testdata2 ms_drbd_testdata2 \
rule $id="l-drbd-testdata2-rule" 0: #uname eq storage-test-d or
#uname eq storage-test-c
location l-drbd1 ms_drbd_testdata1 \
rule $id="l-drbd1-rule" 0: #uname eq storage-test-d or #uname
eq storage-test-c
location l-locking c_locking \
rule $id="l-locking-rule" 0: #uname eq storage-test-d or #uname
eq storage-test-c
location l-st-stc cl_st-storage-test-c \
rule $id="l-st-stc-rule" 0: #uname eq storage-test-d or #uname
eq storage-voter
location l-st-std cl_st-storage-test-d \
rule $id="l-st-std-rule" 0: #uname eq storage-test-c or #uname
eq storage-voter
property $id="cib-bootstrap-options" \
dc-version="1.1.7-ee0730e13d124c3d58f00016c3376a1de5323cff" \
cluster-infrastructure="openais" \
last-lrm-refresh="1412185414" \
maintenance-mode="false" \
expected-quorum-votes="3" \
symmetric-cluster="false" \
stonith-action="poweroff"
Any help would be greatly appreciated.
regards, Felix
-------------- next part --------------
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a1 to 7a3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a2 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a3 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7a3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a3 to 7a4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a4 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a4 to 7a5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a5 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a5 to 7a6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a6 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7a6
Oct 2 15:32:48 storage-test-c cib: [2736]: debug: activateCibXml: Triggering CIB write for cib_apply_diff op
Oct 2 15:32:48 storage-test-c cib: [2736]: debug: Forking temp process write_cib_contents
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a6 to 7a7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a7 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a7 to 7a8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a8 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a8 to 7a9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7a9 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7aa
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7a9 to 7aa
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7aa to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7aa
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7aa
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=143:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_notify_0
Oct 2 15:32:48 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation notify[90] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 100 to the operation list.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 notify[90] (pid 13668)
Oct 2 15:32:48 storage-test-c lrmd: [13668]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:notify process 13668 exited with return code 0.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: operation notify[90] on drbd_testdata2:0 for client 2741: pid 13668 exited with return code 0
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete notify op (interval=0)
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_notify_0 from 143:271:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256768-64
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_notify_0 (call=90, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7aa to 7ac
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ab to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ac to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ab
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ab
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ac
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ac
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7ac
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ad
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ac to 7ad
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ad to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ae
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ad to 7ae
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ae to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ad
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ae
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7ae
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7af
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ae to 7af
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7af to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7af to 7b0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b0 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7af
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b1
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b0 to 7b1
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b1 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b1
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: cancel_op: Cancelling op 89 for drbd_testdata2:0 (drbd_testdata2:0:89)
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b1 to 7b2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b2 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7b1
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: cancel_op: operation monitor[89] on drbd_testdata2:0 for client 2741, its parameters: drbd_resource=[testdata2] CRM_meta_role=[Master] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_inactive_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_master_uname=[ ] CRM_meta_name=[monitor] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[storage-test-c storage-test-d ] cancelled
Oct 2 15:32:48 storage-test-c lrmd: [2738]: debug: on_msg_cancel_op: operation 89 cancelled
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: cancel_op: Op 89 for drbd_testdata2:0 (drbd_testdata2:0:89): cancelled
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=78:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_demote_0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7b2
Oct 2 15:32:48 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation demote[91] on drbd_testdata2:0 for client 2741, its parameters: drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_timeout=[20000] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_notify_start_resource=[ ] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 100 to the operation list.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 demote[91] (pid 13690)
Oct 2 15:32:48 storage-test-c lrmd: [13690]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_monitor_29000 (call=89, status=1, cib-update=0, confirmed=true) Cancelled
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: update_history_cache: Appending monitor op to history for 'drbd_testdata2:0'
Oct 2 15:32:48 storage-test-c drbd[13690]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf secondary testdata2
Oct 2 15:32:48 storage-test-c cib: [2736]: info: Managed write_cib_contents process 13667 exited with return code 0.
Oct 2 15:32:48 storage-test-c drbd[13690]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:48 storage-test-c drbd[13690]: DEBUG: testdata2: Command output:
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:demote:stdout)
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:demote process 13690 exited with return code 0.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: operation demote[91] on drbd_testdata2:0 for client 2741: pid 13690 exited with return code 0
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:0 after complete demote op (interval=0)
Oct 2 15:32:48 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_demote_0 (call=91, rc=0, cib-update=79, confirmed=true) ok
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: update_history_cache: Appending demote op to history for 'drbd_testdata2:0'
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b2 to 7b4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b3 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b4 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7b4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b4 to 7b5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b5 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b5 to 7b6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b6 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b6 to 7b7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b7 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7b7
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b7 to 7b8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b8 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b8 to 7b9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7b9 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7b9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ba
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7b9 to 7ba
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ba to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bb
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ba to 7bb
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7bb to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ba
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7bb to 7bc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7bc to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bd
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7bc to 7bd
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7bd to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bb
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bd
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=144:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_notify_0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7be
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7bd to 7be
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7be to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7be
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bf
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7be to 7bf
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7bf to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bf
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7bf to 7c0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c0 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7bd
Oct 2 15:32:48 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation notify[92] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 100 to the operation list.
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7c0
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 notify[92] (pid 13730)
Oct 2 15:32:48 storage-test-c lrmd: [13730]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:48 storage-test-c drbd[13730]: DEBUG: testdata2: Calling /usr/sbin/crm_master -Q -l reboot -v 10000
Oct 2 15:32:48 storage-test-c attrd: [2739]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:0=10000
Oct 2 15:32:48 storage-test-c attrd: [2739]: debug: attrd_local_callback: Supplied: 10000, Current: 10000, Stored: 10000
Oct 2 15:32:48 storage-test-c drbd[13730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:48 storage-test-c drbd[13730]: DEBUG: testdata2: Command output:
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:notify:stdout)
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:notify process 13730 exited with return code 0.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: operation notify[92] on drbd_testdata2:0 for client 2741: pid 13730 exited with return code 0
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete notify op (interval=0)
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_notify_0 from 144:271:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256768-65
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_notify_0 (call=92, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c0 to 7c2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c1 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c2 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c1
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c1
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7c2
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c2 to 7c3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c3 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c3 to 7c4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c4 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c3
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7c4
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c4 to 7c5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c5 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c5 to 7c6
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c6 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c5
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c6
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=141:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_notify_0
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c6 to 7c7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c7 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c7
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c7 to 7c8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c8 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c8
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7c6
Oct 2 15:32:48 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation notify[93] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 100 to the operation list.
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7c8
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 notify[93] (pid 13769)
Oct 2 15:32:48 storage-test-c lrmd: [13769]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:notify process 13769 exited with return code 0.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: operation notify[93] on drbd_testdata2:0 for client 2741: pid 13769 exited with return code 0
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete notify op (interval=0)
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_notify_0 from 141:271:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256768-66
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_notify_0 (call=93, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7c8 to 7ca
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7c9 to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ca to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c9
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ca
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ca
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7ca
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cb
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ca to 7cb
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7cb to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7cb to 7cc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7cc to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cb
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7cc
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cd
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7cc to 7cd
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7cd to pending delivery queue
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ce
Oct 2 15:32:48 storage-test-c corosync[2515]: [TOTEM ] Delivering 7cd to 7ce
Oct 2 15:32:48 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=79:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_stop_0
Oct 2 15:32:48 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation stop[94] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[ ] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] CRM_meta_notify_start_uname=[ ] CRM_meta_clone_node_max=[1] CRM_meta_notify=[true] CRM_meta_n to the operation list.
Oct 2 15:32:48 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 stop[94] (pid 13791)
Oct 2 15:32:48 storage-test-c lrmd: [13791]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-c drbd[13791]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf down testdata2
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Command output:
Oct 2 15:32:49 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:stop:stdout)
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf down testdata2
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Command output:
Oct 2 15:32:49 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:stop:stdout)
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Calling /usr/sbin/crm_master -l reboot -D
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:0=<null>
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: attrd_local_callback: Supplied: (null), Current: 10000, Stored: 10000
Oct 2 15:32:49 storage-test-c attrd: [2739]: notice: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_testdata2:0 (<null>)
Oct 2 15:32:49 storage-test-c cib: [2736]: debug: cib_process_xpath: Processing cib_query op for //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] (/cib/status/node_state[2]/transient_attributes/instance_attributes/nvpair[3])
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: find_nvpair_attr_delegate: Match <nvpair id="status-storage-test-c-master-drbd_testdata2.0" name="master-drbd_testdata2:0" value="10000" />
Oct 2 15:32:49 storage-test-c attrd: [2739]: notice: attrd_perform_update: Sent delete 112: node=storage-test-c, attr=master-drbd_testdata2:0, id=<n/a>, set=(null), section=status
Oct 2 15:32:49 storage-test-c cib: [2736]: debug: cib_process_xpath: Processing cib_query op for //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] (/cib/status/node_state[2]/transient_attributes/instance_attributes/nvpair[3])
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: find_nvpair_attr_delegate: Match <nvpair id="status-storage-test-c-master-drbd_testdata2.0" name="master-drbd_testdata2:0" value="10000" />
Oct 2 15:32:49 storage-test-c attrd: [2739]: notice: attrd_perform_update: Sent delete 114: node=storage-test-c, attr=master-drbd_testdata2:0, id=<n/a>, set=(null), section=status
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update 112 for master-drbd_testdata2:0=(null) passed
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-c drbd[13791]: DEBUG: testdata2: Command output:
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update 114 for master-drbd_testdata2:0=(null) passed
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:stop:stdout)
Oct 2 15:32:49 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:stop process 13791 exited with return code 0.
Oct 2 15:32:49 storage-test-c lrmd: [2738]: info: operation stop[94] on drbd_testdata2:0 for client 2741: pid 13791 exited with return code 0
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:0 after complete stop op (interval=0)
Oct 2 15:32:49 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_stop_0 (call=94, rc=0, cib-update=80, confirmed=true) ok
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: update_history_cache: Appending stop op to history for 'drbd_testdata2:0'
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-c cib: [2736]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] does not exist
Oct 2 15:32:49 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update -22 for master-drbd_testdata2:1=(null) passed
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:54 storage-test-c lrmd: [2738]: debug: rsc:st-storage-test-d:1 monitor[17] (pid 13863)
Oct 2 15:32:54 storage-test-c lrmd: [13863]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:54 storage-test-c lrm-stonith: [13863]: debug: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/crm/st_command
Oct 2 15:32:54 storage-test-c lrm-stonith: [13863]: debug: get_stonith_token: Obtained registration token: 8e46ca9b-4f0d-4615-9885-237c5a3ae580
Oct 2 15:32:54 storage-test-c lrm-stonith: [13863]: debug: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/crm/st_callback
Oct 2 15:32:54 storage-test-c lrm-stonith: [13863]: debug: get_stonith_token: Obtained registration token: 49c5e42d-83f6-441b-af45-1bce18a185d3
Oct 2 15:32:54 storage-test-c stonith-ng: [2737]: debug: stonith_command: Processing register from lrmd ( 0)
Oct 2 15:32:54 storage-test-c lrm-stonith: [13863]: debug: stonith_api_signon: Connection to STONITH successful
Oct 2 15:32:54 storage-test-c stonith-ng: [2737]: debug: stonith_command: Processing st_execute from lrmd ( 1000)
Oct 2 15:32:54 storage-test-c stonith-ng: [2737]: info: stonith_command: Processed st_execute from lrmd: rc=-1
Oct 2 15:32:54 storage-test-c stonith-ng: [2737]: debug: run_stonith_agent: forking
Oct 2 15:32:54 storage-test-c stonith-ng: [2737]: debug: run_stonith_agent: sending args
Oct 2 15:32:54 storage-test-c stonith-ng: [2737]: debug: stonith_device_execute: Operation monitor on st-storage-test-d:1 is active with pid: 13864
Oct 2 15:32:55 storage-test-c stonith: [13865]: info: external/ipmi device OK.
Oct 2 15:32:55 storage-test-c stonith-ng: [2737]: debug: log_operation: Operation 'monitor' [13864] for device 'st-storage-test-d:1' returned: 0
Oct 2 15:32:55 storage-test-c stonith-ng: [2737]: info: log_operation: st-storage-test-d:1: Performing: stonith -t external/ipmi -S
Oct 2 15:32:55 storage-test-c stonith-ng: [2737]: info: log_operation: st-storage-test-d:1: success: 0
Oct 2 15:32:55 storage-test-c stonith-ng: [2737]: debug: log_operation: st-storage-test-d:1: (total 52 bytes)
Oct 2 15:32:55 storage-test-c lrm-stonith: [13863]: debug: execra: st-storage-test-d:1_monitor returned 0
Oct 2 15:32:55 storage-test-c lrm-stonith: [13863]: debug: stonith_api_signoff: Signing out of the STONITH Service
Oct 2 15:32:55 storage-test-c lrmd: [2738]: info: operation monitor[17] on st-storage-test-d:1 for client 2741: pid 13863 exited with return code 0
Oct 2 15:32:56 storage-test-c lrmd: [2738]: debug: rsc:drbd_testdata1:0 monitor[40] (pid 13881)
Oct 2 15:32:56 storage-test-c lrmd: [13881]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:56 storage-test-c drbd[13881]: DEBUG: testdata1: Calling /usr/sbin/crm_master -Q -l reboot -v 10000
Oct 2 15:32:56 storage-test-c attrd: [2739]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata1:0=10000
Oct 2 15:32:56 storage-test-c attrd: [2739]: debug: attrd_local_callback: Supplied: 10000, Current: 10000, Stored: 10000
Oct 2 15:32:56 storage-test-c drbd[13881]: DEBUG: testdata1: Exit code 0
Oct 2 15:32:56 storage-test-c drbd[13881]: DEBUG: testdata1: Command output:
Oct 2 15:32:56 storage-test-c lrmd: [2738]: debug: RA output: (drbd_testdata1:0:monitor:stdout)
Oct 2 15:32:56 storage-test-c lrmd: [2738]: info: operation monitor[40] on drbd_testdata1:0 for client 2741: pid 13881 exited with return code 0
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7e8 to 7ea
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7e9 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ea to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7e9
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7e9
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ea
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ea
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7ea
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7eb
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ea to 7eb
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7eb to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ec
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7eb to 7ec
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ec to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7eb
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ed
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ec to 7ed
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ed to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ec
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ed
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7ed
Oct 2 15:32:57 storage-test-c cib: [2736]: debug: activateCibXml: Triggering CIB write for cib_apply_diff op
Oct 2 15:32:57 storage-test-c cib: [2736]: debug: Forking temp process write_cib_contents
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ee
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ed to 7ee
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ee to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ef
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ee to 7ef
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ef to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ee
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f0
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ef to 7f0
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f0 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f1
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f0 to 7f1
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f1 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ef
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f0
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f1
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7f1
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=74:273:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_start_0
Oct 2 15:32:57 storage-test-c lrmd: [2738]: debug: on_msg_perform_op:2400: copying parameters for rsc drbd_testdata2:0
Oct 2 15:32:57 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation start[95] on drbd_testdata2:0 for client 2741, its parameters: drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[ ] CRM_meta_notify_start_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_inactive_resource=[drbd_testdata2:0 drbd_testdata2:1 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[storage-test- to the operation list.
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 start[95] (pid 13925)
Oct 2 15:32:57 storage-test-c lrmd: [13925]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf check-resize testdata2
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:start:stdout)
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf new-resource testdata2
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:start:stdout)
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf new-minor testdata2
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:start:stdout)
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf --peer storage-test-d attach testdata2
Oct 2 15:32:57 storage-test-c cib: [2736]: info: Managed write_cib_contents process 13924 exited with return code 0.
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:start:stdout)
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf --peer storage-test-d adjust testdata2
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:start:stdout)
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Calling /usr/sbin/crm_master -Q -l reboot -v 1000
Oct 2 15:32:57 storage-test-c attrd: [2739]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:0=1000
Oct 2 15:32:57 storage-test-c attrd: [2739]: debug: attrd_local_callback: Supplied: 1000, Current: (null), Stored: (null)
Oct 2 15:32:57 storage-test-c attrd: [2739]: debug: attrd_local_callback: New value of master-drbd_testdata2:0 is 1000
Oct 2 15:32:57 storage-test-c attrd: [2739]: notice: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_testdata2:0 (1000)
Oct 2 15:32:57 storage-test-c cib: [2736]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] does not exist
Oct 2 15:32:57 storage-test-c cib: [2736]: debug: cib_process_xpath: Processing cib_query op for /cib (/cib)
Oct 2 15:32:57 storage-test-c attrd: [2739]: notice: attrd_perform_update: Sent update 118: master-drbd_testdata2:0=1000
Oct 2 15:32:57 storage-test-c attrd: [2739]: debug: xmlfromIPC: Peer disconnected
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f1 to 7f3
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f2 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f3 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f2
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f2
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f3
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f3
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7f3
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f4
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f3 to 7f4
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f4 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f5
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f4 to 7f5
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f5 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f4
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f5
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7f5
Oct 2 15:32:57 storage-test-c drbd[13925]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update 118 for master-drbd_testdata2:0=1000 passed
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:start:stdout)
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:start process 13925 exited with return code 0.
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: operation start[95] on drbd_testdata2:0 for client 2741: pid 13925 exited with return code 0
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:0 after complete start op (interval=0)
Oct 2 15:32:57 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_start_0 (call=95, rc=0, cib-update=81, confirmed=true) ok
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: update_history_cache: Appending start op to history for 'drbd_testdata2:0'
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f5 to 7f7
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f6 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f7 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f6
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f6
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f7
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f7
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7f7
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f8
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f7 to 7f8
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f8 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f9
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f8 to 7f9
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7f9 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f8
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fa
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7f9 to 7fa
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7fa to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f9
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fa
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7fa
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fb
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7fa to 7fb
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7fb to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fb
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fc
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7fb to 7fc
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7fc to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fc
Oct 2 15:32:57 storage-test-c cib: [2736]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] does not exist
Oct 2 15:32:57 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update -22 for master-drbd_testdata2:1=(null) passed
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7fc
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fd
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7fc to 7fd
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7fd to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fe
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7fd to 7fe
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7fe to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fd
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fe
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 7fe
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ff
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7fe to 7ff
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 7ff to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ff
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 800
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 7ff to 800
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 800 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 800
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 800
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 801
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 800 to 801
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 801 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 802
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 801 to 802
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 802 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 801
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 802
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 803
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 802 to 803
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 803 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 804
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 803 to 804
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=134:273:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_notify_0
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 804 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 803
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 804
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 802
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 805
Oct 2 15:32:57 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation notify[96] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[drbd_testdata2:0 drbd_testdata2:1 ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:0 drbd_testdata2:1 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[storage-test to the operation list.
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 804 to 805
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 805 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 806
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 805 to 806
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 806 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 805
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 807
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 806 to 807
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 807 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 806
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 807
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 803
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 notify[96] (pid 14062)
Oct 2 15:32:57 storage-test-c lrmd: [14062]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 807
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-c drbd[14062]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf --peer storage-test-d -v adjust testdata2
Oct 2 15:32:57 storage-test-c drbd[14062]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-c drbd[14062]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:notify:stdout)
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:notify process 14062 exited with return code 0.
Oct 2 15:32:57 storage-test-c lrmd: [2738]: info: operation notify[96] on drbd_testdata2:0 for client 2741: pid 14062 exited with return code 0
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete notify op (interval=0)
Oct 2 15:32:57 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_notify_0 from 134:273:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256777-67
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_notify_0 (call=96, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering 807 to 809
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 808 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 809 to pending delivery queue
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 808
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 808
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 809
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 809
Oct 2 15:32:57 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 809
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80a
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 809 to 80a
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 80a to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80b
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 80a to 80b
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 80b to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80a
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80b
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 80b
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80c
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 80b to 80c
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 80c to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80d
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 80c to 80d
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 80d to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80c
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80e
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 80d to 80e
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 80e to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80d
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80f
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 80e to 80f
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 80f to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80e
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80f
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=147:274:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_notify_0
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 80f
Oct 2 15:32:58 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation notify[97] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[storage-test-c storage-test-d ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[ ] crm_feature_set=[3.0.6] CRM_me to the operation list.
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 notify[97] (pid 14102)
Oct 2 15:32:58 storage-test-c lrmd: [14102]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:notify process 14102 exited with return code 0.
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: operation notify[97] on drbd_testdata2:0 for client 2741: pid 14102 exited with return code 0
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete notify op (interval=0)
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_notify_0 from 147:274:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-68
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:58 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_notify_0 (call=97, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 80f to 811
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 810 to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 811 to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 810
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 810
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 811
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 811
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 811
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 812
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 811 to 812
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 812 to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 813
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 812 to 813
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 813 to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 812
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 813
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] releasing messages up to and including 813
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 814
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 813 to 814
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering MCAST message with seq 814 to pending delivery queue
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Received ringid(10.1.22.61:80) seq 815
Oct 2 15:32:58 storage-test-c corosync[2515]: [TOTEM ] Delivering 814 to 815
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=77:274:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_promote_0
Oct 2 15:32:58 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation promote[98] on drbd_testdata2:0 for client 2741, its parameters: drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[storage-test-c storage-test-d ] CRM_meta_notify_start_resource=[ ] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[ ] crm_feature_set=[3.0.6] CRM_m to the operation list.
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 promote[98] (pid 14124)
Oct 2 15:32:58 storage-test-c lrmd: [14124]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:58 storage-test-c drbd[14124]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf primary testdata2
Oct 2 15:32:58 storage-test-c drbd[14124]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:58 storage-test-c drbd[14124]: DEBUG: testdata2: Command output:
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:promote:stdout)
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:promote process 14124 exited with return code 0.
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: operation promote[98] on drbd_testdata2:0 for client 2741: pid 14124 exited with return code 0
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:0 after complete promote op (interval=0)
Oct 2 15:32:58 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_promote_0 (call=98, rc=0, cib-update=82, confirmed=true) ok
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: update_history_cache: Appending promote op to history for 'drbd_testdata2:0'
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: do_lrm_rsc_op: Performing key=148:274:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:0_notify_0
Oct 2 15:32:58 storage-test-c lrmd: [2738]: debug: on_msg_perform_op: add an operation operation notify[99] on drbd_testdata2:0 for client 2741, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[storage-test-c storage-test-d ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[ ] crm_feature_set=[3.0.6] CRM_me to the operation list.
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: rsc:drbd_testdata2:0 notify[99] (pid 14166)
Oct 2 15:32:58 storage-test-c lrmd: [14166]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-c drbd[14166]: DEBUG: testdata2: Calling /usr/sbin/crm_master -Q -l reboot -v 10000
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:0=10000
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: attrd_local_callback: Supplied: 10000, Current: 1000, Stored: 1000
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: attrd_local_callback: New value of master-drbd_testdata2:0 is 10000
Oct 2 15:32:58 storage-test-c attrd: [2739]: notice: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_testdata2:0 (10000)
Oct 2 15:32:58 storage-test-c cib: [2736]: debug: cib_process_xpath: Processing cib_query op for //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] (/cib/status/node_state[2]/transient_attributes/instance_attributes/nvpair[3])
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: find_nvpair_attr_delegate: Match <nvpair id="status-storage-test-c-master-drbd_testdata2.0" name="master-drbd_testdata2:0" value="1000" />
Oct 2 15:32:58 storage-test-c attrd: [2739]: notice: attrd_perform_update: Sent update 121: master-drbd_testdata2:0=10000
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: xmlfromIPC: Peer disconnected
Oct 2 15:32:58 storage-test-c drbd[14166]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:58 storage-test-c drbd[14166]: DEBUG: testdata2: Command output:
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: RA output: (drbd_testdata2:0:notify:stdout)
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: Managed drbd_testdata2:0:notify process 14166 exited with return code 0.
Oct 2 15:32:58 storage-test-c lrmd: [2738]: info: operation notify[99] on drbd_testdata2:0 for client 2741: pid 14166 exited with return code 0
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete notify op (interval=0)
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update 121 for master-drbd_testdata2:0=10000 passed
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_notify_0 from 148:274:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-69
Oct 2 15:32:58 storage-test-c crmd: [2741]: info: process_lrm_event: LRM operation drbd_testdata2:0_notify_0 (call=99, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-c cib: [2736]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-c']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] does not exist
Oct 2 15:32:58 storage-test-c attrd: [2739]: debug: attrd_cib_callback: Update -22 for master-drbd_testdata2:1=(null) passed
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: do_lrm_invoke: PE requested op drbd_testdata2:0_monitor_31000 (call=NA) be cancelled
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: do_lrm_invoke: Nothing known about operation 0 for drbd_testdata2:0_monitor_31000
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: delete_op_entry: sync: Sending delete op for drbd_testdata2:0 (call=0)
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:0 after complete monitor op (interval=31000)
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:0_monitor_31000 from 6:275:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-70
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-c crmd: [2741]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
-------------- next part --------------
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a1 to 7a2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a2 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a2 to 7a3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a3 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7a3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a3 to 7a4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a4 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a4 to 7a5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a5 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a5 to 7a6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a6 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7a6
Oct 2 15:32:48 storage-test-d cib: [2806]: debug: activateCibXml: Triggering CIB write for cib_apply_diff op
Oct 2 15:32:48 storage-test-d cib: [2806]: debug: Forking temp process write_cib_contents
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a6 to 7a7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a7 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a7 to 7a8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a8 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a8 to 7a9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7a9 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7a9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7aa
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7a9 to 7aa
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7aa to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7aa
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7aa
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=145:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_notify_0
Oct 2 15:32:48 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation notify[107] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10 to the operation list.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 notify[107] (pid 15518)
Oct 2 15:32:48 storage-test-d lrmd: [15518]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ab
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7aa to 7ab
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ab to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ab
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ac
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ab to 7ac
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ac to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ac
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7ac
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:notify process 15518 exited with return code 0.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: operation notify[107] on drbd_testdata2:1 for client 2812: pid 15518 exited with return code 0
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete notify op (interval=0)
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_notify_0 from 145:271:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256768-97
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_notify_0 (call=107, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ac to 7ae
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ad to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ae to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ad
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ae
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ad
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ae
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7ae
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7af
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ae to 7af
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7af to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7af
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7af to 7b0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b0 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b0 to 7b1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b1 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b1 to 7b2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b2 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7b1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7b2
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: cancel_op: Cancelling op 106 for drbd_testdata2:1 (drbd_testdata2:1:106)
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: cancel_op: operation monitor[106] on drbd_testdata2:1 for client 2812, its parameters: drbd_resource=[testdata2] CRM_meta_role=[Master] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_inactive_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_master_uname=[ ] CRM_meta_name=[monitor] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[storage-test-c storage-test-d ] cancelled
Oct 2 15:32:48 storage-test-d lrmd: [2808]: debug: on_msg_cancel_op: operation 106 cancelled
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: cancel_op: Op 106 for drbd_testdata2:1 (drbd_testdata2:1:106): cancelled
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=80:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_demote_0
Oct 2 15:32:48 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation demote[108] on drbd_testdata2:1 for client 2812, its parameters: drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_timeout=[20000] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_notify_start_resource=[ ] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10 to the operation list.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 demote[108] (pid 15540)
Oct 2 15:32:48 storage-test-d lrmd: [15540]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_monitor_29000 (call=106, status=1, cib-update=0, confirmed=true) Cancelled
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: update_history_cache: Appending monitor op to history for 'drbd_testdata2:1'
Oct 2 15:32:48 storage-test-d drbd[15540]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf secondary testdata2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b2 to 7b3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b3 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b3 to 7b4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b4 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7b4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b4 to 7b5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b5 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b5 to 7b6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b6 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b6 to 7b7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b7 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7b7
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:48 storage-test-d drbd[15540]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:48 storage-test-d drbd[15540]: DEBUG: testdata2: Command output:
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:demote:stdout)
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:demote process 15540 exited with return code 0.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: operation demote[108] on drbd_testdata2:1 for client 2812: pid 15540 exited with return code 0
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:1 after complete demote op (interval=0)
Oct 2 15:32:48 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_demote_0 (call=108, rc=0, cib-update=89, confirmed=true) ok
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: update_history_cache: Appending demote op to history for 'drbd_testdata2:1'
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b7 to 7b9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b8 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7b9 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7b9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7b9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ba
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7b9 to 7ba
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ba to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ba
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bb
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ba to 7bb
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7bb to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7bb to 7bc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7bc to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bb
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bd
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7bc to 7bd
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7bd to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bd
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7be
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7bd to 7be
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7be to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7be
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bf
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7be to 7bf
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7bf to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7bf to 7c0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c0 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7bf
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7bd
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=146:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_notify_0
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7c0
Oct 2 15:32:48 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation notify[109] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10 to the operation list.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 notify[109] (pid 15580)
Oct 2 15:32:48 storage-test-d lrmd: [15580]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:48 storage-test-d cib: [2806]: info: Managed write_cib_contents process 15516 exited with return code 0.
Oct 2 15:32:48 storage-test-d drbd[15580]: DEBUG: testdata2: Calling /usr/sbin/crm_master -Q -l reboot -v 10000
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c0 to 7c1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c1 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c1
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c1 to 7c2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c2 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c2
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7c2
Oct 2 15:32:48 storage-test-d attrd: [2809]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:1=10000
Oct 2 15:32:48 storage-test-d attrd: [2809]: debug: attrd_local_callback: Supplied: 10000, Current: 10000, Stored: 10000
Oct 2 15:32:48 storage-test-d drbd[15580]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:48 storage-test-d drbd[15580]: DEBUG: testdata2: Command output:
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:notify:stdout)
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:notify process 15580 exited with return code 0.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: operation notify[109] on drbd_testdata2:1 for client 2812: pid 15580 exited with return code 0
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete notify op (interval=0)
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_notify_0 from 146:271:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256768-98
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_notify_0 (call=109, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c2 to 7c4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c3 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c4 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c3
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7c4
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c4 to 7c5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c5 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c5
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c5 to 7c6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c6 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c6 to 7c7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c7 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c7
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c7 to 7c8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c8 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c8
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7c6
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7c8
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=142:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_notify_0
Oct 2 15:32:48 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation notify[110] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10 to the operation list.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 notify[110] (pid 15619)
Oct 2 15:32:48 storage-test-d lrmd: [15619]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c8 to 7c9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7c9 to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7c9
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ca
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7c9 to 7ca
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ca to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ca
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7ca
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:notify process 15619 exited with return code 0.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: operation notify[110] on drbd_testdata2:1 for client 2812: pid 15619 exited with return code 0
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete notify op (interval=0)
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_notify_0 from 142:271:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256768-99
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_notify_0 (call=110, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ca to 7cc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7cb to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7cc to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cb
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cb
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7cc
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cd
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering 7cc to 7cd
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7cd to pending delivery queue
Oct 2 15:32:48 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7cd
Oct 2 15:32:48 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=81:271:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_stop_0
Oct 2 15:32:48 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation stop[111] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[ ] CRM_meta_notify_stop_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_demote_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_master_uname=[storage-test-c storage-test-d ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] CRM_meta_notify_start_uname=[ ] CRM_meta_clone_node_max=[1] CRM_meta_notify=[true] CRM_meta_ to the operation list.
Oct 2 15:32:48 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 stop[111] (pid 15641)
Oct 2 15:32:48 storage-test-d lrmd: [15641]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf down testdata2
Oct 2 15:32:49 storage-test-d cib: [2806]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] does not exist
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update -22 for master-drbd_testdata2:0=(null) passed
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Command output:
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:stop:stdout)
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf down testdata2
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Command output:
Oct 2 15:32:49 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:stop:stdout)
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Calling /usr/sbin/crm_master -l reboot -D
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:1=<null>
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: attrd_local_callback: Supplied: (null), Current: 10000, Stored: 10000
Oct 2 15:32:49 storage-test-d attrd: [2809]: notice: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_testdata2:1 (<null>)
Oct 2 15:32:49 storage-test-d cib: [2806]: debug: cib_process_xpath: Processing cib_query op for //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] (/cib/status/node_state[3]/transient_attributes/instance_attributes/nvpair[3])
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: find_nvpair_attr_delegate: Match <nvpair id="status-storage-test-d-master-drbd_testdata2.1" name="master-drbd_testdata2:1" value="10000" />
Oct 2 15:32:49 storage-test-d attrd: [2809]: notice: attrd_perform_update: Sent delete 157: node=storage-test-d, attr=master-drbd_testdata2:1, id=<n/a>, set=(null), section=status
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: xmlfromIPC: Peer disconnected
Oct 2 15:32:49 storage-test-d cib: [2806]: debug: cib_process_xpath: Processing cib_query op for //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] (/cib/status/node_state[3]/transient_attributes/instance_attributes/nvpair[3])
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: find_nvpair_attr_delegate: Match <nvpair id="status-storage-test-d-master-drbd_testdata2.1" name="master-drbd_testdata2:1" value="10000" />
Oct 2 15:32:49 storage-test-d attrd: [2809]: notice: attrd_perform_update: Sent delete 159: node=storage-test-d, attr=master-drbd_testdata2:1, id=<n/a>, set=(null), section=status
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:49 storage-test-d drbd[15641]: DEBUG: testdata2: Command output:
Oct 2 15:32:49 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:stop:stdout)
Oct 2 15:32:49 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:stop process 15641 exited with return code 0.
Oct 2 15:32:49 storage-test-d lrmd: [2808]: info: operation stop[111] on drbd_testdata2:1 for client 2812: pid 15641 exited with return code 0
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update 157 for master-drbd_testdata2:1=(null) passed
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:1 after complete stop op (interval=0)
Oct 2 15:32:49 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_stop_0 (call=111, rc=0, cib-update=90, confirmed=true) ok
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: update_history_cache: Appending stop op to history for 'drbd_testdata2:1'
Oct 2 15:32:49 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update 159 for master-drbd_testdata2:1=(null) passed
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:49 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:54 storage-test-d lrmd: [2808]: debug: rsc:st-storage-test-c:1 monitor[14] (pid 15711)
Oct 2 15:32:54 storage-test-d lrmd: [15711]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:54 storage-test-d lrm-stonith: [15711]: debug: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/crm/st_command
Oct 2 15:32:54 storage-test-d lrm-stonith: [15711]: debug: get_stonith_token: Obtained registration token: 49de9570-d12e-480d-8a60-1f2fbc52c3eb
Oct 2 15:32:54 storage-test-d lrm-stonith: [15711]: debug: init_client_ipc_comms_nodispatch: Attempting to talk on: /var/run/crm/st_callback
Oct 2 15:32:54 storage-test-d lrm-stonith: [15711]: debug: get_stonith_token: Obtained registration token: 05009b66-56fa-4ead-ae76-04113d5b9dde
Oct 2 15:32:54 storage-test-d lrm-stonith: [15711]: debug: stonith_api_signon: Connection to STONITH successful
Oct 2 15:32:54 storage-test-d stonith-ng: [2807]: debug: stonith_command: Processing register from lrmd ( 0)
Oct 2 15:32:54 storage-test-d stonith-ng: [2807]: debug: stonith_command: Processing st_execute from lrmd ( 1000)
Oct 2 15:32:54 storage-test-d stonith-ng: [2807]: info: stonith_command: Processed st_execute from lrmd: rc=-1
Oct 2 15:32:54 storage-test-d stonith-ng: [2807]: debug: run_stonith_agent: forking
Oct 2 15:32:54 storage-test-d stonith-ng: [2807]: debug: run_stonith_agent: sending args
Oct 2 15:32:54 storage-test-d stonith-ng: [2807]: debug: stonith_device_execute: Operation monitor on st-storage-test-c:1 is active with pid: 15712
Oct 2 15:32:55 storage-test-d stonith: [15713]: info: external/ipmi device OK.
Oct 2 15:32:55 storage-test-d stonith-ng: [2807]: debug: log_operation: Operation 'monitor' [15712] for device 'st-storage-test-c:1' returned: 0
Oct 2 15:32:55 storage-test-d stonith-ng: [2807]: info: log_operation: st-storage-test-c:1: Performing: stonith -t external/ipmi -S
Oct 2 15:32:55 storage-test-d stonith-ng: [2807]: info: log_operation: st-storage-test-c:1: success: 0
Oct 2 15:32:55 storage-test-d stonith-ng: [2807]: debug: log_operation: st-storage-test-c:1: (total 52 bytes)
Oct 2 15:32:55 storage-test-d lrm-stonith: [15711]: debug: execra: st-storage-test-c:1_monitor returned 0
Oct 2 15:32:55 storage-test-d lrm-stonith: [15711]: debug: stonith_api_signoff: Signing out of the STONITH Service
Oct 2 15:32:55 storage-test-d lrmd: [2808]: info: operation monitor[14] on st-storage-test-c:1 for client 2812: pid 15711 exited with return code 0
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7e9
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7e8 to 7e9
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7e9 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7e9
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ea
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7e9 to 7ea
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ea to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ea
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7ea
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7eb
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ea to 7eb
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7eb to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7eb
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ec
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7eb to 7ec
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ec to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ed
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ec to 7ed
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ed to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ec
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ed
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7ed
Oct 2 15:32:57 storage-test-d cib: [2806]: debug: activateCibXml: Triggering CIB write for cib_apply_diff op
Oct 2 15:32:57 storage-test-d cib: [2806]: debug: Forking temp process write_cib_contents
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ee
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ed to 7ee
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ee to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ee
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ef
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ee to 7ef
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ef to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ef
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f0
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7ef to 7f0
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f0 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f0
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f1
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f0 to 7f1
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f1 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f1
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7f1
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=76:273:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_start_0
Oct 2 15:32:57 storage-test-d lrmd: [2808]: debug: on_msg_perform_op:2400: copying parameters for rsc drbd_testdata2:1
Oct 2 15:32:57 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation start[112] on drbd_testdata2:1 for client 2812, its parameters: drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[ ] CRM_meta_notify_start_resource=[drbd_testdata2:0 drbd_testdata2:1 ] CRM_meta_notify_inactive_resource=[drbd_testdata2:0 drbd_testdata2:1 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[storage-test to the operation list.
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 start[112] (pid 15730)
Oct 2 15:32:57 storage-test-d lrmd: [15730]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf check-resize testdata2
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:start:stdout)
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf new-resource testdata2
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:start:stdout)
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf new-minor testdata2
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:start:stdout)
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf --peer storage-test-c attach testdata2
Oct 2 15:32:57 storage-test-d cib: [2806]: info: Managed write_cib_contents process 15729 exited with return code 0.
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f2
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f1 to 7f2
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f2 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f2
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f3
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f2 to 7f3
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f3 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f3
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7f3
Oct 2 15:32:57 storage-test-d cib: [2806]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] does not exist
Oct 2 15:32:57 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update -22 for master-drbd_testdata2:0=(null) passed
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f4
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f3 to 7f4
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f4 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f4
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f5
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f4 to 7f5
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f5 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f5
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7f5
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f6
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f5 to 7f6
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f6 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f6
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f7
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f6 to 7f7
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f7 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f7
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7f7
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f8
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f7 to 7f8
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f8 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f8
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f9
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f8 to 7f9
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7f9 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7f9
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fa
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7f9 to 7fa
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7fa to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fa
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7fa
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:start:stdout)
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf --peer storage-test-c adjust testdata2
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:start:stdout)
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Calling /usr/sbin/crm_master -Q -l reboot -v 1000
Oct 2 15:32:57 storage-test-d attrd: [2809]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:1=1000
Oct 2 15:32:57 storage-test-d attrd: [2809]: debug: attrd_local_callback: Supplied: 1000, Current: (null), Stored: (null)
Oct 2 15:32:57 storage-test-d attrd: [2809]: debug: attrd_local_callback: New value of master-drbd_testdata2:1 is 1000
Oct 2 15:32:57 storage-test-d attrd: [2809]: notice: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_testdata2:1 (1000)
Oct 2 15:32:57 storage-test-d cib: [2806]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] does not exist
Oct 2 15:32:57 storage-test-d cib: [2806]: debug: cib_process_xpath: Processing cib_query op for /cib (/cib)
Oct 2 15:32:57 storage-test-d attrd: [2809]: notice: attrd_perform_update: Sent update 163: master-drbd_testdata2:1=1000
Oct 2 15:32:57 storage-test-d attrd: [2809]: debug: xmlfromIPC: Peer disconnected
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7fa to 7fc
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7fb to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7fc to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fb
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fc
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fb
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fc
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7fc
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fd
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7fc to 7fd
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7fd to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fd
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fe
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7fd to 7fe
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7fe to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7fe
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 7fe
Oct 2 15:32:57 storage-test-d drbd[15730]: DEBUG: testdata2: Command output:
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:start:stdout)
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:start process 15730 exited with return code 0.
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: operation start[112] on drbd_testdata2:1 for client 2812: pid 15730 exited with return code 0
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:1 after complete start op (interval=0)
Oct 2 15:32:57 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update 163 for master-drbd_testdata2:1=1000 passed
Oct 2 15:32:57 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_start_0 (call=112, rc=0, cib-update=91, confirmed=true) ok
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: update_history_cache: Appending start op to history for 'drbd_testdata2:1'
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 7fe to 800
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 7ff to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 800 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ff
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 800
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 7ff
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 800
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 800
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 801
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 800 to 801
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 801 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 801
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 802
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 801 to 802
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 802 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 802
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 803
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 802 to 803
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 803 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 803
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 802
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 804
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 803 to 804
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 804 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 804
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 805
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 804 to 805
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 805 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 805
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 806
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 805 to 806
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 806 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 806
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 807
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 806 to 807
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 807 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 807
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 803
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=135:273:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_notify_0
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 807
Oct 2 15:32:57 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation notify[113] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[drbd_testdata2:0 drbd_testdata2:1 ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:0 drbd_testdata2:1 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[storage-tes to the operation list.
Oct 2 15:32:57 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 notify[113] (pid 15866)
Oct 2 15:32:57 storage-test-d lrmd: [15866]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:57 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:57 storage-test-d drbd[15866]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf --peer storage-test-c -v adjust testdata2
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 808
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 807 to 808
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 808 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 808
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 809
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering 808 to 809
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 809 to pending delivery queue
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 809
Oct 2 15:32:57 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 809
Oct 2 15:32:58 storage-test-d drbd[15866]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:58 storage-test-d drbd[15866]: DEBUG: testdata2: Command output:
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:notify:stdout)
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:notify process 15866 exited with return code 0.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: operation notify[113] on drbd_testdata2:1 for client 2812: pid 15866 exited with return code 0
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete notify op (interval=0)
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_notify_0 from 135:273:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-100
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:58 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_notify_0 (call=113, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 809 to 80b
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 80a to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 80b to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80a
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80b
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80a
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80b
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 80b
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80c
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 80b to 80c
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 80c to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80c
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80d
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 80c to 80d
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 80d to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80d
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80e
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 80d to 80e
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 80e to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80e
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80f
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 80e to 80f
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 80f to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 80f
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 80f
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=149:274:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_notify_0
Oct 2 15:32:58 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation notify[114] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[storage-test-c storage-test-d ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[ ] crm_feature_set=[3.0.6] CRM_m to the operation list.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 notify[114] (pid 15906)
Oct 2 15:32:58 storage-test-d lrmd: [15906]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 810
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 80f to 810
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 810 to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 810
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 811
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 810 to 811
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 811 to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 811
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 811
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:notify process 15906 exited with return code 0.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: operation notify[114] on drbd_testdata2:1 for client 2812: pid 15906 exited with return code 0
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete notify op (interval=0)
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_notify_0 from 149:274:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-101
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:58 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_notify_0 (call=114, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] mcasted message added to pending queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 811 to 813
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 812 to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 813 to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 812
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 813
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 812
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 813
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] releasing messages up to and including 813
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 814
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 813 to 814
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering MCAST message with seq 814 to pending delivery queue
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 814
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Received ringid(10.1.22.61:80) seq 815
Oct 2 15:32:58 storage-test-d corosync[2751]: [TOTEM ] Delivering 814 to 815
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=82:274:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_promote_0
Oct 2 15:32:58 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation promote[115] on drbd_testdata2:1 for client 2812, its parameters: drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_timeout=[20000] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[storage-test-c storage-test-d ] CRM_meta_notify_start_resource=[ ] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[ ] crm_feature_set=[3.0.6] CRM_ to the operation list.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 promote[115] (pid 15928)
Oct 2 15:32:58 storage-test-d lrmd: [15928]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:58 storage-test-d drbd[15928]: DEBUG: testdata2: Calling drbdadm -c /etc/drbd.conf primary testdata2
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-d drbd[15928]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:58 storage-test-d drbd[15928]: DEBUG: testdata2: Command output:
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:promote:stdout)
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:promote process 15928 exited with return code 0.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: operation promote[115] on drbd_testdata2:1 for client 2812: pid 15928 exited with return code 0
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: create_operation_update: do_update_resource: Updating resouce drbd_testdata2:1 after complete promote op (interval=0)
Oct 2 15:32:58 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_promote_0 (call=115, rc=0, cib-update=92, confirmed=true) ok
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: update_history_cache: Appending promote op to history for 'drbd_testdata2:1'
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: do_lrm_rsc_op: Performing key=150:274:0:2885cd15-da39-417f-996f-61399f064d06 op=drbd_testdata2:1_notify_0
Oct 2 15:32:58 storage-test-d lrmd: [2808]: debug: on_msg_perform_op: add an operation operation notify[116] on drbd_testdata2:1 for client 2812, its parameters: CRM_meta_notify_start_resource=[ ] drbd_resource=[testdata2] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_master_uname=[ ] CRM_meta_notify_promote_uname=[storage-test-c storage-test-d ] CRM_meta_timeout=[20000] CRM_meta_notify_inactive_resource=[drbd_testdata2:2 ] stop_outdates_secondary=[true] adjust_master_score=[0 10 1000 10000] CRM_meta_notify_start_uname=[ ] crm_feature_set=[3.0.6] CRM_m to the operation list.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: rsc:drbd_testdata2:1 notify[116] (pid 15970)
Oct 2 15:32:58 storage-test-d lrmd: [15970]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-d cib: [2806]: debug: cib_process_xpath: cib_query: //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:0'] does not exist
Oct 2 15:32:58 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update -22 for master-drbd_testdata2:0=(null) passed
Oct 2 15:32:58 storage-test-d drbd[15970]: DEBUG: testdata2: Calling /usr/sbin/crm_master -Q -l reboot -v 10000
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-d attrd: [2809]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata2:1=10000
Oct 2 15:32:58 storage-test-d attrd: [2809]: debug: attrd_local_callback: Supplied: 10000, Current: 1000, Stored: 1000
Oct 2 15:32:58 storage-test-d attrd: [2809]: debug: attrd_local_callback: New value of master-drbd_testdata2:1 is 10000
Oct 2 15:32:58 storage-test-d attrd: [2809]: notice: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_testdata2:1 (10000)
Oct 2 15:32:58 storage-test-d cib: [2806]: debug: cib_process_xpath: Processing cib_query op for //cib/status//node_state[@id='storage-test-d']//transient_attributes//nvpair[@name='master-drbd_testdata2:1'] (/cib/status/node_state[3]/transient_attributes/instance_attributes/nvpair[3])
Oct 2 15:32:58 storage-test-d attrd: [2809]: debug: find_nvpair_attr_delegate: Match <nvpair id="status-storage-test-d-master-drbd_testdata2.1" name="master-drbd_testdata2:1" value="1000" />
Oct 2 15:32:58 storage-test-d attrd: [2809]: notice: attrd_perform_update: Sent update 166: master-drbd_testdata2:1=10000
Oct 2 15:32:58 storage-test-d drbd[15970]: DEBUG: testdata2: Exit code 0
Oct 2 15:32:58 storage-test-d drbd[15970]: DEBUG: testdata2: Command output:
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: RA output: (drbd_testdata2:1:notify:stdout)
Oct 2 15:32:58 storage-test-d attrd: [2809]: debug: attrd_cib_callback: Update 166 for master-drbd_testdata2:1=10000 passed
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: Managed drbd_testdata2:1:notify process 15970 exited with return code 0.
Oct 2 15:32:58 storage-test-d lrmd: [2808]: info: operation notify[116] on drbd_testdata2:1 for client 2812: pid 15970 exited with return code 0
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete notify op (interval=0)
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_notify_0 from 150:274:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-102
Oct 2 15:32:58 storage-test-d crmd: [2812]: info: process_lrm_event: LRM operation drbd_testdata2:1_notify_0 (call=116, rc=0, cib-update=0, confirmed=true) ok
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: do_lrm_invoke: PE requested op drbd_testdata2:1_monitor_31000 (call=NA) be cancelled
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: do_lrm_invoke: Nothing known about operation 0 for drbd_testdata2:1_monitor_31000
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: delete_op_entry: sync: Sending delete op for drbd_testdata2:1 (call=0)
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: create_operation_update: send_direct_ack: Updating resouce drbd_testdata2:1 after complete monitor op (interval=31000)
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: send_direct_ack: ACK'ing resource op drbd_testdata2:1_monitor_31000 from 9:275:0:2885cd15-da39-417f-996f-61399f064d06: lrm_invoke-lrmd-1412256778-103
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:32:58 storage-test-d crmd: [2812]: debug: get_xpath_object: No match for //cib_update_result//diff-added//crm_config in /notify
Oct 2 15:33:05 storage-test-d lrmd: [2808]: debug: rsc:drbd_testdata1:1 monitor[102] (pid 16018)
Oct 2 15:33:05 storage-test-d lrmd: [16018]: debug: perform_ra_op: resetting scheduler class to SCHED_OTHER
Oct 2 15:33:05 storage-test-d drbd[16018]: DEBUG: testdata1: Calling /usr/sbin/crm_master -Q -l reboot -v 10000
Oct 2 15:33:05 storage-test-d attrd: [2809]: debug: attrd_local_callback: update message from crm_attribute: master-drbd_testdata1:1=10000
Oct 2 15:33:05 storage-test-d attrd: [2809]: debug: attrd_local_callback: Supplied: 10000, Current: 10000, Stored: 10000
Oct 2 15:33:05 storage-test-d drbd[16018]: DEBUG: testdata1: Exit code 0
Oct 2 15:33:05 storage-test-d drbd[16018]: DEBUG: testdata1: Command output:
Oct 2 15:33:05 storage-test-d lrmd: [2808]: debug: RA output: (drbd_testdata1:1:monitor:stdout)
Oct 2 15:33:05 storage-test-d lrmd: [2808]: info: operation monitor[102] on drbd_testdata1:1 for client 2812: pid 16018 exited with return code 0
More information about the Pacemaker
mailing list