[ClusterLabs] VirtualDomain live migration error

Oscar Segarra oscar.segarra at gmail.com
Thu Aug 31 18:26:34 EDT 2017


Hi,

Yes, it is....

The qemu-kvm process is executed by the oneadmin user.

When I cluster tries the live migration, what users do play?

Oneadmin
Root
Hacluster

I have just configured pasworless ssh connection with oneadmin.

Do I need to configure any other passwordless ssh connection with any other
user?

What user executes the virsh migrate - - live?

Is there any way to check ssk keys?

Sorry for all theese questions.

Thanks a lot




El 1 sept. 2017 0:12, "Ken Gaillot" <kgaillot at redhat.com> escribió:

On Thu, 2017-08-31 at 23:45 +0200, Oscar Segarra wrote:
> 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 ]

^^^ There you go. Sounds like the ssh key isn't being accepted. No idea
why though.



> 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
>
>

--
Ken Gaillot <kgaillot at redhat.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.clusterlabs.org/pipermail/users/attachments/20170901/13d5e17b/attachment-0001.html>


More information about the Users mailing list