[ClusterLabs] VirtualDomain live migration error
Oscar Segarra
oscar.segarra at gmail.com
Thu Aug 31 17:45:59 EDT 2017
Hi Ken,
Thanks a lot for you quick answer:
Regarding to selinux, it is disabled. The FW is disabled as well.
[root at vdicnode01 ~]# sestatus
SELinux status: disabled
[root at vdicnode01 ~]# service firewalld status
Redirecting to /bin/systemctl status firewalld.service
● firewalld.service - firewalld - dynamic firewall daemon
Loaded: loaded (/usr/lib/systemd/system/firewalld.service; disabled;
vendor preset: enabled)
Active: inactive (dead)
Docs: man:firewalld(1)
On migration, it performs a gracefully shutdown and a start on the new node.
I attach the logs when trying to migrate from vdicnode02 to vdicnode01:
vdicnode02 corosync.log:
Aug 31 23:38:17 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.161.2 2
Aug 31 23:38:17 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.162.0 (null)
Aug 31 23:38:17 [1521] vdicnode02 cib: info: cib_perform_op: --
/cib/configuration/constraints/rsc_location[@id='location-vm-vdicdb01-vdicnode01--INFINITY']
Aug 31 23:38:17 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @epoch=162, @num_updates=0
Aug 31 23:38:17 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_replace operation for section
configuration: OK (rc=0, origin=vdicnode01/cibadmin/2, version=0.162.0)
Aug 31 23:38:17 [1521] vdicnode02 cib: info: cib_file_backup:
Archived previous version as /var/lib/pacemaker/cib/cib-65.raw
Aug 31 23:38:17 [1521] vdicnode02 cib: info:
cib_file_write_with_digest: Wrote version 0.162.0 of the CIB to disk
(digest: 1f87611b60cd7c48b95b6b788b47f65f)
Aug 31 23:38:17 [1521] vdicnode02 cib: info:
cib_file_write_with_digest: Reading cluster configuration file
/var/lib/pacemaker/cib/cib.jt2KPw (digest:
/var/lib/pacemaker/cib/cib.Kwqfpl)
Aug 31 23:38:22 [1521] vdicnode02 cib: info: cib_process_ping:
Reporting our current digest to vdicnode01:
dace3a23264934279d439420d5a716cc for 0.162.0 (0x7f96bb26c5c0 0)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.162.0 2
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.0 (null)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @epoch=163
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: ++
/cib/configuration/constraints: <rsc_location
id="location-vm-vdicdb01-vdicnode02--INFINITY" node="vdicnode02"
rsc="vm-vdicdb01" score="-INFINITY"/>
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_replace operation for section
configuration: OK (rc=0, origin=vdicnode01/cibadmin/2, version=0.163.0)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_file_backup:
Archived previous version as /var/lib/pacemaker/cib/cib-66.raw
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_file_write_with_digest: Wrote version 0.163.0 of the CIB to disk
(digest: 47a548b36746de9275d66cc6aeb0fdc4)
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_file_write_with_digest: Reading cluster configuration file
/var/lib/pacemaker/cib/cib.rcgXiT (digest:
/var/lib/pacemaker/cib/cib.7geMfi)
Aug 31 23:38:27 [1523] vdicnode02 lrmd: info:
cancel_recurring_action: Cancelling ocf operation
vm-vdicdb01_monitor_10000
Aug 31 23:38:27 [1526] vdicnode02 crmd: info: do_lrm_rsc_op:
Performing key=6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a
op=vm-vdicdb01_migrate_to_0
Aug 31 23:38:27 [1523] vdicnode02 lrmd: info: log_execute:
executing - rsc:vm-vdicdb01 action:migrate_to call_id:9
Aug 31 23:38:27 [1526] vdicnode02 crmd: info: process_lrm_event:
Result of monitor operation for vm-vdicdb01 on vdicnode02: Cancelled |
call=7 key=vm-vdicdb01_monitor_10000 confirmed=true
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.163.0 2
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.1 (null)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @num_updates=1
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_migrate_to_0, @operation=migrate_to,
@crm-debug-origin=cib_action_update,
@transition-key=6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=-1:193;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=-1, @rc-code=193, @op-status=-1, @last-run=1504215507, @last-rc-cha
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/41, version=0.163.1)
VirtualDomain(vm-vdicdb01)[5241]: 2017/08/31_23:38:27 INFO: vdicdb01:
Starting live migration to vdicnode01 (using: virsh
--connect=qemu:///system --quiet migrate --live vdicdb01
qemu+ssh://vdicnode01/system ).
VirtualDomain(vm-vdicdb01)[5241]: 2017/08/31_23:38:27 ERROR:
vdicdb01: live migration to vdicnode01 failed: 1
Aug 31 23:38:27 [1523] vdicnode02 lrmd: notice: operation_finished:
vm-vdicdb01_migrate_to_0:5241:stderr [ error: Cannot recv data: Host
key verification failed.: Connection reset by peer ]
Aug 31 23:38:27 [1523] vdicnode02 lrmd: notice: operation_finished:
vm-vdicdb01_migrate_to_0:5241:stderr [ ocf-exit-reason:vdicdb01: live
migration to vdicnode01 failed: 1 ]
Aug 31 23:38:27 [1523] vdicnode02 lrmd: info: log_finished:
finished - rsc:vm-vdicdb01 action:migrate_to call_id:9 pid:5241 exit-code:1
exec-time:78ms queue-time:0ms
Aug 31 23:38:27 [1526] vdicnode02 crmd: notice: process_lrm_event:
Result of migrate_to operation for vm-vdicdb01 on vdicnode02: 1
(unknown error) | call=9 key=vm-vdicdb01_migrate_to_0 confirmed=true
cib-update=14
Aug 31 23:38:27 [1526] vdicnode02 crmd: notice: process_lrm_event:
vdicnode02-vm-vdicdb01_migrate_to_0:9 [ error: Cannot recv data: Host
key verification failed.: Connection reset by
peer\nocf-exit-reason:vdicdb01: live migration to vdicnode01 failed: 1\n ]
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_process_request: Forwarding cib_modify operation for section status
to all (origin=local/crmd/14)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.163.1 2
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.2 (null)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @num_updates=2
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@crm-debug-origin=do_update_resource,
@transition-magic=0:1;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=9, @rc-code=1, @op-status=0, @exec-time=78, @exit-reason=vdicdb01:
live migration to vdicnode01 failed: 1
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: ++
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']:
<lrm_rsc_op id="vm-vdicdb01_last_failure_0"
operation_key="vm-vdicdb01_migrate_to_0" operation="migrate_to"
crm-debug-origin="do_update_resource" crm_feature_set="3.0.10"
transition-key="6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
transition-magic="0:1;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
exit-reason="vdicdb01: live migration to vdicn
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode02/crmd/14, version=0.163.2)
Aug 31 23:38:27 [1526] vdicnode02 crmd: info: do_lrm_rsc_op:
Performing key=2:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a
op=vm-vdicdb01_stop_0
Aug 31 23:38:27 [1523] vdicnode02 lrmd: info: log_execute:
executing - rsc:vm-vdicdb01 action:stop call_id:10
VirtualDomain(vm-vdicdb01)[5285]: 2017/08/31_23:38:27 INFO: Issuing
graceful shutdown request for domain vdicdb01.
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.163.2 2
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.3 (null)
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @num_updates=3
Aug 31 23:38:27 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_stop_0, @operation=stop,
@transition-key=4:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=0:0;4:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=6, @rc-code=0, @last-run=1504215507, @last-rc-change=1504215507,
@exec-time=57
Aug 31 23:38:27 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/43, version=0.163.3)
Aug 31 23:38:30 [1523] vdicnode02 lrmd: info: log_finished:
finished - rsc:vm-vdicdb01 action:stop call_id:10 pid:5285 exit-code:0
exec-time:3159ms queue-time:0ms
Aug 31 23:38:30 [1526] vdicnode02 crmd: notice: process_lrm_event:
Result of stop operation for vm-vdicdb01 on vdicnode02: 0 (ok) |
call=10 key=vm-vdicdb01_stop_0 confirmed=true cib-update=15
Aug 31 23:38:30 [1521] vdicnode02 cib: info:
cib_process_request: Forwarding cib_modify operation for section status
to all (origin=local/crmd/15)
Aug 31 23:38:30 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.163.3 2
Aug 31 23:38:30 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.4 (null)
Aug 31 23:38:30 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @num_updates=4
Aug 31 23:38:30 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_stop_0, @operation=stop,
@transition-key=2:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=0:0;2:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=10, @rc-code=0, @exec-time=3159
Aug 31 23:38:30 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode02/crmd/15, version=0.163.4)
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.163.4 2
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.5 (null)
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @num_updates=5
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_start_0, @operation=start,
@transition-key=5:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=0:0;5:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=7, @last-run=1504215510, @last-rc-change=1504215510, @exec-time=528
Aug 31 23:38:31 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/44, version=0.163.5)
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: --- 0.163.5 2
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op:
Diff: +++ 0.163.6 (null)
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op: +
/cib: @num_updates=6
Aug 31 23:38:31 [1521] vdicnode02 cib: info: cib_perform_op: ++
/cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='vm-vdicdb01']:
<lrm_rsc_op id="vm-vdicdb01_monitor_10000"
operation_key="vm-vdicdb01_monitor_10000" operation="monitor"
crm-debug-origin="do_update_resource" crm_feature_set="3.0.10"
transition-key="6:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
transition-magic="0:0;6:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
on_node="vdicnode01" call-id="8" rc-code="0" op-s
Aug 31 23:38:31 [1521] vdicnode02 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/45, version=0.163.6)
Aug 31 23:38:36 [1521] vdicnode02 cib: info: cib_process_ping:
Reporting our current digest to vdicnode01:
9141ea9880f5a44b133003982d863bc8 for 0.163.6 (0x7f96bb2625a0 0)
vdicnode01 - corosync.log
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Forwarding cib_replace operation for section
configuration to all (origin=local/cibadmin/2)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.162.0 2
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.0 (null)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @epoch=163
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: ++
/cib/configuration/constraints: <rsc_location
id="location-vm-vdicdb01-vdicnode02--INFINITY" node="vdicnode02"
rsc="vm-vdicdb01" score="-INFINITY"/>
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_replace operation for section
configuration: OK (rc=0, origin=vdicnode01/cibadmin/2, version=0.163.0)
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
abort_transition_graph: Transition aborted by
rsc_location.location-vm-vdicdb01-vdicnode02--INFINITY 'create': Non-status
change | cib=0.163.0 source=te_update_diff:436
path=/cib/configuration/constraints complete=true
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice:
do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE |
input=I_PE_CALC cause=C_FSA_INTERNAL origin=abort_transition_graph
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_file_backup:
Archived previous version as /var/lib/pacemaker/cib/cib-85.raw
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_file_write_with_digest: Wrote version 0.163.0 of the CIB to disk
(digest: 47a548b36746de9275d66cc6aeb0fdc4)
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_file_write_with_digest: Reading cluster configuration file
/var/lib/pacemaker/cib/cib.npBIW2 (digest:
/var/lib/pacemaker/cib/cib.bDogoB)
Aug 31 23:38:27 [1535] vdicnode01 pengine: info:
determine_online_status: Node vdicnode02 is online
Aug 31 23:38:27 [1535] vdicnode01 pengine: info:
determine_online_status: Node vdicnode01 is online
Aug 31 23:38:27 [1535] vdicnode01 pengine: info: native_print:
vm-vdicdb01 (ocf::heartbeat:VirtualDomain): Started vdicnode02
Aug 31 23:38:27 [1535] vdicnode01 pengine: info: RecurringOp:
Start recurring monitor (10s) for vm-vdicdb01 on vdicnode01
Aug 31 23:38:27 [1535] vdicnode01 pengine: notice: LogActions:
Migrate vm-vdicdb01 (Started vdicnode02 -> vdicnode01)
Aug 31 23:38:27 [1535] vdicnode01 pengine: notice: process_pe_message:
Calculated transition 6, saving inputs in
/var/lib/pacemaker/pengine/pe-input-96.bz2
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
do_state_transition: State transition S_POLICY_ENGINE ->
S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
origin=handle_response
Aug 31 23:38:27 [1536] vdicnode01 crmd: info: do_te_invoke:
Processing graph 6 (ref=pe_calc-dc-1504215507-24) derived from
/var/lib/pacemaker/pengine/pe-input-96.bz2
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice: te_rsc_command:
Initiating migrate_to operation vm-vdicdb01_migrate_to_0 on vdicnode02 |
action 6
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
create_operation_update: cib_action_update: Updating resource
vm-vdicdb01 after migrate_to op pending (interval=0)
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Forwarding cib_modify operation for section status
to all (origin=local/crmd/41)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.163.0 2
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.1 (null)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @num_updates=1
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_migrate_to_0, @operation=migrate_to,
@crm-debug-origin=cib_action_update,
@transition-key=6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=-1:193;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=-1, @rc-code=193, @op-status=-1, @last-run=1504215507, @last-rc-cha
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/41, version=0.163.1)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.163.1 2
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.2 (null)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @num_updates=2
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@crm-debug-origin=do_update_resource,
@transition-magic=0:1;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=9, @rc-code=1, @op-status=0, @exec-time=78, @exit-reason=vdicdb01:
live migration to vdicnode01 failed: 1
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: ++
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']:
<lrm_rsc_op id="vm-vdicdb01_last_failure_0"
operation_key="vm-vdicdb01_migrate_to_0" operation="migrate_to"
crm-debug-origin="do_update_resource" crm_feature_set="3.0.10"
transition-key="6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
transition-magic="0:1;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
exit-reason="vdicdb01: live migration to vdicn
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode02/crmd/14, version=0.163.2)
Aug 31 23:38:27 [1536] vdicnode01 crmd: warning: status_from_rc:
Action 6 (vm-vdicdb01_migrate_to_0) on vdicnode02 failed (target: 0 vs. rc:
1): Error
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice:
abort_transition_graph: Transition aborted by operation
vm-vdicdb01_migrate_to_0 'modify' on vdicnode02: Event failed |
magic=0:1;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a cib=0.163.2
source=match_graph_event:310 complete=false
Aug 31 23:38:27 [1536] vdicnode01 crmd: info: match_graph_event:
Action vm-vdicdb01_migrate_to_0 (6) confirmed on vdicnode02 (rc=1)
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
process_graph_event: Detected action (6.6)
vm-vdicdb01_migrate_to_0.9=unknown error: failed
Aug 31 23:38:27 [1536] vdicnode01 crmd: warning: status_from_rc:
Action 6 (vm-vdicdb01_migrate_to_0) on vdicnode02 failed (target: 0 vs. rc:
1): Error
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
abort_transition_graph: Transition aborted by operation
vm-vdicdb01_migrate_to_0 'create' on vdicnode02: Event failed |
magic=0:1;6:6:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a cib=0.163.2
source=match_graph_event:310 complete=false
Aug 31 23:38:27 [1536] vdicnode01 crmd: info: match_graph_event:
Action vm-vdicdb01_migrate_to_0 (6) confirmed on vdicnode02 (rc=1)
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
process_graph_event: Detected action (6.6)
vm-vdicdb01_migrate_to_0.9=unknown error: failed
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice: run_graph:
Transition 6 (Complete=1, Pending=0, Fired=0, Skipped=0, Incomplete=5,
Source=/var/lib/pacemaker/pengine/pe-input-96.bz2): Complete
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
do_state_transition: State transition S_TRANSITION_ENGINE ->
S_POLICY_ENGINE | input=I_PE_CALC cause=C_FSA_INTERNAL origin=notify_crmd
Aug 31 23:38:27 [1535] vdicnode01 pengine: info:
determine_online_status: Node vdicnode02 is online
Aug 31 23:38:27 [1535] vdicnode01 pengine: info:
determine_online_status: Node vdicnode01 is online
Aug 31 23:38:27 [1535] vdicnode01 pengine: warning:
unpack_rsc_op_failure: Processing failed op migrate_to for vm-vdicdb01 on
vdicnode02: unknown error (1)
Aug 31 23:38:27 [1535] vdicnode01 pengine: warning:
unpack_rsc_op_failure: Processing failed op migrate_to for vm-vdicdb01 on
vdicnode02: unknown error (1)
Aug 31 23:38:27 [1535] vdicnode01 pengine: info: native_print:
vm-vdicdb01 (ocf::heartbeat:VirtualDomain): FAILED
Aug 31 23:38:27 [1535] vdicnode01 pengine: info: native_print:
1 : vdicnode01
Aug 31 23:38:27 [1535] vdicnode01 pengine: info: native_print:
2 : vdicnode02
Aug 31 23:38:27 [1535] vdicnode01 pengine: error:
native_create_actions: Resource vm-vdicdb01 (ocf::VirtualDomain) is active
on 2 nodes attempting recovery
Aug 31 23:38:27 [1535] vdicnode01 pengine: warning:
native_create_actions: See
http://clusterlabs.org/wiki/FAQ#Resource_is_Too_Active for more information.
Aug 31 23:38:27 [1535] vdicnode01 pengine: info: RecurringOp:
Start recurring monitor (10s) for vm-vdicdb01 on vdicnode01
Aug 31 23:38:27 [1535] vdicnode01 pengine: notice: LogActions:
Recover vm-vdicdb01 (Started vdicnode01)
Aug 31 23:38:27 [1535] vdicnode01 pengine: error: process_pe_message:
Calculated transition 7 (with errors), saving inputs in
/var/lib/pacemaker/pengine/pe-error-8.bz2
Aug 31 23:38:27 [1536] vdicnode01 crmd: info:
do_state_transition: State transition S_POLICY_ENGINE ->
S_TRANSITION_ENGINE | input=I_PE_SUCCESS cause=C_IPC_MESSAGE
origin=handle_response
Aug 31 23:38:27 [1536] vdicnode01 crmd: info: do_te_invoke:
Processing graph 7 (ref=pe_calc-dc-1504215507-26) derived from
/var/lib/pacemaker/pengine/pe-error-8.bz2
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice: te_rsc_command:
Initiating stop operation vm-vdicdb01_stop_0 locally on vdicnode01 | action
4
Aug 31 23:38:27 [1536] vdicnode01 crmd: info: do_lrm_rsc_op:
Performing key=4:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a
op=vm-vdicdb01_stop_0
Aug 31 23:38:27 [1533] vdicnode01 lrmd: info: log_execute:
executing - rsc:vm-vdicdb01 action:stop call_id:6
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice: te_rsc_command:
Initiating stop operation vm-vdicdb01_stop_0 on vdicnode02 | action 2
VirtualDomain(vm-vdicdb01)[5268]: 2017/08/31_23:38:27 INFO: Domain
vdicdb01 already stopped.
Aug 31 23:38:27 [1533] vdicnode01 lrmd: info: log_finished:
finished - rsc:vm-vdicdb01 action:stop call_id:6 pid:5268 exit-code:0
exec-time:57ms queue-time:0ms
Aug 31 23:38:27 [1536] vdicnode01 crmd: notice: process_lrm_event:
Result of stop operation for vm-vdicdb01 on vdicnode01: 0 (ok) |
call=6 key=vm-vdicdb01_stop_0 confirmed=true cib-update=43
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Forwarding cib_modify operation for section status
to all (origin=local/crmd/43)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.163.2 2
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.3 (null)
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @num_updates=3
Aug 31 23:38:27 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_stop_0, @operation=stop,
@transition-key=4:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=0:0;4:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=6, @rc-code=0, @last-run=1504215507, @last-rc-change=1504215507,
@exec-time=57
Aug 31 23:38:27 [1536] vdicnode01 crmd: info: match_graph_event:
Action vm-vdicdb01_stop_0 (4) confirmed on vdicnode01 (rc=0)
Aug 31 23:38:27 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/43, version=0.163.3)
Aug 31 23:38:30 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.163.3 2
Aug 31 23:38:30 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.4 (null)
Aug 31 23:38:30 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @num_updates=4
Aug 31 23:38:30 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_stop_0, @operation=stop,
@transition-key=2:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=0:0;2:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=10, @rc-code=0, @exec-time=3159
Aug 31 23:38:30 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode02/crmd/15, version=0.163.4)
Aug 31 23:38:30 [1536] vdicnode01 crmd: info: match_graph_event:
Action vm-vdicdb01_stop_0 (2) confirmed on vdicnode02 (rc=0)
Aug 31 23:38:30 [1536] vdicnode01 crmd: notice: te_rsc_command:
Initiating start operation vm-vdicdb01_start_0 locally on vdicnode01 |
action 5
Aug 31 23:38:30 [1536] vdicnode01 crmd: info: do_lrm_rsc_op:
Performing key=5:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a
op=vm-vdicdb01_start_0
Aug 31 23:38:30 [1533] vdicnode01 lrmd: info: log_execute:
executing - rsc:vm-vdicdb01 action:start call_id:7
Aug 31 23:38:31 [1533] vdicnode01 lrmd: info: log_finished:
finished - rsc:vm-vdicdb01 action:start call_id:7 pid:5401 exit-code:0
exec-time:528ms queue-time:0ms
Aug 31 23:38:31 [1536] vdicnode01 crmd: info: action_synced_wait:
Managed VirtualDomain_meta-data_0 process 5486 exited with rc=0
Aug 31 23:38:31 [1536] vdicnode01 crmd: notice: process_lrm_event:
Result of start operation for vm-vdicdb01 on vdicnode01: 0 (ok) |
call=7 key=vm-vdicdb01_start_0 confirmed=true cib-update=44
Aug 31 23:38:31 [1531] vdicnode01 cib: info:
cib_process_request: Forwarding cib_modify operation for section status
to all (origin=local/crmd/44)
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.163.4 2
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.5 (null)
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @num_updates=5
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='vm-vdicdb01']/lrm_rsc_op[@id='vm-vdicdb01_last_0']:
@operation_key=vm-vdicdb01_start_0, @operation=start,
@transition-key=5:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@transition-magic=0:0;5:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a,
@call-id=7, @last-run=1504215510, @last-rc-change=1504215510, @exec-time=528
Aug 31 23:38:31 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/44, version=0.163.5)
Aug 31 23:38:31 [1536] vdicnode01 crmd: info: match_graph_event:
Action vm-vdicdb01_start_0 (5) confirmed on vdicnode01 (rc=0)
Aug 31 23:38:31 [1536] vdicnode01 crmd: notice: te_rsc_command:
Initiating monitor operation vm-vdicdb01_monitor_10000 locally on
vdicnode01 | action 6
Aug 31 23:38:31 [1536] vdicnode01 crmd: info: do_lrm_rsc_op:
Performing key=6:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a
op=vm-vdicdb01_monitor_10000
Aug 31 23:38:31 [1536] vdicnode01 crmd: info: process_lrm_event:
Result of monitor operation for vm-vdicdb01 on vdicnode01: 0 (ok) |
call=8 key=vm-vdicdb01_monitor_10000 confirmed=false cib-update=45
Aug 31 23:38:31 [1531] vdicnode01 cib: info:
cib_process_request: Forwarding cib_modify operation for section status
to all (origin=local/crmd/45)
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: --- 0.163.5 2
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op:
Diff: +++ 0.163.6 (null)
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op: +
/cib: @num_updates=6
Aug 31 23:38:31 [1531] vdicnode01 cib: info: cib_perform_op: ++
/cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='vm-vdicdb01']:
<lrm_rsc_op id="vm-vdicdb01_monitor_10000"
operation_key="vm-vdicdb01_monitor_10000" operation="monitor"
crm-debug-origin="do_update_resource" crm_feature_set="3.0.10"
transition-key="6:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
transition-magic="0:0;6:7:0:fe1a9b0a-816c-4b97-96cb-b90dbf71417a"
on_node="vdicnode01" call-id="8" rc-code="0" op-s
Aug 31 23:38:31 [1531] vdicnode01 cib: info:
cib_process_request: Completed cib_modify operation for section status:
OK (rc=0, origin=vdicnode01/crmd/45, version=0.163.6)
Aug 31 23:38:31 [1536] vdicnode01 crmd: info: match_graph_event:
Action vm-vdicdb01_monitor_10000 (6) confirmed on vdicnode01 (rc=0)
Aug 31 23:38:31 [1536] vdicnode01 crmd: notice: run_graph:
Transition 7 (Complete=5, Pending=0, Fired=0, Skipped=0, Incomplete=0,
Source=/var/lib/pacemaker/pengine/pe-error-8.bz2): Complete
Aug 31 23:38:31 [1536] vdicnode01 crmd: info: do_log: Input
I_TE_SUCCESS received in state S_TRANSITION_ENGINE from notify_crmd
Aug 31 23:38:31 [1536] vdicnode01 crmd: notice:
do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE |
input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd
Aug 31 23:38:36 [1531] vdicnode01 cib: info: cib_process_ping:
Reporting our current digest to vdicnode01:
9141ea9880f5a44b133003982d863bc8 for 0.163.6 (0x7f61cec09270 0)
Thanks a lot
2017-08-31 16:20 GMT+02:00 Ken Gaillot <kgaillot at redhat.com>:
> On Thu, 2017-08-31 at 01:13 +0200, Oscar Segarra wrote:
> > Hi,
> >
> >
> > In my environment, I have just two hosts, where qemu-kvm process is
> > launched by a regular user (oneadmin) - open nebula -
> >
> >
> > I have created a VirtualDomain resource that starts and stops the VM
> > perfectly. Nevertheless, when I change the location weight in order to
> > force the migration, It raises a migration failure "error: 1"
> >
> >
> > If I execute the virsh migrate command (that appears in corosync.log)
> > from command line, it works perfectly.
> >
> >
> > Anybody has experienced the same issue?
> >
> >
> > Thanks in advance for your help
>
> If something works from the command line but not when run by a daemon,
> my first suspicion is SELinux. Check the audit log for denials around
> that time.
>
> I'd also check the system log and Pacemaker detail log around that time
> to see if there is any more information.
> --
> Ken Gaillot <kgaillot at redhat.com>
>
>
>
>
>
> _______________________________________________
> Users mailing list: Users at clusterlabs.org
> http://lists.clusterlabs.org/mailman/listinfo/users
>
> Project Home: http://www.clusterlabs.org
> Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf
> Bugs: http://bugs.clusterlabs.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.clusterlabs.org/pipermail/users/attachments/20170831/7e24009f/attachment-0003.html>
More information about the Users
mailing list