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.
This commit is contained in:
Amaury Denoyelle 2024-07-31 18:43:55 +02:00
parent a6e2523ca1
commit 9f829ea3f3
3 changed files with 27 additions and 1 deletions

View File

@ -17,6 +17,7 @@
#include <haproxy/quic_frame-t.h> #include <haproxy/quic_frame-t.h>
#include <haproxy/quic_stream-t.h> #include <haproxy/quic_stream-t.h>
#include <haproxy/stconn-t.h> #include <haproxy/stconn-t.h>
#include <haproxy/time-t.h>
/* Stream types */ /* Stream types */
enum qcs_type { enum qcs_type {
@ -156,6 +157,12 @@ struct qcs {
uint64_t err; /* error code to transmit via RESET_STREAM */ uint64_t err; /* error code to transmit via RESET_STREAM */
int start; /* base timestamp for http-request timeout */ 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. */ /* Used as qcc_app_ops.close callback argument. */

View File

@ -149,6 +149,12 @@ static struct qcs *qcs_new(struct qcc *qcc, uint64_t id, enum qcs_type type)
qcs->err = 0; 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(); qcs->sd = sedesc_new();
if (!qcs->sd) if (!qcs->sd)
goto err; goto err;
@ -534,6 +540,7 @@ int qcc_notify_buf(struct qcc *qcc)
if (!LIST_ISEMPTY(&qcc->buf_wait_list)) { if (!LIST_ISEMPTY(&qcc->buf_wait_list)) {
qcs = LIST_ELEM(qcc->buf_wait_list.n, struct qcs *, el_buf); qcs = LIST_ELEM(qcc->buf_wait_list.n, struct qcs *, el_buf);
LIST_DEL_INIT(&qcs->el_buf); LIST_DEL_INIT(&qcs->el_buf);
tot_time_stop(&qcs->timer.buf);
qcs_notify_send(qcs); qcs_notify_send(qcs);
ret = 1; ret = 1;
} }
@ -1004,6 +1011,7 @@ struct buffer *qcc_get_stream_txbuf(struct qcs *qcs, int *err)
if (!out) { if (!out) {
if (qcc->flags & QC_CF_CONN_FULL) { if (qcc->flags & QC_CF_CONN_FULL) {
LIST_APPEND(&qcc->buf_wait_list, &qcs->el_buf); LIST_APPEND(&qcc->buf_wait_list, &qcs->el_buf);
tot_time_start(&qcs->timer.buf);
goto out; 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); TRACE_STATE("hitting stream desc buffer limit", QMUX_EV_QCS_SEND, qcc->conn, qcs);
LIST_APPEND(&qcc->buf_wait_list, &qcs->el_buf); LIST_APPEND(&qcc->buf_wait_list, &qcs->el_buf);
tot_time_start(&qcs->timer.buf);
qcc->flags |= QC_CF_CONN_FULL; qcc->flags |= QC_CF_CONN_FULL;
goto out; goto out;
} }
@ -1102,6 +1111,7 @@ static void qcc_notify_fctl(struct qcc *qcc)
while (!LIST_ISEMPTY(&qcc->fctl_list)) { while (!LIST_ISEMPTY(&qcc->fctl_list)) {
qcs = LIST_ELEM(qcc->fctl_list.n, struct qcs *, el_fctl); qcs = LIST_ELEM(qcc->fctl_list.n, struct qcs *, el_fctl);
LIST_DEL_INIT(&qcs->el_fctl); LIST_DEL_INIT(&qcs->el_fctl);
tot_time_stop(&qcs->timer.fctl);
qcs_notify_send(qcs); qcs_notify_send(qcs);
} }
} }
@ -1454,10 +1464,12 @@ int qcc_recv_max_stream_data(struct qcc *qcc, uint64_t id, uint64_t max)
tasklet_wakeup(qcc->wait_event.tasklet); tasklet_wakeup(qcc->wait_event.tasklet);
} }
if (unblock_soft) if (unblock_soft) {
tot_time_stop(&qcs->timer.fctl);
qcs_notify_send(qcs); qcs_notify_send(qcs);
} }
} }
}
if (qcc_may_expire(qcc) && !qcc->nb_hreq) if (qcc_may_expire(qcc) && !qcc->nb_hreq)
qcc_refresh_timeout(qcc); qcc_refresh_timeout(qcc);
@ -2928,6 +2940,7 @@ static size_t qmux_strm_snd_buf(struct stconn *sc, struct buffer *buf,
TRACE_DEVEL("append to fctl-list", TRACE_DEVEL("append to fctl-list",
QMUX_EV_STRM_SEND, qcs->qcc->conn, qcs); QMUX_EV_STRM_SEND, qcs->qcc->conn, qcs);
LIST_APPEND(&qcs->qcc->fctl_list, &qcs->el_fctl); LIST_APPEND(&qcs->qcc->fctl_list, &qcs->el_fctl);
tot_time_start(&qcs->timer.fctl);
} }
goto end; 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)) { if (qfctl_sblocked(&qcs->tx.fc)) {
TRACE_DEVEL("leaving on flow-control reached", TRACE_DEVEL("leaving on flow-control reached",
QMUX_EV_STRM_SEND, qcs->qcc->conn, qcs); QMUX_EV_STRM_SEND, qcs->qcc->conn, qcs);
tot_time_start(&qcs->timer.fctl);
goto end; goto end;
} }

View File

@ -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, chunk_appendf(msg, " .tx=%llu %llu/%llu", (ullong)qcs->tx.fc.off_soft,
(ullong)qcs->tx.fc.off_real, (ullong)qcs->tx.fc.off_real,
(ullong)qcs->tx.fc.limit); (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));
} }