[ClusterLabs] crm resource stop VirtualDomain - but VirtualDomain shutdown start some minutes later
Ken Gaillot
kgaillot at redhat.com
Tue Feb 15 18:52:53 EST 2022
On Tue, 2022-02-15 at 22:24 +0100, Lentes, Bernd wrote:
> Hi,
>
> i have a weird behaviour in my 2-node-cluster.
> I stopped several VirtualDomains via "crm resource stop
> VirtualDomain", but the respective shutdown starts minutes later.
> All on the same host.
>
> .bash_history:
>
> 3520 2022-02-15 20:55:44 crm resource stop vm_greensql
> 3521 2022-02-15 20:56:34 crm resource stop vm_ssh
> 3522 2022-02-15 20:57:23 crm resource stop vm_sim
> 3523 2022-02-15 20:58:38 crm resource stop vm_mouseidgenes
> 3524 2022-02-15 21:00:24 crm resource stop vm_genetrap
> 3525 2022-02-15 21:01:25 crm resource stop vm_severin
> 3526 2022-02-15 21:01:34 crm resource stop vm_idcc_devel
>
> /var/log/cluster/corosync.log:
>
> Feb 15 20:55:45 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27455.0 2
> Feb 15 20:55:45 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27456.0 138c70d41548c4cb1d767dd578a98b8f
> Feb 15 20:55:45 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27456
> Feb 15 20:55:45 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_gr
> eensql']/meta_attributes[@id='vm_greensql-
> meta_attributes']/nvpair[@id='vm_greensql-meta_attributes-target-
> role']: @value=Stopped
> Feb 15 20:55:45 [15365] ha-idg-2 cib: info:
> cib_process_request: Completed cib_apply_diff operation for
> section 'all': OK (rc=0, origin=ha-idg-1/cibadmin/2,
> version=7.27456.0)
> Feb 15 20:55:45 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_greensql-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27456.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_greensql']/meta_a
> tt
> ributes[@id='vm_greensql-meta_attributes']/nvpair[@id='vm_greensql-
> meta_attributes-target-role'] complete=false
> ...
> Feb 15 20:56:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27456.0 2
> Feb 15 20:56:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27457.0 (null)
> Feb 15 20:56:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27457
> Feb 15 20:56:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_ss
> h']/meta_attributes[@id='vm_ssh-meta_attributes']/nvpair[@id='vm_ssh-
> meta_attributes-target-role']: @value=Stopped
> Feb 15 20:56:35 [15365] ha-idg-2 cib: info:
> cib_process_request: Completed cib_apply_diff operation for
> section 'all': OK (rc=0, origin=ha-idg-1/cibadmin/2,
> version=7.27457.0)
> Feb 15 20:56:35 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_ssh-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27457.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_ssh']/meta_attrib
> utes[@i
> d='vm_ssh-meta_attributes']/nvpair[@id='vm_ssh-meta_attributes-
> target-role'] complete=false
> ...
> Feb 15 20:57:24 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27457.0 2
> Feb 15 20:57:24 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27458.0 7f91d8e52c8ff0887916ad921703fadd
> Feb 15 20:57:24 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27458
> Feb 15 20:57:24 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_si
> m']/meta_attributes[@id='vm_sim-meta_attributes']/nvpair[@id='vm_sim-
> meta_attributes-target-role']: @value=Stopped
> Feb 15 20:57:24 [15365] ha-idg-2 cib: info:
> cib_process_request: Completed cib_apply_diff operation for
> section 'all': OK (rc=0, origin=ha-idg-1/cibadmin/2,
> version=7.27458.0)
> Feb 15 20:57:24 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_sim-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27458.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_sim']/meta_attrib
> utes[@i
> d='vm_sim-meta_attributes']/nvpair[@id='vm_sim-meta_attributes-
> target-role'] complete=false
> ...
> Feb 15 20:58:39 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27458.0 2
> Feb 15 20:58:39 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27459.0 727c5953b33542602028bf903b0578bc
> Feb 15 20:58:39 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27459
> Feb 15 20:58:39 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_mo
> useidgenes']/meta_attributes[@id='vm_mouseidgenes-
> meta_attributes']/nvpair[@id='vm_mouseidgenes-meta_attributes-target-
> role']: @value=Stopped
> Feb 15 20:58:39 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_mouseidgenes-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27459.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_mouseidgenes']/
> meta_attributes[@id='vm_mouseidgenes-
> meta_attributes']/nvpair[@id='vm_mouseidgenes-meta_attributes-target-
> role'] complete=false
> ...
> Feb 15 21:00:25 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27459.0 2
> Feb 15 21:00:25 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27460.0 6892b9e418707b524335a51d07898526
> Feb 15 21:00:25 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27460
> Feb 15 21:00:25 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_ge
> netrap']/meta_attributes[@id='vm_genetrap-
> meta_attributes']/nvpair[@id='vm_genetrap-meta_attributes-target-
> role']: @value=Stopped
> Feb 15 21:00:25 [15365] ha-idg-2 cib: info:
> cib_process_request: Completed cib_apply_diff operation for
> section 'all': OK (rc=0, origin=ha-idg-1/cibadmin/2,
> version=7.27460.0)
> Feb 15 21:00:25 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_genetrap-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27460.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_genetrap']/meta_a
> ttributes[@id='vm_genetrap-meta_attributes']/nvpair[@id='vm_genetrap-
> meta_attributes-target-role'] complete=false
> ...
> Feb 15 21:01:26 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27460.0 2
> Feb 15 21:01:26 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27461.0 1dbf0cc47e1fc3c2d79a8ba24dc9e509
> Feb 15 21:01:26 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27461
> Feb 15 21:01:26 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_se
> verin']/meta_attributes[@id='vm_severin-
> meta_attributes']/nvpair[@id='vm_severin-meta_attributes-target-
> role']: @value=Stopped
> Feb 15 21:01:26 [15365] ha-idg-2 cib: info:
> cib_process_request: Completed cib_apply_diff operation for
> section 'all': OK (rc=0, origin=ha-idg-1/cibadmin/2,
> version=7.27461.0)
> Feb 15 21:01:26 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_severin-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27461.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_severin']/meta_at
> tributes[@id='vm_severin-meta_attributes']/nvpair[@id='vm_severin-
> meta_attributes-target-role'] complete=false
> ...
> Feb 15 21:01:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: --- 7.27461.0 2
> Feb 15 21:01:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: Diff: +++ 7.27462.0 (null)
> Feb 15 21:01:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib: @epoch=27462
> Feb 15 21:01:35 [15365] ha-idg-2 cib: info:
> cib_perform_op: + /cib/configuration/resources/primitive[@id='vm_id
> cc_devel']/meta_attributes[@id='vm_idcc-devel-
> meta_attributes']/nvpair[@id='vm_idcc-devel-meta_attributes-target-
> role']: @value=Stopped
> Feb 15 21:01:35 [15365] ha-idg-2 cib: info:
> cib_process_request: Completed cib_apply_diff operation for
> section 'all': OK (rc=0, origin=ha-idg-1/cibadmin/2,
> version=7.27462.0)
> Feb 15 21:01:35 [15370] ha-idg-2 crmd: info:
> abort_transition_graph: Transition 128 aborted by vm_idcc-devel-
> meta_attributes-target-role doing modify target-role=Stopped:
> Configuration change | cib=7.27462.0 source=te_update_diff_v2:483
> path=/cib/configuration/resources/primitive[@id='vm_idcc_devel']/meta
> _attributes[@id='vm_idcc-devel-meta_attributes']/nvpair[@id='vm_idcc-
> devel-meta_attributes-target-role'] complete=false
>
> And the actual shutdown:
> VirtualDomain(vm_idcc_devel)[20935]: 2022/02/15_21:04:27 INFO:
> Issuing graceful shutdown request for domain vm_idcc_devel.
> VirtualDomain(vm_greensql)[20941]: 2022/02/15_21:04:27 INFO:
> Issuing graceful shutdown request for domain vm_greensql.
> VirtualDomain(vm_ssh)[20947]: 2022/02/15_21:04:27 INFO: Issuing
> graceful shutdown request for domain vm_ssh.
> VirtualDomain(vm_sim)[20934]: 2022/02/15_21:04:27 INFO: Issuing
> graceful shutdown request for domain vm_sim.
> VirtualDomain(vm_genetrap)[20936]: 2022/02/15_21:04:27 INFO:
> Issuing graceful shutdown request for domain vm_genetrap.
> VirtualDomain(vm_severin)[20945]: 2022/02/15_21:04:27 INFO:
> Issuing graceful shutdown request for domain vm_severin.
> VirtualDomain(vm_mouseidgenes)[20937]: 2022/02/15_21:04:27 INFO:
> Issuing graceful shutdown request for domain vm_mouseidgenes.
>
> Any idea ?
> What is about that transition 128, which is aborted ?
A transition is the set of actions that need to be taken in response to
current conditions. A transition is aborted any time conditions change
(here, the target-role being changed in the configuration), so that a
new set of actions can be calculated.
Someone once defined a transition as an "action plan", and I'm tempted
to use that instead. Plus maybe replace "aborted" with "interrupted",
so then we'd have "Action plan interrupted" which is maybe a little
more understandable.
>
> Transition 128 is finished:
> Feb 15 21:04:26 [15370] ha-idg-2 crmd: notice:
> run_graph: Transition 128 (Complete=1, Pending=0, Fired=0,
> Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-
> 3548.bz2): Complete
>
> And one second later the shutdown starts. Is that normal that there
> is such a big time gap ?
>
> Bernd
No, there should be another transition calculated (with a "saving
input" message) immediately after the original transition is aborted.
What's the timestamp on that?
--
Ken Gaillot <kgaillot at redhat.com>
More information about the Users
mailing list