MINOR: mux-quic: measure QCS lifetime and its blocking state

Reuse newly defined tot_time structure to measure various values related
to a QCS lifetime.

First, a timer is used to comptabilize the total QCS lifetime. Then, two
other timers are used to account the total time during which Tx from
stream layer to MUX is blocked, either on lack of buffer or due to
flow-control.

These three timers are reported in qmux_dump_qcs_info(). Thus, they are
available in traces and for QUIC MUX debug string sample.

diff --git a/include/haproxy/mux_quic-t.h b/include/haproxy/mux_quic-t.h
index daf39f1e87aac7e51e1a6e9928c9ca097bdd9d80..ee3fbe54c0f60b7c03539ab1f228eebfb6d73243 100644 (file)
--- a/include/haproxy/mux_quic-t.h
+++ b/include/haproxy/mux_quic-t.h
@@ -17,6 +17,7 @@
 #include <haproxy/quic_frame-t.h>
 #include <haproxy/quic_stream-t.h>
 #include <haproxy/stconn-t.h>
+#include <haproxy/time-t.h>
 
 /* Stream types */
 enum qcs_type {
@@ -156,6 +157,12 @@ struct qcs {
        uint64_t err; /* error code to transmit via RESET_STREAM */
 
        int start; /* base timestamp for http-request timeout */
+
+       struct {
+               struct tot_time base; /* total QCS lifetime */
+               struct tot_time buf;  /* stream to QCS send blocked on buffer */
+               struct tot_time fctl; /* stream to QCS send blocked on flow-control */
+       } timer;
 };
 
 /* Used as qcc_app_ops.close callback argument. */

diff --git a/src/mux_quic.c b/src/mux_quic.c
index ddaea06228e387bf2054c7920a9729c2c2f5bd0d..54574ebe4ea99fe45b60b68a7271a058685529d0 100644 (file)
--- a/src/mux_quic.c
+++ b/src/mux_quic.c
@@ -149,6 +149,12 @@ static struct qcs *qcs_new(struct qcc *qcc, uint64_t id, enum qcs_type type)
 
        qcs->err = 0;
 
+       /* Reset all timers and start base one. */
+       tot_time_reset(&qcs->timer.base);
+       tot_time_reset(&qcs->timer.buf);
+       tot_time_reset(&qcs->timer.fctl);
+       tot_time_start(&qcs->timer.base);
+
        qcs->sd = sedesc_new();
        if (!qcs->sd)
                goto err;
@@ -534,6 +540,7 @@ int qcc_notify_buf(struct qcc *qcc)
        if (!LIST_ISEMPTY(&qcc->buf_wait_list)) {
                qcs = LIST_ELEM(qcc->buf_wait_list.n, struct qcs *, el_buf);
                LIST_DEL_INIT(&qcs->el_buf);
+               tot_time_stop(&qcs->timer.buf);
                qcs_notify_send(qcs);
                ret = 1;
        }
@@ -1004,6 +1011,7 @@ struct buffer *qcc_get_stream_txbuf(struct qcs *qcs, int *err)
        if (!out) {
                if (qcc->flags & QC_CF_CONN_FULL) {
                        LIST_APPEND(&qcc->buf_wait_list, &qcs->el_buf);
+                       tot_time_start(&qcs->timer.buf);
                        goto out;
                }
 
@@ -1018,6 +1026,7 @@ struct buffer *qcc_get_stream_txbuf(struct qcs *qcs, int *err)
 
                        TRACE_STATE("hitting stream desc buffer limit", QMUX_EV_QCS_SEND, qcc->conn, qcs);
                        LIST_APPEND(&qcc->buf_wait_list, &qcs->el_buf);
+                       tot_time_start(&qcs->timer.buf);
                        qcc->flags |= QC_CF_CONN_FULL;
                        goto out;
                }
@@ -1102,6 +1111,7 @@ static void qcc_notify_fctl(struct qcc *qcc)
        while (!LIST_ISEMPTY(&qcc->fctl_list)) {
                qcs = LIST_ELEM(qcc->fctl_list.n, struct qcs *, el_fctl);
                LIST_DEL_INIT(&qcs->el_fctl);
+               tot_time_stop(&qcs->timer.fctl);
                qcs_notify_send(qcs);
        }
 }
@@ -1454,8 +1464,10 @@ int qcc_recv_max_stream_data(struct qcc *qcc, uint64_t id, uint64_t max)
                                tasklet_wakeup(qcc->wait_event.tasklet);
                        }
 
-                       if (unblock_soft)
+                       if (unblock_soft) {
+                               tot_time_stop(&qcs->timer.fctl);
                                qcs_notify_send(qcs);
+                       }
                }
        }
 
@@ -2928,6 +2940,7 @@ static size_t qmux_strm_snd_buf(struct stconn *sc, struct buffer *buf,
                        TRACE_DEVEL("append to fctl-list",
                                    QMUX_EV_STRM_SEND, qcs->qcc->conn, qcs);
                        LIST_APPEND(&qcs->qcc->fctl_list, &qcs->el_fctl);
+                       tot_time_start(&qcs->timer.fctl);
                }
                goto end;
        }
@@ -2935,6 +2948,7 @@ static size_t qmux_strm_snd_buf(struct stconn *sc, struct buffer *buf,
        if (qfctl_sblocked(&qcs->tx.fc)) {
                TRACE_DEVEL("leaving on flow-control reached",
                            QMUX_EV_STRM_SEND, qcs->qcc->conn, qcs);
+               tot_time_start(&qcs->timer.fctl);
                goto end;
        }
 

diff --git a/src/qmux_trace.c b/src/qmux_trace.c
index 2cca6207d1a32ce8645b2769e6914870b69d94a9..424c07e577dbb001ae6e179bc6bd61ac00cca1cf 100644 (file)
--- a/src/qmux_trace.c
+++ b/src/qmux_trace.c
@@ -124,4 +124,9 @@ void qmux_dump_qcs_info(struct buffer *msg, const struct qcs *qcs)
        chunk_appendf(msg, " .tx=%llu %llu/%llu", (ullong)qcs->tx.fc.off_soft,
                                                  (ullong)qcs->tx.fc.off_real,
                                                  (ullong)qcs->tx.fc.limit);
+
+       chunk_appendf(msg, " .ti=%u/%u/%u",
+                     tot_time_read(&qcs->timer.base),
+                     tot_time_read(&qcs->timer.buf),
+                     tot_time_read(&qcs->timer.fctl));
 }