Mercurial > hg > nginx
changeset 8360:f175006124d0 quic
Cleaned up hexdumps in debug output.
- the ngx_quic_hexdump0() macro is renamed to ngx_quic_hexdump();
the original ngx_quic_hexdump() macro with variable argument is
removed, extra information is logged normally, with ngx_log_debug()
- all labels in hex dumps are prefixed with "quic"
- the hexdump format is simplified, length is moved forward to avoid
situations when the dump is truncated, and length is not shown
- ngx_quic_flush_flight() function contents is debug-only, placed under
NGX_DEBUG macro to avoid "unused variable" warnings from compiler
- frame names in labels are capitalized, similar to other places
author | Vladimir Homutov <vl@nginx.com> |
---|---|
date | Fri, 24 Apr 2020 11:33:00 +0300 |
parents | 2f900ae486bc |
children | 336d527ca031 |
files | src/event/ngx_event_quic.c src/event/ngx_event_quic.h src/event/ngx_event_quic_protection.c src/event/ngx_event_quic_transport.c |
diffstat | 4 files changed, 63 insertions(+), 54 deletions(-) [+] |
line wrap: on
line diff
--- a/src/event/ngx_event_quic.c Fri Apr 24 10:11:47 2020 +0300 +++ b/src/event/ngx_event_quic.c Fri Apr 24 11:33:00 2020 +0300 @@ -252,8 +252,9 @@ c = ngx_ssl_get_connection((ngx_ssl_conn_t *) ssl_conn); #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump(c->log, "level:%d read secret", - rsecret, secret_len, level); + ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, + "quic ngx_quic_set_read_secret() level:%d", level); + ngx_quic_hexdump(c->log, "quic read secret", rsecret, secret_len); #endif keys = &c->quic->keys[level]; @@ -279,8 +280,9 @@ c = ngx_ssl_get_connection((ngx_ssl_conn_t *) ssl_conn); #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump(c->log, "level:%d write secret", - wsecret, secret_len, level); + ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, + "quic ngx_quic_set_write_secret() level:%d", level); + ngx_quic_hexdump(c->log, "quic write secret", wsecret, secret_len); #endif keys = &c->quic->keys[level]; @@ -304,7 +306,9 @@ c = ngx_ssl_get_connection((ngx_ssl_conn_t *) ssl_conn); #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump(c->log, "level:%d read", rsecret, secret_len, level); + ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, + "quic ngx_quic_set_encryption_secrets() level:%d", level); + ngx_quic_hexdump(c->log, "quic read", rsecret, secret_len); #endif keys = &c->quic->keys[level]; @@ -322,7 +326,7 @@ } #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump(c->log, "level:%d write", wsecret, secret_len, level); + ngx_quic_hexdump(c->log, "quic write", wsecret, secret_len); #endif return ngx_quic_set_encryption_secret(c->pool, ssl_conn, level, @@ -434,13 +438,14 @@ static int ngx_quic_flush_flight(ngx_ssl_conn_t *ssl_conn) { +#if (NGX_DEBUG) ngx_connection_t *c; c = ngx_ssl_get_connection((ngx_ssl_conn_t *) ssl_conn); ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0, "quic ngx_quic_flush_flight()"); - +#endif return 1; } @@ -676,7 +681,7 @@ } #ifdef NGX_QUIC_DEBUG_PACKETS - ngx_quic_hexdump0(c->log, "quic transport parameters", p, len); + ngx_quic_hexdump(c->log, "quic transport parameters", p, len); #endif if (SSL_set_quic_transport_params(ssl_conn, p, len) == 0) { @@ -2456,7 +2461,7 @@ } #ifdef NGX_QUIC_DEBUG_PACKETS - ngx_quic_hexdump0(c->log, "packet to send", res.data, res.len); + ngx_quic_hexdump(c->log, "quic packet to send", res.data, res.len); #endif len = c->send(c, res.data, res.len);
--- a/src/event/ngx_event_quic.h Fri Apr 24 10:11:47 2020 +0300 +++ b/src/event/ngx_event_quic.h Fri Apr 24 11:33:00 2020 +0300 @@ -87,31 +87,25 @@ //#define NGX_QUIC_DEBUG_FRAMES_ALLOC /* log frames alloc/reuse/free */ //#define NGX_QUIC_DEBUG_CRYPTO - #if (NGX_DEBUG) -#define ngx_quic_hexdump(log, fmt, data, len, ...) \ +#define ngx_quic_hexdump(log, label, data, len) \ do { \ ngx_int_t m; \ u_char buf[2048]; \ \ if (log->log_level & NGX_LOG_DEBUG_EVENT) { \ m = ngx_hex_dump(buf, (u_char *) data, ngx_min(len, 1024)) - buf; \ - ngx_log_debug(NGX_LOG_DEBUG_EVENT, log, 0, \ - "%s: " fmt " %*s%s, len: %uz", \ - __FUNCTION__, __VA_ARGS__, m, buf, \ - len < 2048 ? "" : "...", len); \ + ngx_log_debug4(NGX_LOG_DEBUG_EVENT, log, 0, \ + label " len:%uz data:%*s%s", \ + len, m, buf, len < 2048 ? "" : "..."); \ } \ } while (0) #else -#define ngx_quic_hexdump(log, fmt, data, len, ...) +#define ngx_quic_hexdump(log, fmt, data, len) #endif -#define ngx_quic_hexdump0(log, fmt, data, len) \ - ngx_quic_hexdump(log, fmt "%s", data, len, "") \ - - #endif /* _NGX_EVENT_QUIC_H_INCLUDED_ */
--- a/src/event/ngx_event_quic_protection.c Fri Apr 24 10:11:47 2020 +0300 +++ b/src/event/ngx_event_quic_protection.c Fri Apr 24 11:33:00 2020 +0300 @@ -157,8 +157,10 @@ }; #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pool->log, "salt", salt, sizeof(salt)); - ngx_quic_hexdump0(pool->log, "initial secret", is, is_len); + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, pool->log, 0, + "quic ngx_quic_set_initial_secret"); + ngx_quic_hexdump(pool->log, "quic salt", salt, sizeof(salt)); + ngx_quic_hexdump(pool->log, "quic initial secret", is, is_len); #endif /* draft-ietf-quic-tls-23#section-5.2 */ @@ -266,8 +268,10 @@ } #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump(pool->log, "%V info", info, info_len, label); - ngx_quic_hexdump(pool->log, "%V key", out->data, out->len, label); + ngx_log_debug1(NGX_LOG_DEBUG_EVENT, pool->log, 0, + "quic ngx_quic_hkdf_expand %V keys", label); + ngx_quic_hexdump(pool->log, "quic info", info, info_len); + ngx_quic_hexdump(pool->log, "quic key", out->data, out->len); #endif return NGX_OK; @@ -678,7 +682,7 @@ ngx_uint_t i; ngx_quic_ciphers_t ciphers; - ngx_log_debug(NGX_LOG_DEBUG_EVENT, c->log, 0, "quic key update"); + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0, "quic key update"); if (ngx_quic_ciphers(c->ssl->connection, &ciphers, ssl_encryption_application) @@ -766,7 +770,9 @@ out.data = res->data + ad.len; #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "ad", ad.data, ad.len); + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, pkt->log, 0, + "quic ngx_quic_create_long_packet"); + ngx_quic_hexdump(pkt->log, "quic ad", ad.data, ad.len); #endif if (ngx_quic_ciphers(ssl_conn, &ciphers, pkt->level) == NGX_ERROR) { @@ -777,8 +783,8 @@ ngx_quic_compute_nonce(nonce, sizeof(nonce), pkt->number); #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "server_iv", pkt->secret->iv.data, 12); - ngx_quic_hexdump0(pkt->log, "nonce", nonce, 12); + ngx_quic_hexdump(pkt->log, "quic server_iv", pkt->secret->iv.data, 12); + ngx_quic_hexdump(pkt->log, "quic nonce", nonce, 12); #endif if (ngx_quic_tls_seal(ciphers.c, pkt->secret, &out, @@ -796,8 +802,8 @@ } #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "sample", sample, 16); - ngx_quic_hexdump0(pkt->log, "mask", mask, 5); + ngx_quic_hexdump(pkt->log, "quic sample", sample, 16); + ngx_quic_hexdump(pkt->log, "quic mask", mask, 5); #endif /* quic-tls: 5.4.1. Header Protection Application */ @@ -831,7 +837,9 @@ out.data = res->data + ad.len; #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "ad", ad.data, ad.len); + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, pkt->log, 0, + "quic ngx_quic_create_short_packet"); + ngx_quic_hexdump(pkt->log, "quic ad", ad.data, ad.len); #endif if (ngx_quic_ciphers(ssl_conn, &ciphers, pkt->level) == NGX_ERROR) { @@ -847,8 +855,8 @@ ngx_quic_compute_nonce(nonce, sizeof(nonce), pkt->number); #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "server_iv", pkt->secret->iv.data, 12); - ngx_quic_hexdump0(pkt->log, "nonce", nonce, 12); + ngx_quic_hexdump(pkt->log, "quic server_iv", pkt->secret->iv.data, 12); + ngx_quic_hexdump(pkt->log, "quic nonce", nonce, 12); #endif if (ngx_quic_tls_seal(ciphers.c, pkt->secret, &out, @@ -866,8 +874,8 @@ } #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "sample", sample, 16); - ngx_quic_hexdump0(pkt->log, "mask", mask, 5); + ngx_quic_hexdump(pkt->log, "quic sample", sample, 16); + ngx_quic_hexdump(pkt->log, "quic mask", mask, 5); #endif /* quic-tls: 5.4.1. Header Protection Application */ @@ -977,7 +985,9 @@ sample = p + 4; #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "sample", sample, 16); + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, pkt->log, 0, + "quic ngx_quic_decrypt()"); + ngx_quic_hexdump(pkt->log, "quic sample", sample, 16); #endif /* header protection */ @@ -1007,7 +1017,7 @@ pkt->pn = pn; #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "mask", mask, 5); + ngx_quic_hexdump(pkt->log, "quic mask", mask, 5); #endif ngx_log_debug1(NGX_LOG_DEBUG_EVENT, pkt->log, 0, @@ -1040,8 +1050,8 @@ ngx_quic_compute_nonce(nonce, sizeof(nonce), pn); #ifdef NGX_QUIC_DEBUG_CRYPTO - ngx_quic_hexdump0(pkt->log, "nonce", nonce, 12); - ngx_quic_hexdump0(pkt->log, "ad", ad.data, ad.len); + ngx_quic_hexdump(pkt->log, "quic nonce", nonce, 12); + ngx_quic_hexdump(pkt->log, "quic ad", ad.data, ad.len); #endif pkt->payload.len = in.len - EVP_GCM_TLS_TAG_LEN; @@ -1056,8 +1066,8 @@ nonce, &in, &ad, pkt->log); #if defined(NGX_QUIC_DEBUG_CRYPTO) && defined(NGX_QUIC_DEBUG_PACKETS) - ngx_quic_hexdump0(pkt->log, "packet payload", - pkt->payload.data, pkt->payload.len); + ngx_quic_hexdump(pkt->log, "quic packet payload", + pkt->payload.data, pkt->payload.len); #endif return rc;
--- a/src/event/ngx_event_quic_transport.c Fri Apr 24 10:11:47 2020 +0300 +++ b/src/event/ngx_event_quic_transport.c Fri Apr 24 11:33:00 2020 +0300 @@ -235,7 +235,7 @@ end = pkt->data + pkt->len; #ifdef NGX_QUIC_DEBUG_PACKETS - ngx_quic_hexdump0(pkt->log, "long input", pkt->data, pkt->len); + ngx_quic_hexdump(pkt->log, "quic long packet in", pkt->data, pkt->len); #endif p = ngx_quic_read_uint8(p, end, &pkt->flags); @@ -392,7 +392,7 @@ end = pkt->data + pkt->len; #ifdef NGX_QUIC_DEBUG_PACKETS - ngx_quic_hexdump0(pkt->log, "short input", pkt->data, pkt->len); + ngx_quic_hexdump(pkt->log, "quic short packet in", pkt->data, pkt->len); #endif p = ngx_quic_read_uint8(p, end, &pkt->flags); @@ -476,9 +476,9 @@ pkt->len = varint; #ifdef NGX_QUIC_DEBUG_PACKETS - ngx_quic_hexdump0(pkt->log, "DCID", pkt->dcid.data, pkt->dcid.len); - ngx_quic_hexdump0(pkt->log, "SCID", pkt->scid.data, pkt->scid.len); - ngx_quic_hexdump0(pkt->log, "token", pkt->token.data, pkt->token.len); + ngx_quic_hexdump(pkt->log, "quic DCID", pkt->dcid.data, pkt->dcid.len); + ngx_quic_hexdump(pkt->log, "quic SCID", pkt->scid.data, pkt->scid.len); + ngx_quic_hexdump(pkt->log, "quic token", pkt->token.data, pkt->token.len); #endif return NGX_OK; @@ -577,8 +577,8 @@ f->u.crypto.data); #ifdef NGX_QUIC_DEBUG_FRAMES - ngx_quic_hexdump0(pkt->log, "CRYPTO frame contents", - f->u.crypto.data, f->u.crypto.length); + ngx_quic_hexdump(pkt->log, "quic CRYPTO frame", + f->u.crypto.data, f->u.crypto.length); #endif break; @@ -837,8 +837,8 @@ f->u.stream.fin); #ifdef NGX_QUIC_DEBUG_FRAMES - ngx_quic_hexdump0(pkt->log, "STREAM frame contents", - f->u.stream.data, f->u.stream.length); + ngx_quic_hexdump(pkt->log, "quic STREAM frame", + f->u.stream.data, f->u.stream.length); #endif break; @@ -1080,8 +1080,8 @@ "quic frame in: PATH_CHALLENGE"); #ifdef NGX_QUIC_DEBUG_FRAMES - ngx_quic_hexdump0(pkt->log, "path challenge data", - f->u.path_challenge.data, 8); + ngx_quic_hexdump(pkt->log, "quic PATH_CHALLENGE frame data", + f->u.path_challenge.data, 8); #endif break; @@ -1102,8 +1102,8 @@ "quic frame in: PATH_RESPONSE"); #ifdef NGX_QUIC_DEBUG_FRAMES - ngx_quic_hexdump0(pkt->log, "path response data", - f->u.path_response.data, 8); + ngx_quic_hexdump(pkt->log, "quic PATH_RESPONSE frame data", + f->u.path_response.data, 8); #endif break;