MINOR: quic: Traces adjustments at proto level.
Dump variables displayed by TRACE_ENTER() or TRACE_LEAVE() by calls to TRACE_PROTO().
No more variables are displayed by the two former macros. For now on, these information
are accessible from proto level.
Add new calls to TRACE_PROTO() at important locations in relation whith QUIC transport
protocol.
When relevant, try to prefix such traces with TX or RX keyword to identify the
concerned subpart (transmission or reception) of the protocol.
Must be backported to 2.7.
diff --git a/src/quic_cc_cubic.c b/src/quic_cc_cubic.c
index 0654e42..6e829dd 100644
--- a/src/quic_cc_cubic.c
+++ b/src/quic_cc_cubic.c
@@ -1,5 +1,6 @@
-#include <haproxy/trace.h>
#include <haproxy/quic_cc.h>
+#include <haproxy/ticks.h>
+#include <haproxy/trace.h>
/* This source file is highly inspired from Linux kernel source file
* implementation for TCP Cubic. In fact, we have no choice if we do
@@ -198,7 +199,8 @@
struct quic_path *path = container_of(cc, struct quic_path, cc);
struct cubic *c = quic_cc_priv(cc);
- TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
+ TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc);
+ TRACE_PROTO("CC cubic", QUIC_EV_CONN_CC, cc->qc, ev);
switch (ev->type) {
case QUIC_CC_EVT_ACK:
path->cwnd += ev->ack.acked;
@@ -219,13 +221,15 @@
}
out:
- TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc, NULL, cc);
+ TRACE_PROTO("CC cubic", QUIC_EV_CONN_CC, cc->qc, NULL, cc);
+ TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc);
}
/* Congestion avoidance callback. */
static void quic_cc_cubic_ca_cb(struct quic_cc *cc, struct quic_cc_event *ev)
{
- TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
+ TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc);
+ TRACE_PROTO("CC cubic", QUIC_EV_CONN_CC, cc->qc, ev);
switch (ev->type) {
case QUIC_CC_EVT_ACK:
quic_cubic_update(cc, ev->ack.acked);
@@ -239,7 +243,7 @@
}
out:
- TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc, NULL, cc);
+ TRACE_PROTO("CC cubic", QUIC_EV_CONN_CC, cc->qc, NULL, cc);
}
/* Recovery period callback */
@@ -248,6 +252,7 @@
struct cubic *c = quic_cc_priv(cc);
TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
+ TRACE_PROTO("CC cubic", QUIC_EV_CONN_CC, cc->qc, ev);
BUG_ON(!tick_isset(c->recovery_start_time));
@@ -257,8 +262,10 @@
* A recovery period ends and the sender enters congestion avoidance when a
* packet sent during the recovery period is acknowledged.
*/
- if (tick_is_le(ev->ack.time_sent, c->recovery_start_time))
+ if (tick_is_le(ev->ack.time_sent, c->recovery_start_time)) {
+ TRACE_PROTO("CC cubic (still in recov. period)", QUIC_EV_CONN_CC, cc->qc);
goto leave;
+ }
cc->algo->state = QUIC_CC_ST_CA;
c->recovery_start_time = TICK_ETERNITY;
@@ -271,6 +278,7 @@
}
leave:
+ TRACE_PROTO("CC cubic", QUIC_EV_CONN_CC, cc->qc, NULL, cc);
TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc, NULL, cc);
}
diff --git a/src/quic_cc_newreno.c b/src/quic_cc_newreno.c
index 2eedbfb..bf714b1 100644
--- a/src/quic_cc_newreno.c
+++ b/src/quic_cc_newreno.c
@@ -80,7 +80,8 @@
struct quic_path *path;
struct nr *nr = quic_cc_priv(cc);
- TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
+ TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc);
+ TRACE_PROTO("CC reno", QUIC_EV_CONN_CC, cc->qc, ev);
path = container_of(cc, struct quic_path, cc);
switch (ev->type) {
case QUIC_CC_EVT_ACK:
@@ -98,7 +99,8 @@
/* XXX TO DO XXX */
break;
}
- TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc,, cc);
+ TRACE_PROTO("CC reno", QUIC_EV_CONN_CC, cc->qc, NULL, cc);
+ TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc);
}
/* Congestion avoidance callback. */
@@ -107,7 +109,8 @@
struct quic_path *path;
struct nr *nr = quic_cc_priv(cc);
- TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
+ TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc);
+ TRACE_PROTO("CC reno", QUIC_EV_CONN_CC, cc->qc, ev);
path = container_of(cc, struct quic_path, cc);
switch (ev->type) {
case QUIC_CC_EVT_ACK:
@@ -132,7 +135,8 @@
}
out:
- TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc, NULL, cc);
+ TRACE_PROTO("CC reno", QUIC_EV_CONN_CC, cc->qc, NULL, cc);
+ TRACE_LEAVE(QUIC_EV_CONN_CC, cc->qc);
}
/* Recovery period callback. */
@@ -143,7 +147,8 @@
BUG_ON(!tick_isset(nr->recovery_start_time));
- TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
+ TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc);
+ TRACE_PROTO("CC reno", QUIC_EV_CONN_CC, cc->qc, ev);
path = container_of(cc, struct quic_path, cc);
switch (ev->type) {
case QUIC_CC_EVT_ACK:
@@ -151,8 +156,10 @@
* A recovery period ends and the sender enters congestion avoidance when a
* packet sent during the recovery period is acknowledged.
*/
- if (tick_is_le(ev->ack.time_sent, nr->recovery_start_time))
+ if (tick_is_le(ev->ack.time_sent, nr->recovery_start_time)) {
+ TRACE_PROTO("CC reno (still in recovery period)", QUIC_EV_CONN_CC, cc->qc, ev);
goto leave;
+ }
cc->algo->state = QUIC_CC_ST_CA;
nr->recovery_start_time = TICK_ETERNITY;
@@ -167,6 +174,7 @@
}
leave:
+ TRACE_PROTO("CC reno", QUIC_EV_CONN_CC, cc->qc, ev);
TRACE_ENTER(QUIC_EV_CONN_CC, cc->qc, ev);
}
static void quic_cc_nr_state_trace(struct buffer *buf, const struct quic_cc *cc)
diff --git a/src/quic_conn.c b/src/quic_conn.c
index ef2707c..f65e217 100644
--- a/src/quic_conn.c
+++ b/src/quic_conn.c
@@ -702,10 +702,8 @@
if (mask & QUIC_EV_CONN_PSTRM) {
const struct quic_frame *frm = a2;
- if (frm) {
- chunk_appendf(&trace_buf, " frm@%p", frm);
+ if (frm)
chunk_frm_appendf(&trace_buf, frm);
- }
}
if (mask & QUIC_EV_CONN_ELEVELSEL) {
@@ -793,8 +791,8 @@
unsigned int pto;
int handshake_confirmed;
- TRACE_ENTER(QUIC_EV_CONN_STIMER, qc,
- NULL, NULL, &qc->path->ifae_pkts);
+ TRACE_ENTER(QUIC_EV_CONN_STIMER, qc);
+ TRACE_PROTO("set timer", QUIC_EV_CONN_STIMER, qc, NULL, NULL, &qc->path->ifae_pkts);
pktns = NULL;
if (!qc->timer_task) {
@@ -842,7 +840,8 @@
task_schedule(qc->timer_task, qc->timer);
}
leave:
- TRACE_LEAVE(QUIC_EV_CONN_STIMER, qc, pktns);
+ TRACE_PROTO("set timer", QUIC_EV_CONN_STIMER, qc, pktns);
+ TRACE_LEAVE(QUIC_EV_CONN_STIMER, qc);
}
/* Derive new keys and ivs required for Key Update feature for <qc> QUIC
@@ -930,7 +929,8 @@
ret = 1;
leave:
- TRACE_LEAVE(QUIC_EV_CONN_KP, qc, &kp_trace);
+ TRACE_PROTO("key update", QUIC_EV_CONN_KP, qc, &kp_trace);
+ TRACE_LEAVE(QUIC_EV_CONN_KP, qc);
return ret;
}
@@ -1746,7 +1746,8 @@
static inline void qc_treat_acked_tx_frm(struct quic_conn *qc,
struct quic_frame *frm)
{
- TRACE_ENTER(QUIC_EV_CONN_PRSAFRM, qc, frm);
+ TRACE_ENTER(QUIC_EV_CONN_PRSAFRM, qc);
+ TRACE_PROTO("RX ack TX frm", QUIC_EV_CONN_PRSAFRM, qc, frm);
switch (frm->type) {
case QUIC_FT_STREAM_8 ... QUIC_FT_STREAM_F:
@@ -2215,7 +2216,7 @@
}
}
- TRACE_PROTO("rcvd ack range", QUIC_EV_CONN_PRSAFRM,
+ TRACE_PROTO("RX ack range", QUIC_EV_CONN_PRSAFRM,
qc, NULL, &largest, &smallest);
do {
uint64_t gap, ack_range;
@@ -2253,7 +2254,7 @@
/* Next range */
smallest = largest - ack_range;
- TRACE_PROTO("rcvd next ack range", QUIC_EV_CONN_PRSAFRM,
+ TRACE_PROTO("RX next ack range", QUIC_EV_CONN_PRSAFRM,
qc, NULL, &largest, &smallest);
} while (1);
@@ -2640,7 +2641,7 @@
p = eb64_entry(node, struct quic_tx_packet, pn_node);
node = eb64_next(node);
/* Skip the empty and coalesced packets */
- TRACE_PRINTF(TRACE_LEVEL_DEVELOPER, QUIC_EV_CONN_SPPKTS, qc, 0, 0, 0,
+ TRACE_PRINTF(TRACE_LEVEL_PROTO, QUIC_EV_CONN_SPPKTS, qc, 0, 0, 0,
"--> pn=%llu (%d %d %d)", (ull)p->pn_node.key,
LIST_ISEMPTY(&p->frms), !!(p->flags & QUIC_FL_TX_PACKET_COALESCED),
qc_pkt_with_only_acked_frms(p));
@@ -2663,7 +2664,7 @@
goto leave;
}
- TRACE_DEVEL("duplicating packet", QUIC_EV_CONN_SPPKTS, qc, pkt);
+ TRACE_PROTO("duplicating packet", QUIC_EV_CONN_SPPKTS, qc, pkt);
qc_dup_pkt_frms(qc, &pkt->frms, frms);
if (frms == frms1 && frms2) {
frms = frms2;
@@ -2702,7 +2703,7 @@
struct quic_tx_packet *p;
p = eb64_entry(node, struct quic_tx_packet, pn_node);
- TRACE_PRINTF(TRACE_LEVEL_DEVELOPER, QUIC_EV_CONN_SPPKTS, qc, 0, 0, 0,
+ TRACE_PRINTF(TRACE_LEVEL_PROTO, QUIC_EV_CONN_SPPKTS, qc, 0, 0, 0,
"--> pn=%llu (%d %d)", (ull)p->pn_node.key,
LIST_ISEMPTY(&p->frms), !!(p->flags & QUIC_FL_TX_PACKET_COALESCED));
if (!LIST_ISEMPTY(&p->frms) && !(p->flags & QUIC_FL_TX_PACKET_COALESCED) &&
@@ -2737,7 +2738,7 @@
/* No risk to loop here, #packet per datagram is bounded */
requeue:
- TRACE_DEVEL("duplicating packet", QUIC_EV_CONN_PRSAFRM, qc, NULL, &pkt->pn_node.key);
+ TRACE_PROTO("duplicating packet", QUIC_EV_CONN_PRSAFRM, qc, NULL, &pkt->pn_node.key);
qc_dup_pkt_frms(qc, &pkt->frms, tmp);
if (qel == iqel) {
if (pkt->next && pkt->next->type == QUIC_PACKET_TYPE_HANDSHAKE) {
@@ -3089,7 +3090,6 @@
goto leave;
}
- TRACE_PROTO("RX frame", QUIC_EV_CONN_PSTRM, qc, &frm);
switch (frm.type) {
case QUIC_FT_PADDING:
break;
@@ -3523,7 +3523,7 @@
(qel == &qc->els[QUIC_TLS_ENC_LEVEL_INITIAL] ||
qel == &qc->els[QUIC_TLS_ENC_LEVEL_HANDSHAKE]);
- TRACE_POINT(QUIC_EV_CONN_PHPKTS, qc, qel);
+ TRACE_PROTO("TX prep pks", QUIC_EV_CONN_PHPKTS, qc, qel);
probe = 0;
cc = qc->flags & QUIC_FL_CONN_IMMEDIATE_CLOSE;
/* We do not probe if an immediate close was asked */
@@ -3724,7 +3724,7 @@
tmpbuf.area = (char *)pos;
tmpbuf.size = tmpbuf.data = dglen;
- TRACE_DATA("send dgram", QUIC_EV_CONN_SPPKTS, qc);
+ TRACE_PROTO("TX dgram", QUIC_EV_CONN_SPPKTS, qc);
/* If sendto is on error just skip the call to it for the rest
* of the loop but continue to purge the buffer. Data will be
* transmitted when QUIC packets are detected as lost on our
@@ -3802,7 +3802,7 @@
pkt->pktns->tx.in_flight += pkt->in_flight_len;
if (pkt->in_flight_len)
qc_set_timer(qc);
- TRACE_DATA("sent pkt", QUIC_EV_CONN_SPPKTS, qc, pkt);
+ TRACE_PROTO("TX pkt", QUIC_EV_CONN_SPPKTS, qc, pkt);
next_pkt = pkt->next;
quic_tx_packet_refinc(pkt);
eb64_insert(&pkt->pktns->tx.pkts, &pkt->pn_node);
@@ -4278,7 +4278,7 @@
app_qel = &qc->els[QUIC_TLS_ENC_LEVEL_APP];
/* A server must not process incoming 1-RTT packets before the handshake is complete. */
if (el == app_qel && qc_is_listener(qc) && qc->state < QUIC_HS_ST_COMPLETE) {
- TRACE_DEVEL("hp not removed (handshake not completed)",
+ TRACE_PROTO("RX hp not removed (handshake not completed)",
QUIC_EV_CONN_ELRMHP, qc);
goto out;
}
@@ -4289,7 +4289,7 @@
tls_ctx = qc_select_tls_ctx(qc, el, pqpkt);
if (!qc_do_rm_hp(qc, pqpkt, tls_ctx, el->pktns->rx.largest_pn,
pqpkt->data + pqpkt->pn_offset, pqpkt->data)) {
- TRACE_ERROR("hp removing error", QUIC_EV_CONN_ELRMHP, qc);
+ TRACE_ERROR("RX hp removing error", QUIC_EV_CONN_ELRMHP, qc);
}
else {
qc_handle_spin_bit(qc, pqpkt, el);
@@ -4299,7 +4299,7 @@
pqpkt->pn_node.key = pqpkt->pn;
eb64_insert(&el->rx.pkts, &pqpkt->pn_node);
quic_rx_packet_refinc(pqpkt);
- TRACE_DEVEL("hp removed", QUIC_EV_CONN_ELRMHP, qc, pqpkt);
+ TRACE_PROTO("RX hp removed", QUIC_EV_CONN_ELRMHP, qc, pqpkt);
}
LIST_DELETE(&pqpkt->list);
quic_rx_packet_refdec(pqpkt);
@@ -4323,7 +4323,7 @@
struct quic_cstream *cstream = el->cstream;
ncb_sz_t data;
- TRACE_ENTER(QUIC_EV_CONN_PHPKTS, qc, el);
+ TRACE_ENTER(QUIC_EV_CONN_PHPKTS, qc);
BUG_ON(!cstream);
ncbuf = &cstream->rx.ncbuf;
@@ -4461,24 +4461,24 @@
/* check if tls secrets are available */
if (qel->tls_ctx.flags & QUIC_FL_TLS_SECRETS_DCD) {
- TRACE_DEVEL("Discarded keys", QUIC_EV_CONN_TRMHP, qc);
+ TRACE_PROTO("Discarded keys", QUIC_EV_CONN_TRMHP, qc);
goto cant_rm_hp;
}
if (!quic_tls_has_rx_sec(qel)) {
- TRACE_DEVEL("non available secrets", QUIC_EV_CONN_TRMHP, qc);
+ TRACE_PROTO("non available secrets", QUIC_EV_CONN_TRMHP, qc);
goto cant_rm_hp;
}
if (tel == QUIC_TLS_ENC_LEVEL_APP && qc->state < QUIC_HS_ST_COMPLETE) {
- TRACE_DEVEL("handshake not complete", QUIC_EV_CONN_TRMHP, qc);
+ TRACE_PROTO("handshake not complete", QUIC_EV_CONN_TRMHP, qc);
goto cant_rm_hp;
}
/* check if the connection layer is ready before using app level */
if ((tel == QUIC_TLS_ENC_LEVEL_APP || tel == QUIC_TLS_ENC_LEVEL_EARLY_DATA) &&
qc->mux_state == QC_MUX_NULL) {
- TRACE_DEVEL("connection layer not ready", QUIC_EV_CONN_TRMHP, qc);
+ TRACE_PROTO("connection layer not ready", QUIC_EV_CONN_TRMHP, qc);
goto cant_rm_hp;
}
@@ -4997,7 +4997,8 @@
}
out:
- TRACE_LEAVE(QUIC_EV_CONN_IO_CB, qc, &st, &ssl_err);
+ TRACE_PROTO("ssl error", QUIC_EV_CONN_IO_CB, qc, &st, &ssl_err);
+ TRACE_LEAVE(QUIC_EV_CONN_IO_CB, qc);
return t;
}
@@ -5141,7 +5142,8 @@
struct quic_conn *qc = ctx;
struct quic_pktns *pktns;
- TRACE_ENTER(QUIC_EV_CONN_PTIMER, qc,
+ TRACE_ENTER(QUIC_EV_CONN_PTIMER, qc);
+ TRACE_PROTO("process timer", QUIC_EV_CONN_PTIMER, qc,
NULL, NULL, &qc->path->ifae_pkts);
task->expire = TICK_ETERNITY;
pktns = quic_loss_pktns(qc);
@@ -5211,7 +5213,8 @@
qc->path->loss.pto_count++;
out:
- TRACE_LEAVE(QUIC_EV_CONN_PTIMER, qc, pktns);
+ TRACE_PROTO("process timer", QUIC_EV_CONN_PTIMER, qc, pktns);
+ TRACE_LEAVE(QUIC_EV_CONN_PTIMER, qc);
return task;
}
@@ -5844,7 +5847,7 @@
goto out;
}
- TRACE_PROTO("hp not removed", QUIC_EV_CONN_TRMHP, qc, pkt);
+ TRACE_PROTO("RX hp not removed", QUIC_EV_CONN_TRMHP, qc, pkt);
LIST_APPEND(&qel->rx.pqpkts, &pkt->list);
quic_rx_packet_refinc(pkt);
}
@@ -6575,7 +6578,7 @@
}
}
else if (!qc) {
- TRACE_PROTO("No connection on a non Initial packet", QUIC_EV_CONN_LPKT, NULL, NULL, NULL, pkt->version);
+ TRACE_PROTO("RX non Initial pkt without connection", QUIC_EV_CONN_LPKT, NULL, NULL, NULL, pkt->version);
if (global.cluster_secret && !send_stateless_reset(l, &dgram->saddr, pkt))
TRACE_ERROR("stateless reset not sent", QUIC_EV_CONN_LPKT, qc);
goto err;
@@ -6759,7 +6762,7 @@
*/
if (pkt->type == QUIC_PACKET_TYPE_INITIAL &&
dgram->len < QUIC_INITIAL_PACKET_MINLEN) {
- TRACE_PROTO("Too short datagram with an Initial packet", QUIC_EV_CONN_LPKT);
+ TRACE_PROTO("RX too short datagram with an Initial packet", QUIC_EV_CONN_LPKT);
HA_ATOMIC_INC(&prx_counters->too_short_initial_dgram);
goto drop;
}
@@ -6769,14 +6772,14 @@
* datagram.
*/
if (pkt->type == QUIC_PACKET_TYPE_0RTT && !l->bind_conf->ssl_conf.early_data) {
- TRACE_PROTO("0-RTT packet not supported", QUIC_EV_CONN_LPKT);
+ TRACE_PROTO("RX 0-RTT packet not supported", QUIC_EV_CONN_LPKT);
goto drop;
}
}
else {
- TRACE_PROTO("short header packet received", QUIC_EV_CONN_LPKT);
+ TRACE_PROTO("RX short header packet", QUIC_EV_CONN_LPKT);
if (end - buf < QUIC_HAP_CID_LEN) {
- TRACE_PROTO("Packet dropped", QUIC_EV_CONN_LPKT);
+ TRACE_PROTO("RX pkt dropped", QUIC_EV_CONN_LPKT);
goto drop;
}
@@ -6789,7 +6792,7 @@
if (!(pkt->flags & QUIC_FL_RX_PACKET_DGRAM_FIRST) &&
(pkt->dcid.len != dgram->dcid_len ||
memcmp(dgram->dcid, pkt->dcid.data, pkt->dcid.len))) {
- TRACE_PROTO("Packet dropped", QUIC_EV_CONN_LPKT);
+ TRACE_PROTO("RX pkt dropped", QUIC_EV_CONN_LPKT);
goto drop;
}
@@ -6800,7 +6803,8 @@
pkt->len = end - beg;
}
- TRACE_LEAVE(QUIC_EV_CONN_LPKT, NULL, pkt, NULL, qv);
+ TRACE_PROTO("RX pkt parsed", QUIC_EV_CONN_LPKT, NULL, pkt, NULL, qv);
+ TRACE_LEAVE(QUIC_EV_CONN_LPKT);
return 0;
drop:
@@ -6808,7 +6812,8 @@
drop_silent:
if (!pkt->len)
pkt->len = end - beg;
- TRACE_LEAVE(QUIC_EV_CONN_LPKT, NULL, pkt, NULL, qv);
+ TRACE_PROTO("RX pkt parsing failed", QUIC_EV_CONN_LPKT, NULL, pkt, NULL, qv);
+ TRACE_LEAVE(QUIC_EV_CONN_LPKT);
return -1;
}
@@ -6967,7 +6972,8 @@
struct quic_enc_level *qel = NULL;
size_t b_cspace;
- TRACE_ENTER(QUIC_EV_CONN_LPKT, qc, pkt, NULL, qv);
+ TRACE_ENTER(QUIC_EV_CONN_LPKT, qc);
+ TRACE_PROTO("RX pkt", QUIC_EV_CONN_LPKT, qc, pkt, NULL, qv);
if (pkt->flags & QUIC_FL_RX_PACKET_DGRAM_FIRST &&
qc->flags & QUIC_FL_CONN_ANTI_AMPLIFICATION_REACHED) {
@@ -7031,12 +7037,14 @@
qc->wait_event.tasklet);
drop_silent:
- TRACE_LEAVE(QUIC_EV_CONN_LPKT, qc ? qc : NULL, pkt, NULL, qv);
+ TRACE_PROTO("RX pkt", QUIC_EV_CONN_LPKT, qc ? qc : NULL, pkt, NULL, qv);
+ TRACE_LEAVE(QUIC_EV_CONN_LPKT, qc ? qc : NULL);
return;
drop:
HA_ATOMIC_INC(&qc->prx_counters->dropped_pkt);
- TRACE_LEAVE(QUIC_EV_CONN_LPKT, qc ? qc : NULL, pkt, NULL, qv);
+ TRACE_PROTO("packet drop", QUIC_EV_CONN_LPKT, qc ? qc : NULL, pkt, NULL, qv);
+ TRACE_LEAVE(QUIC_EV_CONN_LPKT, qc ? qc : NULL);
}
/* This function builds into <buf> buffer a QUIC long packet header.
@@ -7208,7 +7216,7 @@
room = QUIC_MIN(room, remain - headlen);
}
- TRACE_PROTO("************** frames build (headlen)",
+ TRACE_PROTO("TX frms build (headlen)",
QUIC_EV_CONN_BCFRMS, qc, &headlen);
/* NOTE: switch/case block inside a loop, a successful status must be
@@ -7818,7 +7826,8 @@
size_t pn_len, payload_len, aad_len;
struct quic_tx_packet *pkt;
- TRACE_ENTER(QUIC_EV_CONN_TXPKT, qc, NULL, qel);
+ TRACE_ENTER(QUIC_EV_CONN_TXPKT, qc);
+ TRACE_PROTO("TX pkt build", QUIC_EV_CONN_TXPKT, qc, NULL, qel);
*err = 0;
pkt = pool_alloc(pool_head_quic_tx_packet);
if (!pkt) {
@@ -7886,7 +7895,8 @@
ret_pkt = pkt;
leave:
- TRACE_LEAVE(QUIC_EV_CONN_TXPKT, qc, ret_pkt);
+ TRACE_PROTO("TX pkt built", QUIC_EV_CONN_TXPKT, qc, ret_pkt);
+ TRACE_LEAVE(QUIC_EV_CONN_TXPKT, qc);
return ret_pkt;
err:
@@ -8270,8 +8280,10 @@
chunk_appendf(&trash, " loc. TPs:");
quic_transport_params_dump(&trash, qc, &qc->rx.params);
+ chunk_appendf(&trash, "\n");
chunk_appendf(&trash, " rem. TPs:");
quic_transport_params_dump(&trash, qc, &qc->tx.params);
+ chunk_appendf(&trash, "\n");
/* Connection state */
if (qc->flags & QUIC_FL_CONN_CLOSING)
diff --git a/src/quic_frame.c b/src/quic_frame.c
index f569c9f..ec5e042 100644
--- a/src/quic_frame.c
+++ b/src/quic_frame.c
@@ -286,7 +286,7 @@
ar = eb64_last(&tx_ack->arngs->root);
ar_node = eb64_entry(ar, struct quic_arng_node, first);
- TRACE_DEVEL("ack range", QUIC_EV_CONN_PRSAFRM,
+ TRACE_PROTO("TX ack range", QUIC_EV_CONN_PRSAFRM,
qc,, &ar_node->last, &ar_node->first.key);
if (!quic_enc_int(buf, end, ar_node->last) ||
!quic_enc_int(buf, end, tx_ack->ack_delay) ||
@@ -296,7 +296,7 @@
while ((prev_ar = eb64_prev(ar))) {
prev_ar_node = eb64_entry(prev_ar, struct quic_arng_node, first);
- TRACE_DEVEL("ack range", QUIC_EV_CONN_PRSAFRM, qc,,
+ TRACE_PROTO("TX ack range", QUIC_EV_CONN_PRSAFRM, qc,,
&prev_ar_node->last, &prev_ar_node->first.key);
if (!quic_enc_int(buf, end, ar_node->first.key - prev_ar_node->last - 2) ||
!quic_enc_int(buf, end, prev_ar_node->last - prev_ar_node->first.key))
@@ -1115,12 +1115,13 @@
goto leave;
}
- TRACE_PROTO("frame", QUIC_EV_CONN_PRSFRM, qc, frm);
if (!parser->func(frm, qc, buf, end)) {
TRACE_DEVEL("parsing error", QUIC_EV_CONN_PRSFRM, qc, frm);
goto leave;
}
+ TRACE_PROTO("RX frm", QUIC_EV_CONN_PSTRM, qc, frm);
+
pkt->flags |= parser->flags;
ret = 1;
@@ -1155,10 +1156,10 @@
goto leave;
}
- TRACE_PROTO("TX frame", QUIC_EV_CONN_BFRM, qc, frm);
+ TRACE_PROTO("TX frm", QUIC_EV_CONN_BFRM, qc, frm);
*pos++ = frm->type;
if (!quic_frame_builders[frm->type].func(&pos, end, frm, qc)) {
- TRACE_DEVEL("frame building error", QUIC_EV_CONN_BFRM, qc, frm);
+ TRACE_ERROR("frame building error", QUIC_EV_CONN_BFRM, qc, frm);
goto leave;
}
diff --git a/src/quic_loss.c b/src/quic_loss.c
index a92b699..8f19645 100644
--- a/src/quic_loss.c
+++ b/src/quic_loss.c
@@ -20,7 +20,7 @@
struct quic_conn *qc)
{
TRACE_ENTER(QUIC_EV_CONN_RTTUPDT, qc);
- TRACE_DEVEL("Loss info update", QUIC_EV_CONN_RTTUPDT, qc, &rtt, &ack_delay, ql);
+ TRACE_PROTO("TX loss srtt update", QUIC_EV_CONN_RTTUPDT, qc, &rtt, &ack_delay, ql);
ql->latest_rtt = rtt;
if (!ql->rtt_min) {
@@ -46,7 +46,7 @@
ql->srtt += rtt - (ql->srtt >> 3);
}
- TRACE_DEVEL("Loss info update", QUIC_EV_CONN_RTTUPDT, qc,,, ql);
+ TRACE_PROTO("TX loss srtt update", QUIC_EV_CONN_RTTUPDT, qc,,, ql);
TRACE_LEAVE(QUIC_EV_CONN_RTTUPDT, qc);
}
@@ -62,9 +62,9 @@
TRACE_ENTER(QUIC_EV_CONN_SPTO, qc);
pktns = &qc->pktns[QUIC_TLS_PKTNS_INITIAL];
- TRACE_DEVEL("pktns", QUIC_EV_CONN_SPTO, qc, pktns);
+ TRACE_PROTO("TX loss pktns", QUIC_EV_CONN_SPTO, qc, pktns);
for (i = QUIC_TLS_PKTNS_HANDSHAKE; i < QUIC_TLS_PKTNS_MAX; i++) {
- TRACE_DEVEL("pktns", QUIC_EV_CONN_SPTO, qc, &qc->pktns[i]);
+ TRACE_PROTO("TX loss pktns", QUIC_EV_CONN_SPTO, qc, &qc->pktns[i]);
if (!tick_isset(pktns->tx.loss_time) ||
qc->pktns[i].tx.loss_time < pktns->tx.loss_time)
pktns = &qc->pktns[i];
@@ -118,7 +118,7 @@
if (i == QUIC_TLS_PKTNS_01RTT) {
if (!handshake_confirmed) {
- TRACE_STATE("handshake not already completed", QUIC_EV_CONN_SPTO, qc);
+ TRACE_STATE("TX PTO handshake not already completed", QUIC_EV_CONN_SPTO, qc);
pktns = p;
goto out;
}
@@ -132,13 +132,14 @@
lpto = tmp_pto;
pktns = p;
}
- TRACE_DEVEL("pktns", QUIC_EV_CONN_SPTO, qc, p);
+ TRACE_PROTO("TX PTO", QUIC_EV_CONN_SPTO, qc, p);
}
out:
if (pto)
*pto = lpto;
- TRACE_LEAVE(QUIC_EV_CONN_SPTO, qc, pktns, &duration);
+ TRACE_PROTO("TX PTO", QUIC_EV_CONN_SPTO, qc, pktns, &duration);
+ TRACE_LEAVE(QUIC_EV_CONN_SPTO, qc);
return pktns;
}
@@ -159,7 +160,8 @@
struct quic_loss *ql;
unsigned int loss_delay;
- TRACE_ENTER(QUIC_EV_CONN_PKTLOSS, qc, pktns);
+ TRACE_ENTER(QUIC_EV_CONN_PKTLOSS, qc);
+ TRACE_PROTO("TX loss", QUIC_EV_CONN_PKTLOSS, qc, pktns);
pkts = &pktns->tx.pkts;
pktns->tx.loss_time = TICK_ETERNITY;
if (eb_is_empty(pkts))
@@ -200,6 +202,7 @@
}
out:
- TRACE_LEAVE(QUIC_EV_CONN_PKTLOSS, qc, pktns, lost_pkts);
+ TRACE_PROTO("TX loss", QUIC_EV_CONN_PKTLOSS, qc, pktns, lost_pkts);
+ TRACE_LEAVE(QUIC_EV_CONN_PKTLOSS, qc);
}