# HG changeset patch # User Vladimir Homutov # Date 1587717180 -10800 # Node ID f175006124d092dc823888889401810e85b18785 # Parent 2f900ae486bce7a032cb0b60a4422bc9036276ea 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 diff --git a/src/event/ngx_event_quic.c b/src/event/ngx_event_quic.c --- a/src/event/ngx_event_quic.c +++ b/src/event/ngx_event_quic.c @@ -252,8 +252,9 @@ ngx_quic_set_read_secret(ngx_ssl_conn_t 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 @@ ngx_quic_set_write_secret(ngx_ssl_conn_t 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 @@ ngx_quic_set_encryption_secrets(ngx_ssl_ 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 @@ ngx_quic_set_encryption_secrets(ngx_ssl_ } #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 @@ ngx_quic_add_handshake_data(ngx_ssl_conn 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 @@ ngx_quic_init_connection(ngx_connection_ } #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 @@ ngx_quic_send_frames(ngx_connection_t *c } #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); diff --git a/src/event/ngx_event_quic.h b/src/event/ngx_event_quic.h --- a/src/event/ngx_event_quic.h +++ b/src/event/ngx_event_quic.h @@ -87,31 +87,25 @@ ngx_connection_t *ngx_quic_create_uni_st //#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_ */ diff --git a/src/event/ngx_event_quic_protection.c b/src/event/ngx_event_quic_protection.c --- a/src/event/ngx_event_quic_protection.c +++ b/src/event/ngx_event_quic_protection.c @@ -157,8 +157,10 @@ ngx_quic_set_initial_secret(ngx_pool_t * }; #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 @@ ngx_quic_hkdf_expand(ngx_pool_t *pool, c } #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_quic_key_update(ngx_connection_t *c, 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 @@ ngx_quic_create_long_packet(ngx_quic_hea 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_create_long_packet(ngx_quic_hea 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 @@ ngx_quic_create_long_packet(ngx_quic_hea } #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 @@ ngx_quic_create_short_packet(ngx_quic_he 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_create_short_packet(ngx_quic_he 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 @@ ngx_quic_create_short_packet(ngx_quic_he } #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 @@ ngx_quic_decrypt(ngx_quic_header_t *pkt, 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 @@ ngx_quic_decrypt(ngx_quic_header_t *pkt, 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_decrypt(ngx_quic_header_t *pkt, 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 @@ ngx_quic_decrypt(ngx_quic_header_t *pkt, 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; diff --git a/src/event/ngx_event_quic_transport.c b/src/event/ngx_event_quic_transport.c --- a/src/event/ngx_event_quic_transport.c +++ b/src/event/ngx_event_quic_transport.c @@ -235,7 +235,7 @@ ngx_quic_parse_long_header(ngx_quic_head 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 @@ ngx_quic_parse_short_header(ngx_quic_hea 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 @@ ngx_quic_parse_initial_header(ngx_quic_h 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 @@ ngx_quic_parse_frame(ngx_quic_header_t * 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 @@ ngx_quic_parse_frame(ngx_quic_header_t * 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 @@ ngx_quic_parse_frame(ngx_quic_header_t * "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 @@ ngx_quic_parse_frame(ngx_quic_header_t * "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;