[ClusterLabs] crm resource stop VirtualDomain - but VirtualDomain shutdown start some minutes later

[Lentes, Bernd]

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_greensql']/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_att
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_ssh']/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_attributes[@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_sim']/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_attributes[@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_mouseidgenes']/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_genetrap']/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_attributes[@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_severin']/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_attributes[@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_idcc_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 ?

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

-- 

Bernd Lentes 
System Administrator 
Institute for Metabolism and Cell Death (MCD) 
Building 25 - office 122 
HelmholtzZentrum München 
bernd.lentes at helmholtz-muenchen.de 
phone: +49 89 3187 1241 
fax: +49 89 3187 2294 
http://www.helmholtz-muenchen.de/mcd 


Public key: 

30 82 01 0a 02 82 01 01 00 b3 72 3e ce 2c 0a 6f 58 49 2c 92 23 c7 b9 c1 ff 6c 3a 53 be f7 9e e9 24 b7 49 fa 3c e8 de 28 85 2c d3 ed f7 70 03 3f 4d 82 fc cc 96 4f 18 27 1f df 25 b3 13 00 db 4b 1d ec 7f 1b cf f9 cd e8 5b 1f 11 b3 a7 48 f8 c8 37 ed 41 ff 18 9f d7 83 51 a9 bd 86 c2 32 b3 d6 2d 77 ff 32 83 92 67 9e ae ae 9c 99 ce 42 27 6f bf d8 c2 a1 54 fd 2b 6b 12 65 0e 8a 79 56 be 53 89 70 51 02 6a eb 76 b8 92 25 2d 88 aa 57 08 42 ef 57 fb fe 00 71 8e 90 ef b2 e3 22 f3 34 4f 7b f1 c4 b1 7c 2f 1d 6f bd c8 a6 a1 1f 25 f3 e4 4b 6a 23 d3 d2 fa 27 ae 97 80 a3 f0 5a c4 50 4a 45 e3 45 4d 82 9f 8b 87 90 d0 f9 92 2d a7 d2 67 53 e6 ae 1e 72 3e e9 e0 c9 d3 1c 23 e0 75 78 4a 45 60 94 f8 e3 03 0b 09 85 08 d0 6c f3 ff ce fa 50 25 d9 da 81 7b 2a dc 9e 28 8b 83 04 b4 0a 9f 37 b8 ac 58 f1 38 43 0e 72 af 02 03 01 00 01
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 2217 bytes
Desc: S/MIME Cryptographic Signature
URL: <https://lists.clusterlabs.org/pipermail/users/attachments/20220215/d6700e98/attachment.p7s>