DEBUG: mux-spop: Review some trace messages to adjust the message or the level
authorChristopher Faulet <cfaulet@haproxy.com>
Wed, 14 May 2025 07:39:03 +0000 (09:39 +0200)
committerWilly Tarreau <w@1wt.eu>
Thu, 15 May 2025 15:01:44 +0000 (17:01 +0200)
Some trace messages were not really accurrate, reporting a CLOSED connection
while only an error was reported on it. In addition, an TRACE_ERROR() was
used to report a short read on HELLO/DISCONNECT frames header. But it is not
an error. a TRACE_DEVEL() should be used instead.

This patch could be backported to 3.1 to ease future backports.

(cherry picked from commit e2ae8a74e87d32730e3edba26626518fd33e3a58)
Signed-off-by: Willy Tarreau <w@1wt.eu>

src/mux_spop.c

index e6ab213..a1616e8 100644 (file)
@@ -2028,7 +2028,7 @@ static void spop_process_demux(struct spop_conn *spop_conn)
                        TRACE_STATE("receiving AGENT HELLO/DISCONNECT frame header", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR, spop_conn->conn);
                        if (!spop_get_frame_hdr(&spop_conn->dbuf, &hdr)) {
                                spop_conn->flags |= SPOP_CF_DEM_SHORT_READ;
-                               TRACE_ERROR("header frame not available yet", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR, spop_conn->conn);
+                               TRACE_DEVEL("header frame not available yet", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR, spop_conn->conn);
                                goto done;
                        }
 
@@ -2084,7 +2084,7 @@ static void spop_process_demux(struct spop_conn *spop_conn)
                        if ((int)hdr.len < 0 || (int)hdr.len > spop_conn->max_frame_size) {
                                spop_conn_error(spop_conn, SPOP_ERR_BAD_FRAME_SIZE);
                                TRACE_ERROR("invalid SPOP frame length", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
-                               TRACE_STATE("switching to CLOSED", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
+                               TRACE_STATE("switching to ERROR", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
                                break;
                        }
 
@@ -2100,24 +2100,23 @@ static void spop_process_demux(struct spop_conn *spop_conn)
                        if (!(spop_conn->dff & SPOP_FRM_FL_FIN)) {
                                spop_conn_error(spop_conn, SPOP_ERR_FRAG_NOT_SUPPORTED);
                                TRACE_ERROR("frame fragmentation not supported", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
-                               TRACE_STATE("switching to CLOSED", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
+                               TRACE_STATE("switching to ERROR", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
                                break;
                        }
                        if (!spop_conn->dsi && spop_conn->dft == SPOP_FRM_T_AGENT_ACK) {
                                spop_conn_error(spop_conn, SPOP_ERR_INVALID);
                                TRACE_ERROR("invalid SPOP frame (ACK && dsi == 0)", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
-                               TRACE_STATE("switching to CLOSED", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
+                               TRACE_STATE("switching to ERROR", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
                                break;
                        }
                        if (spop_conn->dsi && !spop_conn->dfi) {
                                spop_conn_error(spop_conn, SPOP_ERR_INVALID);
                                TRACE_ERROR("invalid SPOP frame (dsi != 0 && dfi == 0)", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
-                               TRACE_STATE("switching to CLOSED", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
+                               TRACE_STATE("switching to ERROR", SPOP_EV_RX_FRAME|SPOP_EV_RX_FHDR|SPOP_EV_SPOP_CONN_ERR, spop_conn->conn);
                                break;
                        }
                }
 
-
                tmp_spop_strm = spop_conn_st_by_id(spop_conn, spop_conn->dsi);
                if (tmp_spop_strm != spop_strm && spop_strm && spop_strm_sc(spop_strm) &&
                    (b_data(&spop_strm->rxbuf) ||