MINOR: hlua: emit a log instead of an alert for aborted actions due to unavailable...

As reported by Chris Staite in GH #3002, trying to yield from a Lua
action during a client disconnect causes the script to be interrupted
(which is expected) and an alert to be emitted with the error:
"Lua function '%s': yield not allowed".

While this error is well suited for cases where the yield is not expected
at all (ie: when context doesn't allow it) and results from a yield misuse
in the Lua script, it isn't the case when the yield is exceptionnally not
available due to an abort or error in the request/response processing.
Because of that we raise an alert but the user cannot do anything about it
(the script is correct), so it is confusing and polluting the logs.

In this patch we introduce the ACT_OPT_FINAL_EARLY flag which is a
complementary flag to ACT_OPT_FIRST. This flag is set when the
ACT_OPT_FIRST is set earlier than normal (due to error/abort).
hlua_action() then checks for this flag to decide whether an error (alert)
or a simple log message should be emitted when the yield is not available.

It should solve GH #3002. Thanks to Chris Staite (@chrisstaite-menlo) for
having reported the issue and suggested a solution.

diff --git a/include/haproxy/action-t.h b/include/haproxy/action-t.h
index 63925a96fc92fda5a2b6a7520baa92579e116865..b2693ca00df8a27dfeeec12741a79f77364cfc58 100644 (file)
--- a/include/haproxy/action-t.h
+++ b/include/haproxy/action-t.h
@@ -66,7 +66,8 @@ enum act_parse_ret {
 enum act_opt {
        ACT_OPT_NONE  = 0x00000000,  /* no flag */
        ACT_OPT_FINAL = 0x00000001,  /* last call, cannot yield */
-       ACT_OPT_FIRST = 0x00000002,  /* first call for this action */
+       ACT_OPT_FINAL_EARLY = 0x00000002, /* set in addition to ACT_OPT_FINAL if last call occurs earlier than normal due to unexpected IO/error */
+       ACT_OPT_FIRST = 0x00000004,  /* first call for this action */
 };
 
 /* Flags used to describe the action. */

diff --git a/src/hlua.c b/src/hlua.c
index 640743366116ef106b0376232b773fe1437270fd..8e1a54d3a5be513a5481acbec6c6d42a74ff3ee7 100644 (file)
--- a/src/hlua.c
+++ b/src/hlua.c
@@ -11005,8 +11005,24 @@ static enum act_return hlua_action(struct act_rule *rule, struct proxy *px,
        case HLUA_E_YIELD:
          err_yield:
                act_ret = ACT_RET_CONT;
-               SEND_ERR(px, "Lua function '%s': yield not allowed.\n",
-                        rule->arg.hlua_rule->fcn->name);
+               if (flags & ACT_OPT_FINAL_EARLY) {
+                       char *msg = NULL;
+
+                       /* yield not allowed, but it is only caused because ruleset was ended earlier
+                        * than expected, so it is not a misuse of yield in the Lua script: simply emit
+                        * a log
+                        */
+                       memprintf(&msg, "Lua function '%s': unable to yield, aborted Lua execution.\n",
+                                 rule->arg.hlua_rule->fcn->name);
+                       if (msg)
+                               hlua_sendlog(px, LOG_WARNING, msg);
+                       ha_free(&msg);
+               }
+               else {
+                       /* invalid yield use */
+                       SEND_ERR(px, "Lua function '%s': yield not allowed.\n",
+                                rule->arg.hlua_rule->fcn->name);
+               }
                goto end;
 
        case HLUA_E_ERR:

diff --git a/src/http_ana.c b/src/http_ana.c
index f42f47fe02504cf04dbb6116409c7be0ad959a99..f1834e9c581a4b1b56c97d2738a3f19db265e8c3 100644 (file)
--- a/src/http_ana.c
+++ b/src/http_ana.c
@@ -2757,7 +2757,7 @@ static enum rule_result http_req_get_intercept_rule(struct proxy *px, struct lis
        if ((s->scf->flags & SC_FL_ERROR) ||
            ((s->scf->flags & (SC_FL_EOS|SC_FL_ABRT_DONE)) &&
             (px->options & PR_O_ABRT_CLOSE)))
-               act_opts |= ACT_OPT_FINAL;
+               act_opts |= ACT_OPT_FINAL | ACT_OPT_FINAL_EARLY;
 
        /* If "the current_rule_list" match the executed rule list, we are in
         * resume condition. If a resume is needed it is always in the action
@@ -2945,7 +2945,7 @@ static enum rule_result http_res_get_intercept_rule(struct proxy *px, struct lis
        if ((s->scf->flags & SC_FL_ERROR) ||
            ((s->scf->flags & (SC_FL_EOS|SC_FL_ABRT_DONE)) &&
             (px->options & PR_O_ABRT_CLOSE)))
-               act_opts |= ACT_OPT_FINAL;
+               act_opts |= ACT_OPT_FINAL | ACT_OPT_FINAL_EARLY;
 
        /* If "the current_rule_list" match the executed rule list, we are in
         * resume condition. If a resume is needed it is always in the action

diff --git a/src/tcp_rules.c b/src/tcp_rules.c
index a0fc2e74570bd66e8e69935610dbaf1c53cfba63..6076623879de6cac2fb7d5ad62cf286f1b2a3628 100644 (file)
--- a/src/tcp_rules.c
+++ b/src/tcp_rules.c
@@ -124,7 +124,7 @@ int tcp_inspect_request(struct stream *s, struct channel *req, int an_bit)
                partial = SMP_OPT_FINAL;
                /* Action may yield while the inspect_delay is not expired and there is no read error */
                if ((s->scf->flags & SC_FL_ERROR) || !s->be->tcp_req.inspect_delay || tick_is_expired(s->rules_exp, now_ms))
-                       act_opts |= ACT_OPT_FINAL;
+                       act_opts |= ACT_OPT_FINAL | ACT_OPT_FINAL_EARLY;
        }
        else
                partial = 0;
@@ -337,7 +337,7 @@ int tcp_inspect_response(struct stream *s, struct channel *rep, int an_bit)
                partial = SMP_OPT_FINAL;
                /* Action may yield while the inspect_delay is not expired and there is no read error */
                if ((s->scb->flags & SC_FL_ERROR) || !s->be->tcp_rep.inspect_delay || tick_is_expired(s->rules_exp, now_ms))
-                       act_opts |= ACT_OPT_FINAL;
+                       act_opts |= ACT_OPT_FINAL | ACT_OPT_FINAL_EARLY;
        }
        else
                partial = 0;