[ClusterLabs] Antw: [EXT] Heads up for ldirectord in SLES12 SP5 "Use of uninitialized value $ip_port in pattern match (m//) at /usr/sbin/ldirectord line 1830"
Hi!
FYI, here is a copy what I had sent to SUSE support (stating "Because of the
very same DNS resolution problem, stopping also failed"; should a temporary DNS
resolving problem cause a resource stop to fail and cause node fencing in turn?
I don't think so!):
---
The problem is the Perl code that most likely was never tested to handle a
failure of or in ld_gethostservbyname():
FIRST it should be checked whether a value was returned at all; if not there
is a failure in resolution.
In turn a failure in resolution could mean two tings:
1) The names in the configuration are not correct and will never resolve.
2) A temporary failure of some kind caused a failure and the configuration IS
CORRECT.
Clearly the bad case here was 2).
Also looking at the code I wonder why it does not handle things like this:
$ip_port=&ld_gethostservbyname($ip_port, $vsrv->{protocol},
$af);
if ($ip_port) {
if ($ip_port =~ /^(.+):([^:]+)$/) { # replacing the split
($vsrv->{server}, $vsrv->{port}) = ($1, $2);
# this should also handle the case "$ip_port =~
/(\[[0-9A-Fa-f:]+\]):(\d+)/"
} else {
# error "unexpected return from ld_gethostservbyname"
}
} else {
# error "failed to resolve ..."
# here it's unfortunate that the original $ip_port is
lost,
# so it cannot be part of the error message
}
Despite of that is that the critical part was that the "stop" operation SEEMED
to have failed, causing fencing.
Regardless of the success of resolving the names ldirector should be able to
stop!
---
Opinions?
Regards,
Ulrich
>>> "Ulrich Windl" schrieb am 03.08.2022
um
11:13 in Nachricht <62ea3c2c02a10004c...@gwsmtp.uni-regensburg.de>:
> Hi!
>
> I wanted to inform you of an unpleasant bug in ldirectord of SLES12 SP5:
> We had a short network problem while some redundancy paths reconfigured in
> the infrastructure, effectively causing that some network services could not
> be reached.
> Unfortunately ldirectord controlled by the cluster reported a failure (the
> director, not the services being directed to):
>
> h11 crmd[28930]: notice: h11‑prm_lvs_mail_monitor_30:369 [ Use of
> uninitialized value $ip_port in pattern match (m//) at /usr/sbin/ldirectord
> line 1830, line 21. Error [33159] reading file
> /etc/ldirectord/mail.conf at line 10: invalid address for virtual service\n
]
> h11 ldirectord[33266]: Exiting with exit_status 2: config_error:
> Configuration Error
>
> You can guess wat happened:
> Pacemaker tried to recover (stop, then start), but the stop failed, too:
> h11 lrmd[28927]: notice: prm_lvs_mail_stop_0:35047:stderr [ Use of
> uninitialized value $ip_port in pattern match (m//) at /usr/sbin/ldirectord
> line 1830, line 21. ]
> h11 lrmd[28927]: notice: prm_lvs_mail_stop_0:35047:stderr [ Error [36293]
> reading file /etc/ldirectord/mail.conf at line 10: invalid address for
> virtual service ]
> h11 crmd[28930]: notice: Result of stop operation for prm_lvs_mail on h11:
> 1 (unknown error)
>
> A stop failure meant that the node was fenced, interrupting all the other
> services.
>
> Examining the logs I also found this interesting type of error:
> h11 attrd[28928]: notice: Cannot update
> fail‑count‑prm_lvs_rksapds5#monitor_30[monitor]=(null) because peer
> UUID not known (will retry if learned)
>
> Eventually, here's the code that caused the error:
>
> sub _ld_read_config_virtual_resolve
> {
> my($line, $vsrv, $ip_port, $af)=(@_);
>
> if($ip_port){
> $ip_port=&ld_gethostservbyname($ip_port, $vsrv‑>{protocol},
> $af);
> if ($ip_port =~ /(\[[0‑9A‑Fa‑f:]+\]):(\d+)/) {
> $vsrv‑>{server} = $1;
> $vsrv‑>{port} = $2;
> } elsif($ip_port){
> ($vsrv‑>{server}, $vsrv‑>{port}) = split /:/,
$ip_port;
> }
> else {
> &config_error($line,
> "invalid address for virtual service");
> }
> ...
>
> The value returned by ld_gethostservbyname is undefined. I also wonder what
> the program logic is:
> If the host looks like an hex address in square brackets, host and port are
> split at the colon; otherwise host and port are split at the colon.
> Why not split simply at the last colon if the value is defined, AND THEN
> check if the components look OK?
>
> So the "invalid address for virtual service" is only invalid when the
> resolver service (e.g. via LDAP) is unavailable.
> I used host and service names for readability.
>
> (I reported the issue to SLES support)
>
> Regards,
> Ulrich
>
>
>
> ___
> Manage your subscription:
> https://lists.clusterlabs.org/mailman/li
[ClusterLabs] Antw: [EXT] cluster log not unambiguous about state of VirtualDomains
>>> "Lentes, Bernd" schrieb am 03.08.2022 um 17:01 in Nachricht <987208047.150503130.1659538882681.javamail.zim...@helmholtz-muenchen.de>: > Hi, > > i have a strange behaviour found in the cluster log > (/var/log/cluster/corosync.log). > I KNOW that i put one node (ha-idg-2) in standby mode and stopped the > pacemaker service on that node: > The history of the shell says: > 993 2022-08-02 18:28:25 crm node standby ha-idg-2 > 994 2022-08-02 18:28:58 systemctl stop pacemaker.service I think the logs of ha-idg-2 around these commands would be interesting, as wel las any pacemaker messages (if any) in between. BTW, a different, but also confusing message: Aug 03 15:16:58 h12 pengine[14727]: warning: Processing failed start of prm_cwd_w49_sap on h12: unknown error Aug 03 15:16:58 h12 pengine[14727]: warning: Forcing prm_cwd_w49_sap away from h12 after 100 failures (max=3) The point here is that h12 is the only active node in a two-node cluster, so "forcing away" probably means "stop": # crm_mon -1Arfj |grep w49 prm_cwd_w49_sap(ocf::heartbeat:SAPInstance): Stopped Sometimes these messages can be confusing. You could have provided the crm_mon output too, BTW. Regards, Ulrich > > Later on i had some trouble with high load. > I found contradictory entries in the log on the DC (ha-idg-1): > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-documents-oo active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-documents-oo active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-mausdb active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-mausdb active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-photoshop active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-photoshop active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-encore active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-encore active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource dlm:1 active on ha-idg-2 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-seneca active on ha-idg-2<=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-pathway active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-dietrich active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-sim active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-ssh active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-nextcloud active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource fs_ocfs2:1 active on ha-idg-2 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource gfs2_share:1 active on ha-idg-2 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-geneious active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource gfs2_snap:1 active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource vm-geneious-license-mcd active on > ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: >Operation monitor found resource clvmd:1 active on ha-idg-2 > > The log says some VirtualDomains are running on ha-idg-2 !?! > > But just a few lines later the log says all VirtualDomains are running on > ha-idg-1: > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: > vm-mausdb (ocf::lentes:VirtualDomain):Started ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: > vm-sim (ocf::lentes:VirtualDomain):Started ha-idg-1 <=== > Aug 03 00:14:04 [19367] ha-idg
Re: [ClusterLabs] 2-Node Cluster - fencing with just one node running ?
On Wed, Aug 3, 2022 at 2:59 PM Lentes, Bernd wrote: > > Hi, > > i have the following situation: > 2-node Cluster, just one node running (ha-idg-1). > The second node (ha-idg-2) is in standby. DLM monitor on ha-idg-1 times out. > Cluster tries to restart all services depending on DLM: > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Recoverdlm:0 ( ha-idg-1 ) > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartclvmd:0 ( ha-idg-1 ) due to required dlm:0 > start > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartgfs2_share:0( ha-idg-1 ) due to required clvmd:0 > start > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartgfs2_snap:0 ( ha-idg-1 ) due to required > gfs2_share:0 start > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartfs_ocfs2:0 ( ha-idg-1 ) due to required > gfs2_snap:0 start > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > dlm:1 (Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > clvmd:1 (Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > gfs2_share:1(Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > gfs2_snap:1 (Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > fs_ocfs2:1 (Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > ClusterMon-SMTP:0 (Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave > ClusterMon-SMTP:1 (Stopped) > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartvm-mausdb ( ha-idg-1 ) due to required > cl_share running > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartvm-sim ( ha-idg-1 ) due to required > cl_share running > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartvm-geneious ( ha-idg-1 ) due to required > cl_share running > Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* > Restartvm-idcc-devel ( ha-idg-1 ) due to required > cl_share running > ... > > restart of vm-mausdb failed, stop timed out: > VirtualDomain(vm-mausdb)[32415]:2022/08/03_01:19:06 INFO: Issuing > forced shutdown (destroy) request for domain vm-mausdb. > Aug 03 01:19:11 [19365] ha-idg-1 lrmd: warning: > child_timeout_callback: vm-mausdb_stop_0 process (PID 32415) timed out > Aug 03 01:19:11 [19365] ha-idg-1 lrmd: warning: operation_finished: > vm-mausdb_stop_0:32415 - timed out after 72ms > ... > Aug 03 01:19:14 [19367] ha-idg-1pengine: warning: pe_fence_node: > Cluster node ha-idg-1 will be fenced: vm-mausdb failed there > Aug 03 01:19:15 [19368] ha-idg-1 crmd: notice: te_fence_node: > Requesting fencing (Off) of node ha-idg-1 | action=8 timeout=6 > > I have two fencing resources defined. One for ha-idg-1, one for ha-idg-2. > Both are HP ILO network adapters. > I have two location constraints: both take care that the resource for fencing > node ha-idg-1 is running on ha-idg-2 and vice versa. Such constraints are unnecessary. Let's say we have two stonith devices called "fence_dev1" and "fence_dev2" that fence nodes 1 and 2, respectively. If node 2 needs to be fenced, and fence_dev2 is running on node 2, node 1 will still use fence_dev2 to fence node 2. The current location of the stonith device only tells us which node is running the recurring monitor operation for that stonith device. The device is available to ALL nodes, unless it's disabled or it's banned from a given node. So these constraints serve no purpose in most cases. If you ban fence_dev2 from node 1, then node 1 won't be able to use fence_dev2 to fence node 2. Likewise, if you ban fence_dev1 from node 1, then node 1 won't be able to use fence_dev1 to fence itself. Usually that's unnecessary anyway, but it may be preferable to power ourselves off if we're the last remaining node and a stop operation fails. > I never thought that it's necessary that a node has to fence itself. > So now ha-idg-2 is in standby, there is no fence device to stonith ha-idg-1. If ha-idg-2 is in standby, it can still fence ha-idg-1. Since it sounds like you've banned fence_ilo_ha-idg-1 from ha-idg-1, so that it can't run anywhere when ha-idg-2 is in standby, I'm not sure off the top of my head whether fence_ilo_ha-idg-1 is available in this situation. It may not be. A solution would be to stop banning the stonith devices from their respective nodes. Surely if fence_ilo_ha
[ClusterLabs] 2-Node Cluster - fencing with just one node running ?
Hi, i have the following situation: 2-node Cluster, just one node running (ha-idg-1). The second node (ha-idg-2) is in standby. DLM monitor on ha-idg-1 times out. Cluster tries to restart all services depending on DLM: Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Recoverdlm:0 ( ha-idg-1 ) Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartclvmd:0 ( ha-idg-1 ) due to required dlm:0 start Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartgfs2_share:0( ha-idg-1 ) due to required clvmd:0 start Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartgfs2_snap:0 ( ha-idg-1 ) due to required gfs2_share:0 start Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartfs_ocfs2:0 ( ha-idg-1 ) due to required gfs2_snap:0 start Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave dlm:1 (Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave clvmd:1 (Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave gfs2_share:1(Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave gfs2_snap:1 (Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave fs_ocfs2:1 (Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave ClusterMon-SMTP:0 (Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: info: LogActions: Leave ClusterMon-SMTP:1 (Stopped) Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartvm-mausdb ( ha-idg-1 ) due to required cl_share running Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartvm-sim ( ha-idg-1 ) due to required cl_share running Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartvm-geneious ( ha-idg-1 ) due to required cl_share running Aug 03 01:07:11 [19367] ha-idg-1pengine: notice: LogAction:* Restartvm-idcc-devel ( ha-idg-1 ) due to required cl_share running ... restart of vm-mausdb failed, stop timed out: VirtualDomain(vm-mausdb)[32415]:2022/08/03_01:19:06 INFO: Issuing forced shutdown (destroy) request for domain vm-mausdb. Aug 03 01:19:11 [19365] ha-idg-1 lrmd: warning: child_timeout_callback: vm-mausdb_stop_0 process (PID 32415) timed out Aug 03 01:19:11 [19365] ha-idg-1 lrmd: warning: operation_finished: vm-mausdb_stop_0:32415 - timed out after 72ms ... Aug 03 01:19:14 [19367] ha-idg-1pengine: warning: pe_fence_node: Cluster node ha-idg-1 will be fenced: vm-mausdb failed there Aug 03 01:19:15 [19368] ha-idg-1 crmd: notice: te_fence_node: Requesting fencing (Off) of node ha-idg-1 | action=8 timeout=6 I have two fencing resources defined. One for ha-idg-1, one for ha-idg-2. Both are HP ILO network adapters. I have two location constraints: both take care that the resource for fencing node ha-idg-1 is running on ha-idg-2 and vice versa. I never thought that it's necessary that a node has to fence itself. So now ha-idg-2 is in standby, there is no fence device to stonith ha-idg-1. Aug 03 01:19:58 [19364] ha-idg-1 stonith-ng: notice: log_operation: Operation 'Off' [20705] (call 2 from crmd.19368) for host 'ha-idg-1' with device 'fence_ilo_ha-idg-2' returned: 0 (OK) So the cluster starts the resource running on ha-idg-1 and cut off ha-idg-2, which isn't necessary. Finally the cluster seems to realize that something went wrong: Aug 03 01:19:58 [19368] ha-idg-1 crmd: crit: tengine_stonith_notify: We were allegedly just fenced by ha-idg-1 for ha-idg-1! So my question now: is it necessary to have a fencing device that a node can commit suicide ? Bernd -- Bernd Lentes System Administrator Institute for Metabolism and Cell Death (MCD) Building 25 - office 122 HelmholtzZentrum München bernd.len...@helmholtz-muenchen.de phone: +49 89 3187 1241 +49 89 3187 49123 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
Re: [ClusterLabs] cluster log not unambiguous about state of VirtualDomains
The "found ... active" messages mean that it was the case at some point, not necessarily currently. Newer versions log much better messages like: info: Probe found rsc1 active on node1 at Aug 1 15:41:34 2022 so you can see it was a historical result. The later "Started" messages are where the cluster believes the resources are currently. On Wed, 2022-08-03 at 17:01 +0200, Lentes, Bernd wrote: > Hi, > > i have a strange behaviour found in the cluster log > (/var/log/cluster/corosync.log). > I KNOW that i put one node (ha-idg-2) in standby mode and stopped the > pacemaker service on that node: > The history of the shell says: > 993 2022-08-02 18:28:25 crm node standby ha-idg-2 > 994 2022-08-02 18:28:58 systemctl stop pacemaker.service > > Later on i had some trouble with high load. > I found contradictory entries in the log on the DC (ha-idg-1): > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm- > documents-oo active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm- > documents-oo active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-mausdb > active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-mausdb > active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm- > photoshop active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm- > photoshop active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-encore > active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-encore > active on ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource dlm:1 > active on ha-idg-2 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-seneca > active on ha-idg-2<=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-pathway > active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-dietrich > active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-sim > active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-ssh > active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm- > nextcloud active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource fs_ocfs2:1 > active on ha-idg-2 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource > gfs2_share:1 active on ha-idg-2 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm-geneious > active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource gfs2_snap:1 > active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource vm- > geneious-license-mcd active on ha-idg-2 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > determine_op_status: Operation monitor found resource clvmd:1 > active on ha-idg-2 > > The log says some VirtualDomains are running on ha-idg-2 !?! > > But just a few lines later the log says all VirtualDomains are > running on ha-idg-1: > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > common_print:vm- > mausdb (ocf::lentes:VirtualDomain):Started ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > common_print:vm-sim (ocf::lentes:VirtualDomain):Started ha- > idg-1 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > common_print:vm- > geneious (ocf::lentes:VirtualDomain):Started ha-idg-1 <=== > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > common_print:vm-idcc- > devel (ocf::lentes:VirtualDomain):Started ha-idg-1 > Aug 03 00:14:04 [19367] ha-idg-1pengine: info: > common_print:vm- > genetrap (ocf::lentes:VirtualDomain):Started ha-idg-1 > Aug 03 00:14:04 [19367] ha-i
[ClusterLabs] cluster log not unambiguous about state of VirtualDomains
Hi, i have a strange behaviour found in the cluster log (/var/log/cluster/corosync.log). I KNOW that i put one node (ha-idg-2) in standby mode and stopped the pacemaker service on that node: The history of the shell says: 993 2022-08-02 18:28:25 crm node standby ha-idg-2 994 2022-08-02 18:28:58 systemctl stop pacemaker.service Later on i had some trouble with high load. I found contradictory entries in the log on the DC (ha-idg-1): Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-documents-oo active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-documents-oo active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-mausdb active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-mausdb active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-photoshop active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-photoshop active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-encore active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-encore active on ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource dlm:1 active on ha-idg-2 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-seneca active on ha-idg-2<=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-pathway active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-dietrich active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-sim active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-ssh active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-nextcloud active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource fs_ocfs2:1 active on ha-idg-2 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource gfs2_share:1 active on ha-idg-2 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-geneious active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource gfs2_snap:1 active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource vm-geneious-license-mcd active on ha-idg-2 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: determine_op_status: Operation monitor found resource clvmd:1 active on ha-idg-2 The log says some VirtualDomains are running on ha-idg-2 !?! But just a few lines later the log says all VirtualDomains are running on ha-idg-1: Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-mausdb (ocf::lentes:VirtualDomain):Started ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print:vm-sim (ocf::lentes:VirtualDomain):Started ha-idg-1 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-geneious (ocf::lentes:VirtualDomain):Started ha-idg-1 <=== Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-idcc-devel (ocf::lentes:VirtualDomain):Started ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-genetrap (ocf::lentes:VirtualDomain):Started ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-mouseidgenes (ocf::lentes:VirtualDomain):Started ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-greensql (ocf::lentes:VirtualDomain):Started ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: vm-severin (ocf::lentes:VirtualDomain):Started ha-idg-1 Aug 03 00:14:04 [19367] ha-idg-1pengine: info: common_print: ping_19216810010(ocf::pacemaker:ping): Stopped (disabled) Aug 03 00:14:04 [19367] ha-idg-1pengine: in
Re: [ClusterLabs] Antw: [EXT] Re: Q: About a false negative of storage_mon
On Wed, Aug 3, 2022 at 4:02 PM Ulrich Windl wrote: > > >>> Klaus Wenninger schrieb am 03.08.2022 um 15:51 in > Nachricht > : > > On Tue, Aug 2, 2022 at 4:10 PM Ken Gaillot wrote: > >> > >> On Tue, 2022-08-02 at 19:13 +0900, 井上和徳 wrote: > >> > Hi, > >> > > >> > Since O_DIRECT is not specified in open() [1], it reads the buffer > >> > cache and > >> > may result in a false negative. I fear that this possibility > >> > increases > >> > in environments with large buffer cache and running disk-reading > >> > applications > >> > such as database. > >> > > >> > So, I think it's better to specify O_RDONLY|O_DIRECT, but what about > >> > it? > >> > (in this case, lseek() processing is unnecessary.) > >> > > >> > # I am ready to create a patch that works with O_DIRECT. Also, I > >> > wouldn't mind > >> > # a "change to add a new mode of inspection with O_DIRECT > >> > # (add a option to storage_mon) while keeping the current inspection > >> > process". > >> > > >> > [1] > >> > > > > https://github.com/ClusterLabs/resource-agents/blob/main/tools/storage_mon.c# > > > L47-L90 > >> > > >> > Best Regards, > >> > Kazunori INOUE > >> > >> I agree, it makes sense to use O_DIRECT when available. I don't think > >> an option is necessary. > > > > Might as well be interesting to adjust block-size/alignment to the > > device. > > Another consideration could be to on top directly access the block-layer > > using aio. > > Again AIO is POSIX; it depends on the implementation what it really does. Wasn't speaking of the Linux POSIX AIO implementation in userspace (guess that is still the case) but what is available as syscalls (io_submit, io_setup, io_cancel, io_destroy, io_getevents) that is afaik Linux proprietary and can't be wrapped into the Posix interface. > > > Both is being done in sbd (storage-based-death) and yes it as well > > adds Linux specific stuff that might have to be conditional for other OSs. > > > > Klaus > > > >> > >> However, O_DIRECT is not available on all OSes, so the configure script > >> should detect support. Also, it is not supported by all filesystems, so > >> if the open fails, we should retry without O_DIRECT. > >> -- > >> Ken Gaillot > >> > >> ___ > >> Manage your subscription: > >> https://lists.clusterlabs.org/mailman/listinfo/users > >> > >> ClusterLabs home: https://www.clusterlabs.org/ > > > > ___ > > Manage your subscription: > > https://lists.clusterlabs.org/mailman/listinfo/users > > > > ClusterLabs home: https://www.clusterlabs.org/ > > > > ___ > Manage your subscription: > https://lists.clusterlabs.org/mailman/listinfo/users > > ClusterLabs home: https://www.clusterlabs.org/ ___ Manage your subscription: https://lists.clusterlabs.org/mailman/listinfo/users ClusterLabs home: https://www.clusterlabs.org/
[ClusterLabs] Antw: [EXT] Re: Q: About a false negative of storage_mon
>>> Klaus Wenninger schrieb am 03.08.2022 um 15:51 in Nachricht : > On Tue, Aug 2, 2022 at 4:10 PM Ken Gaillot wrote: >> >> On Tue, 2022-08-02 at 19:13 +0900, 井上和徳 wrote: >> > Hi, >> > >> > Since O_DIRECT is not specified in open() [1], it reads the buffer >> > cache and >> > may result in a false negative. I fear that this possibility >> > increases >> > in environments with large buffer cache and running disk-reading >> > applications >> > such as database. >> > >> > So, I think it's better to specify O_RDONLY|O_DIRECT, but what about >> > it? >> > (in this case, lseek() processing is unnecessary.) >> > >> > # I am ready to create a patch that works with O_DIRECT. Also, I >> > wouldn't mind >> > # a "change to add a new mode of inspection with O_DIRECT >> > # (add a option to storage_mon) while keeping the current inspection >> > process". >> > >> > [1] >> > > https://github.com/ClusterLabs/resource-agents/blob/main/tools/storage_mon.c# > L47-L90 >> > >> > Best Regards, >> > Kazunori INOUE >> >> I agree, it makes sense to use O_DIRECT when available. I don't think >> an option is necessary. > > Might as well be interesting to adjust block-size/alignment to the > device. > Another consideration could be to on top directly access the block-layer > using aio. Again AIO is POSIX; it depends on the implementation what it really does. > Both is being done in sbd (storage-based-death) and yes it as well > adds Linux specific stuff that might have to be conditional for other OSs. > > Klaus > >> >> However, O_DIRECT is not available on all OSes, so the configure script >> should detect support. Also, it is not supported by all filesystems, so >> if the open fails, we should retry without O_DIRECT. >> -- >> Ken Gaillot >> >> ___ >> Manage your subscription: >> https://lists.clusterlabs.org/mailman/listinfo/users >> >> ClusterLabs home: https://www.clusterlabs.org/ > > ___ > Manage your subscription: > https://lists.clusterlabs.org/mailman/listinfo/users > > ClusterLabs home: https://www.clusterlabs.org/ ___ Manage your subscription: https://lists.clusterlabs.org/mailman/listinfo/users ClusterLabs home: https://www.clusterlabs.org/
Re: [ClusterLabs] Q: About a false negative of storage_mon
On Tue, Aug 2, 2022 at 4:10 PM Ken Gaillot wrote: > > On Tue, 2022-08-02 at 19:13 +0900, 井上和徳 wrote: > > Hi, > > > > Since O_DIRECT is not specified in open() [1], it reads the buffer > > cache and > > may result in a false negative. I fear that this possibility > > increases > > in environments with large buffer cache and running disk-reading > > applications > > such as database. > > > > So, I think it's better to specify O_RDONLY|O_DIRECT, but what about > > it? > > (in this case, lseek() processing is unnecessary.) > > > > # I am ready to create a patch that works with O_DIRECT. Also, I > > wouldn't mind > > # a "change to add a new mode of inspection with O_DIRECT > > # (add a option to storage_mon) while keeping the current inspection > > process". > > > > [1] > > https://github.com/ClusterLabs/resource-agents/blob/main/tools/storage_mon.c#L47-L90 > > > > Best Regards, > > Kazunori INOUE > > I agree, it makes sense to use O_DIRECT when available. I don't think > an option is necessary. Might as well be interesting to adjust block-size/alignment to the device. Another consideration could be to on top directly access the block-layer using aio. Both is being done in sbd (storage-based-death) and yes it as well adds Linux specific stuff that might have to be conditional for other OSs. Klaus > > However, O_DIRECT is not available on all OSes, so the configure script > should detect support. Also, it is not supported by all filesystems, so > if the open fails, we should retry without O_DIRECT. > -- > Ken Gaillot > > ___ > Manage your subscription: > https://lists.clusterlabs.org/mailman/listinfo/users > > ClusterLabs home: https://www.clusterlabs.org/ ___ Manage your subscription: https://lists.clusterlabs.org/mailman/listinfo/users ClusterLabs home: https://www.clusterlabs.org/
[ClusterLabs] Heads up for ldirectord in SLES12 SP5 "Use of uninitialized value $ip_port in pattern match (m//) at /usr/sbin/ldirectord line 1830"
Hi!
I wanted to inform you of an unpleasant bug in ldirectord of SLES12 SP5:
We had a short network problem while some redundancy paths reconfigured in the
infrastructure, effectively causing that some network services could not be
reached.
Unfortunately ldirectord controlled by the cluster reported a failure (the
director, not the services being directed to):
h11 crmd[28930]: notice: h11-prm_lvs_mail_monitor_30:369 [ Use of
uninitialized value $ip_port in pattern match (m//) at /usr/sbin/ldirectord
line 1830, line 21. Error [33159] reading file
/etc/ldirectord/mail.conf at line 10: invalid address for virtual service\n ]
h11 ldirectord[33266]: Exiting with exit_status 2: config_error: Configuration
Error
You can guess wat happened:
Pacemaker tried to recover (stop, then start), but the stop failed, too:
h11 lrmd[28927]: notice: prm_lvs_mail_stop_0:35047:stderr [ Use of
uninitialized value $ip_port in pattern match (m//) at /usr/sbin/ldirectord
line 1830, line 21. ]
h11 lrmd[28927]: notice: prm_lvs_mail_stop_0:35047:stderr [ Error [36293]
reading file /etc/ldirectord/mail.conf at line 10: invalid address for virtual
service ]
h11 crmd[28930]: notice: Result of stop operation for prm_lvs_mail on h11: 1
(unknown error)
A stop failure meant that the node was fenced, interrupting all the other
services.
Examining the logs I also found this interesting type of error:
h11 attrd[28928]: notice: Cannot update
fail-count-prm_lvs_rksapds5#monitor_30[monitor]=(null) because peer UUID
not known (will retry if learned)
Eventually, here's the code that caused the error:
sub _ld_read_config_virtual_resolve
{
my($line, $vsrv, $ip_port, $af)=(@_);
if($ip_port){
$ip_port=&ld_gethostservbyname($ip_port, $vsrv->{protocol},
$af);
if ($ip_port =~ /(\[[0-9A-Fa-f:]+\]):(\d+)/) {
$vsrv->{server} = $1;
$vsrv->{port} = $2;
} elsif($ip_port){
($vsrv->{server}, $vsrv->{port}) = split /:/, $ip_port;
}
else {
&config_error($line,
"invalid address for virtual service");
}
...
The value returned by ld_gethostservbyname is undefined. I also wonder what the
program logic is:
If the host looks like an hex address in square brackets, host and port are
split at the colon; otherwise host and port are split at the colon.
Why not split simply at the last colon if the value is defined, AND THEN check
if the components look OK?
So the "invalid address for virtual service" is only invalid when the resolver
service (e.g. via LDAP) is unavailable.
I used host and service names for readability.
(I reported the issue to SLES support)
Regards,
Ulrich
___
Manage your subscription:
https://lists.clusterlabs.org/mailman/listinfo/users
ClusterLabs home: https://www.clusterlabs.org/
[ClusterLabs] Antw: Re: Antw: [EXT] Re: Q: About a false negative of storage_mon
>>> Andrei Borzenkov schrieb am 03.08.2022 um 08:58 in Nachricht : > On 03.08.2022 09:02, Ulrich Windl wrote: > Ken Gaillot schrieb am 02.08.2022 um 16:09 in >> Nachricht >> <0a2125a43bbfc09d2ca5bad1a693710f00e33731.ca...@redhat.com>: >>> On Tue, 2022-08-02 at 19:13 +0900, 井上和徳 wrote: Hi, Since O_DIRECT is not specified in open() [1], it reads the buffer cache and may result in a false negative. I fear that this possibility increases in environments with large buffer cache and running disk-reading applications such as database. So, I think it's better to specify O_RDONLY|O_DIRECT, but what about it? (in this case, lseek() processing is unnecessary.) # I am ready to create a patch that works with O_DIRECT. Also, I wouldn't mind # a "change to add a new mode of inspection with O_DIRECT # (add a option to storage_mon) while keeping the current inspection process". [1] >>> >> > https://github.com/ClusterLabs/resource-agents/blob/main/tools/storage_mon.c# >> >>> L47-L90 Best Regards, Kazunori INOUE >>> >>> I agree, it makes sense to use O_DIRECT when available. I don't think >>> an option is necessary. >>> >>> However, O_DIRECT is not available on all OSes, so the configure script >>> should detect support. Also, it is not supported by all filesystems, so >>> if the open fails, we should retry without O_DIRECT. >> >> I just looked it up: It seems POSIX has O_RSYNC and O_SYNC and O_DSYNC) >> instead. > > That is something entirely different. O_SYNC etc are about *file system > level*, while O_DIRECT is about *device* level. O_DIRECT makes process > to talk directly to device. It is unclear whether this is side effect of > implementation or intentional. Well the process still uses the filesystem API to open the device, so I wonder whether it makes a big difference if O_SYNC operate on the filesystem level or the device level. Also if the filesystem level does not pass on O_DIRECT flags to the device, it'll be kind of useless. OTOH, it's discussable whether an external SAN disk system should bypass ist internal cache and read the data anew from some RAID disks if O_DIRECT is in effect. > >> The buffer cache handling may be different though. >> > > Synchronous operation does not actually imply media access. I'm unsure: I tought of I write with O_DSYNC and then the system has a power failure it's guaranteed that the data is on permanent storage (otherwise it would be kind of useless). > > O_RSYNC: "the operation has been completed or diagnosed if unsuccessful. > The read is complete only when an image of the data has been > successfully transferred to the requesting process". Returning buffered > data satisfies this definition. Besides, Linux does not support O_RSYNC. OK, that's a weak definition, specifically as all normal reads are synchronous anyway. > > O_DSYNC: "the operation has been completed or diagnosed if unsuccessful. > The write is complete only when the data specified in the write request > is successfully transferred and all file system information required to > retrieve the data is successfully transferred". Writing to journal > located on external device seems to comply with this definition. > > O_SYNC simply adds filesystem metadata update completion. > > So no, O_SYNC & Co cannot replace O_DIRECT. I rather meant to say: "It's better than nothing if O_DIRECT is missing" Regards, Ulrich > ___ > Manage your subscription: > https://lists.clusterlabs.org/mailman/listinfo/users > > ClusterLabs home: https://www.clusterlabs.org/ ___ Manage your subscription: https://lists.clusterlabs.org/mailman/listinfo/users ClusterLabs home: https://www.clusterlabs.org/
