Mercurial > hg > nginx

changeset 9184:7ec761f0365f

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
QUIC: improved packet and frames debug tracing. Currently, packets generated by ngx_quic_frame_sendto() and ngx_quic_send_early_cc() are not logged, thus making it hard to read logs due to gaps appearing in packet numbers sequence. At frames level, it is handy to see immediately packet number in which they arrived or being sent.
author Vladimir Khomutov <vl@wbsrv.ru>
date Thu, 26 Oct 2023 23:35:09 +0300
parents 8b1526a7e383
children c458cd00bb0b
files src/event/quic/ngx_event_quic_frames.c src/event/quic/ngx_event_quic_output.c src/event/quic/ngx_event_quic_transport.c
diffstat 3 files changed, 32 insertions(+), 16 deletions(-) [+]
line wrap: on
line diff
--- a/src/event/quic/ngx_event_quic_frames.c
+++ b/src/event/quic/ngx_event_quic_frames.c
@@ -886,8 +886,8 @@ ngx_quic_log_frame(ngx_log_t *log, ngx_q
         break;
     }
 
-    ngx_log_debug4(NGX_LOG_DEBUG_EVENT, log, 0, "quic frame %s %s %*s",
-                   tx ? "tx" : "rx", ngx_quic_level_name(f->level),
+    ngx_log_debug5(NGX_LOG_DEBUG_EVENT, log, 0, "quic frame %s %s:%uL %*s",
+                   tx ? "tx" : "rx", ngx_quic_level_name(f->level), f->pnum,
                    p - buf, buf);
 }
 
--- a/src/event/quic/ngx_event_quic_output.c
+++ b/src/event/quic/ngx_event_quic_output.c
@@ -35,6 +35,15 @@
 #define NGX_QUIC_SOCKET_RETRY_DELAY      10 /* ms, for NGX_AGAIN on write */
 
 
+#define ngx_quic_log_packet(log, pkt)                                         \
+    ngx_log_debug6(NGX_LOG_DEBUG_EVENT, log, 0,                               \
+                   "quic packet tx %s bytes:%ui need_ack:%d"                  \
+                   " number:%L encoded nl:%d trunc:0x%xD",                    \
+                   ngx_quic_level_name((pkt)->level), (pkt)->payload.len,     \
+                   (pkt)->need_ack, (pkt)->number, (pkt)->num_len,            \
+                    (pkt)->trunc);
+
+
 static ngx_int_t ngx_quic_create_datagrams(ngx_connection_t *c);
 static void ngx_quic_commit_send(ngx_connection_t *c, ngx_quic_send_ctx_t *ctx);
 static void ngx_quic_revert_send(ngx_connection_t *c, ngx_quic_send_ctx_t *ctx,
@@ -578,6 +587,11 @@ ngx_quic_output_packet(ngx_connection_t 
             pkt.need_ack = 1;
         }
 
+        f->pnum = ctx->pnum;
+        f->first = now;
+        f->last = now;
+        f->plen = 0;
+
         ngx_quic_log_frame(c->log, f, 1);
 
         flen = ngx_quic_create_frame(p, f);
@@ -588,11 +602,6 @@ ngx_quic_output_packet(ngx_connection_t 
         len += flen;
         p += flen;
 
-        f->pnum = ctx->pnum;
-        f->first = now;
-        f->last = now;
-        f->plen = 0;
-
         nframes++;
     }
 
@@ -610,11 +619,7 @@ ngx_quic_output_packet(ngx_connection_t 
 
     res.data = data;
 
-    ngx_log_debug6(NGX_LOG_DEBUG_EVENT, c->log, 0,
-                   "quic packet tx %s bytes:%ui"
-                   " need_ack:%d number:%L encoded nl:%d trunc:0x%xD",
-                   ngx_quic_level_name(ctx->level), pkt.payload.len,
-                   pkt.need_ack, pkt.number, pkt.num_len, pkt.trunc);
+    ngx_quic_log_packet(c->log, &pkt);
 
     if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) {
         return NGX_ERROR;
@@ -899,13 +904,13 @@ ngx_quic_send_early_cc(ngx_connection_t 
     frame.u.close.reason.data = (u_char *) reason;
     frame.u.close.reason.len = ngx_strlen(reason);
 
+    ngx_quic_log_frame(c->log, &frame, 1);
+
     len = ngx_quic_create_frame(NULL, &frame);
     if (len > NGX_QUIC_MAX_UDP_PAYLOAD_SIZE) {
         return NGX_ERROR;
     }
 
-    ngx_quic_log_frame(c->log, &frame, 1);
-
     len = ngx_quic_create_frame(src, &frame);
     if (len == -1) {
         return NGX_ERROR;
@@ -940,6 +945,8 @@ ngx_quic_send_early_cc(ngx_connection_t 
 
     res.data = dst;
 
+    ngx_quic_log_packet(c->log, &pkt);
+
     if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) {
         ngx_quic_keys_cleanup(pkt.keys);
         return NGX_ERROR;
@@ -1198,13 +1205,17 @@ ngx_quic_frame_sendto(ngx_connection_t *
     pad = 4 - pkt.num_len;
     min_payload = ngx_max(min_payload, pad);
 
+#if (NGX_DEBUG)
+    frame->pnum = pkt.number;
+#endif
+
+    ngx_quic_log_frame(c->log, frame, 1);
+
     len = ngx_quic_create_frame(NULL, frame);
     if (len > NGX_QUIC_MAX_UDP_PAYLOAD_SIZE) {
         return NGX_ERROR;
     }
 
-    ngx_quic_log_frame(c->log, frame, 1);
-
     len = ngx_quic_create_frame(src, frame);
     if (len == -1) {
         return NGX_ERROR;
@@ -1220,6 +1231,8 @@ ngx_quic_frame_sendto(ngx_connection_t *
 
     res.data = dst;
 
+    ngx_quic_log_packet(c->log, &pkt);
+
     if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) {
         return NGX_ERROR;
     }
--- a/src/event/quic/ngx_event_quic_transport.c
+++ b/src/event/quic/ngx_event_quic_transport.c
@@ -1135,6 +1135,9 @@ ngx_quic_parse_frame(ngx_quic_header_t *
     }
 
     f->level = pkt->level;
+#if (NGX_DEBUG)
+    f->pnum = pkt->pn;
+#endif
 
     return p - start;