[ClusterLabs] Pacemaker's "stonith too many failures" log is not accurate
井上 和徳
inouekazu at intellilink.co.jp
Fri May 26 04:21:06 EDT 2017
Hi Ken,
The cause turned out.
When stonith is executed, stonithd sends results and notifications to crmd.
https://github.com/ClusterLabs/pacemaker/blob/0459f409580f41b35ce8ae31fb22e6370a508dab/fencing/remote.c#L402-L406
- when "result" is sent (calling do_local_reply()), too many stonith failures is checked in too_many_st_failures().
https://github.com/ClusterLabs/pacemaker/blob/0459f409580f41b35ce8ae31fb22e6370a508dab/crmd/te_callbacks.c#L638-L669
- when "notification" is sent (calling do_stonith_notify()), the number of failures is incremented in st_fail_count_increment().
https://github.com/ClusterLabs/pacemaker/blob/0459f409580f41b35ce8ae31fb22e6370a508dab/crmd/te_callbacks.c#L704-L726
From this, since checking is done before incrementing, the number of failures in "Too many failures (10) to fence" log does not match the number of actual failures.
I confirmed that the expected result will be obtained from the following changes.
# git diff
diff --git a/fencing/remote.c b/fencing/remote.c
index 4a47d49..3ff324e 100644
--- a/fencing/remote.c
+++ b/fencing/remote.c
@@ -399,12 +399,12 @@ handle_local_reply_and_notify(remote_fencing_op_t * op, xmlNode * data, int rc)
reply = stonith_construct_reply(op->request, NULL, data, rc);
crm_xml_add(reply, F_STONITH_DELEGATE, op->delegate);
- /* Send fencing OP reply to local client that initiated fencing */
- do_local_reply(reply, op->client_id, op->call_options & st_opt_sync_call, FALSE);
-
/* bcast to all local clients that the fencing operation happend */
do_stonith_notify(0, T_STONITH_NOTIFY_FENCE, rc, notify_data);
+ /* Send fencing OP reply to local client that initiated fencing */
+ do_local_reply(reply, op->client_id, op->call_options & st_opt_sync_call, FALSE);
+
/* mark this op as having notify's already sent */
op->notify_sent = TRUE;
free_xml(reply);
Regards,
Kazunori INOUE
> -----Original Message-----
> From: Ken Gaillot [mailto:kgaillot at redhat.com]
> Sent: Wednesday, May 17, 2017 11:09 PM
> To: users at clusterlabs.org
> Subject: Re: [ClusterLabs] Pacemaker's "stonith too many failures" log is not accurate
>
> On 05/17/2017 04:56 AM, Klaus Wenninger wrote:
> > On 05/17/2017 11:28 AM, 井上 和徳 wrote:
> >> Hi,
> >> I'm testing Pacemaker-1.1.17-rc1.
> >> The number of failures in "Too many failures (10) to fence" log does not match the number of actual failures.
> >
> > Well it kind of does as after 10 failures it doesn't try fencing again
> > so that is what
> > failures stay at ;-)
> > Of course it still sees the need to fence but doesn't actually try.
> >
> > Regards,
> > Klaus
>
> This feature can be a little confusing: it doesn't prevent all further
> fence attempts of the target, just *immediate* fence attempts. Whenever
> the next transition is started for some other reason (a configuration or
> state change, cluster-recheck-interval, node failure, etc.), it will try
> to fence again.
>
> Also, it only checks this threshold if it's aborting a transition
> *because* of this fence failure. If it's aborting the transition for
> some other reason, the number can go higher than the threshold. That's
> what I'm guessing happened here.
>
> >> After the 11th time fence failure, "Too many failures (10) to fence" is output.
> >> Incidentally, stonith-max-attempts has not been set, so it is 10 by default..
> >>
> >> [root at x3650f log]# egrep "Requesting fencing|error: Operation reboot|Stonith failed|Too many failures"
> >> ##Requesting fencing : 1st time
> >> May 12 05:51:47 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:52:52 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.8415167d: No data available
> >> May 12 05:52:52 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 2nd time
> >> May 12 05:52:52 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:53:56 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.53d3592a: No data available
> >> May 12 05:53:56 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 3rd time
> >> May 12 05:53:56 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:55:01 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.9177cb76: No data available
> >> May 12 05:55:01 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 4th time
> >> May 12 05:55:01 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:56:05 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.946531cb: No data available
> >> May 12 05:56:05 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 5th time
> >> May 12 05:56:05 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:57:10 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.278b3c4b: No data available
> >> May 12 05:57:10 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 6th time
> >> May 12 05:57:10 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:58:14 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for crmd.5269 at rhel73-1.7a49aebb:
> No data available
> >> May 12 05:58:14 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 7th time
> >> May 12 05:58:14 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 05:59:19 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.83421862: No data available
> >> May 12 05:59:19 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 8th time
> >> May 12 05:59:19 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 06:00:24 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for crmd.5269 at rhel73-1.afd7ef98:
> No data available
> >> May 12 06:00:24 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 9th time
> >> May 12 06:00:24 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 06:01:28 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.3b033dbe: No data available
> >> May 12 06:01:28 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 10th time
> >> May 12 06:01:28 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 06:02:33 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for
> crmd.5269 at rhel73-1.5447a345: No data available
> >> May 12 06:02:33 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >> ## 11th time
> >> May 12 06:02:33 rhel73-1 crmd[5269]: notice: Requesting fencing (reboot) of node rhel73-2
> >> May 12 06:03:37 rhel73-1 stonith-ng[5265]: error: Operation reboot of rhel73-2 by rhel73-1 for crmd.5269 at rhel73-1.db50c21a:
> No data available
> >> May 12 06:03:37 rhel73-1 crmd[5269]: warning: Too many failures (10) to fence rhel73-2, giving up
> >> May 12 06:03:37 rhel73-1 crmd[5269]: notice: Transition aborted: Stonith failed
> >>
> >> Regards,
> >> Kazunori INOUE
>
> _______________________________________________
> 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
More information about the Users
mailing list