comparison src/event/quic/ngx_event_quic_output.c @ 9184:7ec761f0365f

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 4ccb0d973206
children fcec773dd249
comparison
equal deleted inserted replaced
9183:8b1526a7e383 9184:7ec761f0365f
31 #define NGX_QUIC_MAX_SR_PACKET 1200 31 #define NGX_QUIC_MAX_SR_PACKET 1200
32 32
33 #define NGX_QUIC_CC_MIN_INTERVAL 1000 /* 1s */ 33 #define NGX_QUIC_CC_MIN_INTERVAL 1000 /* 1s */
34 34
35 #define NGX_QUIC_SOCKET_RETRY_DELAY 10 /* ms, for NGX_AGAIN on write */ 35 #define NGX_QUIC_SOCKET_RETRY_DELAY 10 /* ms, for NGX_AGAIN on write */
36
37
38 #define ngx_quic_log_packet(log, pkt) \
39 ngx_log_debug6(NGX_LOG_DEBUG_EVENT, log, 0, \
40 "quic packet tx %s bytes:%ui need_ack:%d" \
41 " number:%L encoded nl:%d trunc:0x%xD", \
42 ngx_quic_level_name((pkt)->level), (pkt)->payload.len, \
43 (pkt)->need_ack, (pkt)->number, (pkt)->num_len, \
44 (pkt)->trunc);
36 45
37 46
38 static ngx_int_t ngx_quic_create_datagrams(ngx_connection_t *c); 47 static ngx_int_t ngx_quic_create_datagrams(ngx_connection_t *c);
39 static void ngx_quic_commit_send(ngx_connection_t *c, ngx_quic_send_ctx_t *ctx); 48 static void ngx_quic_commit_send(ngx_connection_t *c, ngx_quic_send_ctx_t *ctx);
40 static void ngx_quic_revert_send(ngx_connection_t *c, ngx_quic_send_ctx_t *ctx, 49 static void ngx_quic_revert_send(ngx_connection_t *c, ngx_quic_send_ctx_t *ctx,
576 585
577 if (f->need_ack) { 586 if (f->need_ack) {
578 pkt.need_ack = 1; 587 pkt.need_ack = 1;
579 } 588 }
580 589
581 ngx_quic_log_frame(c->log, f, 1);
582
583 flen = ngx_quic_create_frame(p, f);
584 if (flen == -1) {
585 return NGX_ERROR;
586 }
587
588 len += flen;
589 p += flen;
590
591 f->pnum = ctx->pnum; 590 f->pnum = ctx->pnum;
592 f->first = now; 591 f->first = now;
593 f->last = now; 592 f->last = now;
594 f->plen = 0; 593 f->plen = 0;
595 594
595 ngx_quic_log_frame(c->log, f, 1);
596
597 flen = ngx_quic_create_frame(p, f);
598 if (flen == -1) {
599 return NGX_ERROR;
600 }
601
602 len += flen;
603 p += flen;
604
596 nframes++; 605 nframes++;
597 } 606 }
598 607
599 if (nframes == 0) { 608 if (nframes == 0) {
600 return 0; 609 return 0;
608 pkt.payload.data = src; 617 pkt.payload.data = src;
609 pkt.payload.len = len; 618 pkt.payload.len = len;
610 619
611 res.data = data; 620 res.data = data;
612 621
613 ngx_log_debug6(NGX_LOG_DEBUG_EVENT, c->log, 0, 622 ngx_quic_log_packet(c->log, &pkt);
614 "quic packet tx %s bytes:%ui"
615 " need_ack:%d number:%L encoded nl:%d trunc:0x%xD",
616 ngx_quic_level_name(ctx->level), pkt.payload.len,
617 pkt.need_ack, pkt.number, pkt.num_len, pkt.trunc);
618 623
619 if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) { 624 if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) {
620 return NGX_ERROR; 625 return NGX_ERROR;
621 } 626 }
622 627
897 frame.u.close.error_code = err; 902 frame.u.close.error_code = err;
898 903
899 frame.u.close.reason.data = (u_char *) reason; 904 frame.u.close.reason.data = (u_char *) reason;
900 frame.u.close.reason.len = ngx_strlen(reason); 905 frame.u.close.reason.len = ngx_strlen(reason);
901 906
907 ngx_quic_log_frame(c->log, &frame, 1);
908
902 len = ngx_quic_create_frame(NULL, &frame); 909 len = ngx_quic_create_frame(NULL, &frame);
903 if (len > NGX_QUIC_MAX_UDP_PAYLOAD_SIZE) { 910 if (len > NGX_QUIC_MAX_UDP_PAYLOAD_SIZE) {
904 return NGX_ERROR; 911 return NGX_ERROR;
905 } 912 }
906
907 ngx_quic_log_frame(c->log, &frame, 1);
908 913
909 len = ngx_quic_create_frame(src, &frame); 914 len = ngx_quic_create_frame(src, &frame);
910 if (len == -1) { 915 if (len == -1) {
911 return NGX_ERROR; 916 return NGX_ERROR;
912 } 917 }
937 pkt.scid = inpkt->dcid; 942 pkt.scid = inpkt->dcid;
938 pkt.payload.data = src; 943 pkt.payload.data = src;
939 pkt.payload.len = len; 944 pkt.payload.len = len;
940 945
941 res.data = dst; 946 res.data = dst;
947
948 ngx_quic_log_packet(c->log, &pkt);
942 949
943 if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) { 950 if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) {
944 ngx_quic_keys_cleanup(pkt.keys); 951 ngx_quic_keys_cleanup(pkt.keys);
945 return NGX_ERROR; 952 return NGX_ERROR;
946 } 953 }
1196 min_payload = min ? ngx_quic_payload_size(&pkt, min) : 0; 1203 min_payload = min ? ngx_quic_payload_size(&pkt, min) : 0;
1197 1204
1198 pad = 4 - pkt.num_len; 1205 pad = 4 - pkt.num_len;
1199 min_payload = ngx_max(min_payload, pad); 1206 min_payload = ngx_max(min_payload, pad);
1200 1207
1208 #if (NGX_DEBUG)
1209 frame->pnum = pkt.number;
1210 #endif
1211
1212 ngx_quic_log_frame(c->log, frame, 1);
1213
1201 len = ngx_quic_create_frame(NULL, frame); 1214 len = ngx_quic_create_frame(NULL, frame);
1202 if (len > NGX_QUIC_MAX_UDP_PAYLOAD_SIZE) { 1215 if (len > NGX_QUIC_MAX_UDP_PAYLOAD_SIZE) {
1203 return NGX_ERROR; 1216 return NGX_ERROR;
1204 } 1217 }
1205
1206 ngx_quic_log_frame(c->log, frame, 1);
1207 1218
1208 len = ngx_quic_create_frame(src, frame); 1219 len = ngx_quic_create_frame(src, frame);
1209 if (len == -1) { 1220 if (len == -1) {
1210 return NGX_ERROR; 1221 return NGX_ERROR;
1211 } 1222 }
1217 1228
1218 pkt.payload.data = src; 1229 pkt.payload.data = src;
1219 pkt.payload.len = len; 1230 pkt.payload.len = len;
1220 1231
1221 res.data = dst; 1232 res.data = dst;
1233
1234 ngx_quic_log_packet(c->log, &pkt);
1222 1235
1223 if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) { 1236 if (ngx_quic_encrypt(&pkt, &res) != NGX_OK) {
1224 return NGX_ERROR; 1237 return NGX_ERROR;
1225 } 1238 }
1226 1239