comparison src/event/ngx_event_quic.c @ 8164:eed49b83e18f quic

QUIC: revised value separators in debug and error messages. All values are prefixed with name and separated from it using colon. Multiple values are listed without commas in between. Rationale: this greatly simplifies log parsing for analysis.
author Vladimir Homutov <vl@nginx.com>
date Tue, 27 Oct 2020 14:12:31 +0300
parents b3d9e57d0f62
children c53761445a66
comparison
equal deleted inserted replaced
8163:b3d9e57d0f62 8164:eed49b83e18f
697 SSL_get_peer_quic_transport_params(ssl_conn, &client_params, 697 SSL_get_peer_quic_transport_params(ssl_conn, &client_params,
698 &client_params_len); 698 &client_params_len);
699 699
700 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 700 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
701 "quic SSL_get_peer_quic_transport_params():" 701 "quic SSL_get_peer_quic_transport_params():"
702 " params_len %ui", client_params_len); 702 " params_len:%ui", client_params_len);
703 703
704 if (client_params_len == 0) { 704 if (client_params_len == 0) {
705 /* quic-tls 8.2 */ 705 /* quic-tls 8.2 */
706 qc->error = NGX_QUIC_ERR_CRYPTO(SSL_AD_MISSING_EXTENSION); 706 qc->error = NGX_QUIC_ERR_CRYPTO(SSL_AD_MISSING_EXTENSION);
707 qc->error_reason = "missing transport parameters"; 707 qc->error_reason = "missing transport parameters";
826 ngx_quic_connection_t *qc; 826 ngx_quic_connection_t *qc;
827 827
828 c = ngx_ssl_get_connection((ngx_ssl_conn_t *) ssl_conn); 828 c = ngx_ssl_get_connection((ngx_ssl_conn_t *) ssl_conn);
829 829
830 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 830 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
831 "quic ngx_quic_send_alert(), lvl=%d, alert=%d", 831 "quic ngx_quic_send_alert() lvl:%d alert:%d",
832 (int) level, (int) alert); 832 (int) level, (int) alert);
833 833
834 qc = c->quic; 834 qc = c->quic;
835 if (qc == NULL) { 835 if (qc == NULL) {
836 return 1; 836 return 1;
1580 ngx_quic_close_connection(ngx_connection_t *c, ngx_int_t rc) 1580 ngx_quic_close_connection(ngx_connection_t *c, ngx_int_t rc)
1581 { 1581 {
1582 ngx_pool_t *pool; 1582 ngx_pool_t *pool;
1583 1583
1584 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 1584 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
1585 "quic ngx_quic_close_connection, rc: %i", rc); 1585 "quic ngx_quic_close_connection rc:%i", rc);
1586 1586
1587 if (!c->quic) { 1587 if (!c->quic) {
1588 ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0, 1588 ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0,
1589 "quic close connection early error"); 1589 "quic close connection early error");
1590 1590
1656 qc->error_level = c->ssl ? SSL_quic_read_level(c->ssl->connection) 1656 qc->error_level = c->ssl ? SSL_quic_read_level(c->ssl->connection)
1657 : ssl_encryption_initial; 1657 : ssl_encryption_initial;
1658 1658
1659 if (rc == NGX_OK) { 1659 if (rc == NGX_OK) {
1660 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 1660 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
1661 "quic immediate close, drain = %d", 1661 "quic immediate close drain:%d",
1662 qc->draining); 1662 qc->draining);
1663 1663
1664 qc->close.log = c->log; 1664 qc->close.log = c->log;
1665 qc->close.data = c; 1665 qc->close.data = c;
1666 qc->close.handler = ngx_quic_close_timer_handler; 1666 qc->close.handler = ngx_quic_close_timer_handler;
1676 if (qc->error == 0 && !qc->error_app) { 1676 if (qc->error == 0 && !qc->error_app) {
1677 qc->error = NGX_QUIC_ERR_INTERNAL_ERROR; 1677 qc->error = NGX_QUIC_ERR_INTERNAL_ERROR;
1678 } 1678 }
1679 1679
1680 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 1680 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
1681 "quic immediate close due to %serror: %ui %s", 1681 "quic immediate close due to %s error: %ui %s",
1682 qc->error_app ? "app " : "", qc->error, 1682 qc->error_app ? "app " : "", qc->error,
1683 qc->error_reason ? qc->error_reason : ""); 1683 qc->error_reason ? qc->error_reason : "");
1684 } 1684 }
1685 1685
1686 (void) ngx_quic_send_cc(c); 1686 (void) ngx_quic_send_cc(c);
2017 2017
2018 if (pkt->dcid.len < NGX_QUIC_CID_LEN_MIN) { 2018 if (pkt->dcid.len < NGX_QUIC_CID_LEN_MIN) {
2019 /* 7.2. Negotiating Connection IDs */ 2019 /* 7.2. Negotiating Connection IDs */
2020 ngx_log_error(NGX_LOG_INFO, c->log, 0, 2020 ngx_log_error(NGX_LOG_INFO, c->log, 0,
2021 "quic too short dcid in initial" 2021 "quic too short dcid in initial"
2022 " packet: length %i", pkt->dcid.len); 2022 " packet: len:%i", pkt->dcid.len);
2023 return NGX_ERROR; 2023 return NGX_ERROR;
2024 } 2024 }
2025 2025
2026 qc = ngx_quic_new_connection(c, conf, pkt); 2026 qc = ngx_quic_new_connection(c, conf, pkt);
2027 if (qc == NULL) { 2027 if (qc == NULL) {
2463 } 2463 }
2464 } 2464 }
2465 2465
2466 if (p != end) { 2466 if (p != end) {
2467 ngx_log_error(NGX_LOG_INFO, c->log, 0, 2467 ngx_log_error(NGX_LOG_INFO, c->log, 0,
2468 "quic trailing garbage in payload: %ui bytes", end - p); 2468 "quic trailing garbage in payload:%ui bytes", end - p);
2469 2469
2470 qc->error = NGX_QUIC_ERR_FRAME_ENCODING_ERROR; 2470 qc->error = NGX_QUIC_ERR_FRAME_ENCODING_ERROR;
2471 return NGX_ERROR; 2471 return NGX_ERROR;
2472 } 2472 }
2473 2473
2496 c->log->action = "preparing ack"; 2496 c->log->action = "preparing ack";
2497 2497
2498 ctx = ngx_quic_get_send_ctx(c->quic, pkt->level); 2498 ctx = ngx_quic_get_send_ctx(c->quic, pkt->level);
2499 2499
2500 ngx_log_debug4(NGX_LOG_DEBUG_EVENT, c->log, 0, 2500 ngx_log_debug4(NGX_LOG_DEBUG_EVENT, c->log, 0,
2501 "quic ngx_quic_ack_packet pn %uL largest %uL" 2501 "quic ngx_quic_ack_packet pn:%uL largest %uL fr:%uL"
2502 " first %uL nranges %ui", pkt->pn, ctx->largest_range, 2502 " nranges:%ui", pkt->pn, ctx->largest_range,
2503 ctx->first_range, ctx->nranges); 2503 ctx->first_range, ctx->nranges);
2504 2504
2505 prev_pending = ctx->pending_ack; 2505 prev_pending = ctx->pending_ack;
2506 2506
2507 if (pkt->need_ack) { 2507 if (pkt->need_ack) {
2748 uint64_t base; 2748 uint64_t base;
2749 ngx_uint_t i, smallest, largest; 2749 ngx_uint_t i, smallest, largest;
2750 ngx_quic_ack_range_t *r; 2750 ngx_quic_ack_range_t *r;
2751 2751
2752 ngx_log_debug4(NGX_LOG_DEBUG_EVENT, c->log, 0, 2752 ngx_log_debug4(NGX_LOG_DEBUG_EVENT, c->log, 0,
2753 "quic ngx_quic_drop_ack_ranges pn %uL largest %uL" 2753 "quic ngx_quic_drop_ack_ranges pn:%uL largest:%uL"
2754 " first %uL nranges %ui", pn, ctx->largest_range, 2754 " fr:%uL nranges:%ui", pn, ctx->largest_range,
2755 ctx->first_range, ctx->nranges); 2755 ctx->first_range, ctx->nranges);
2756 2756
2757 base = ctx->largest_range; 2757 base = ctx->largest_range;
2758 2758
2759 if (base == NGX_QUIC_UNSET_PN) { 2759 if (base == NGX_QUIC_UNSET_PN) {
2934 qc = c->quic; 2934 qc = c->quic;
2935 2935
2936 ctx = ngx_quic_get_send_ctx(qc, pkt->level); 2936 ctx = ngx_quic_get_send_ctx(qc, pkt->level);
2937 2937
2938 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 2938 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
2939 "quic ngx_quic_handle_ack_frame level %d", pkt->level); 2939 "quic ngx_quic_handle_ack_frame level:%d", pkt->level);
2940 2940
2941 /* 2941 /*
2942 * If any computed packet number is negative, an endpoint MUST 2942 * If any computed packet number is negative, an endpoint MUST
2943 * generate a connection error of type FRAME_ENCODING_ERROR. 2943 * generate a connection error of type FRAME_ENCODING_ERROR.
2944 * (19.3.1) 2944 * (19.3.1)
2962 2962
2963 /* 13.2.3. Receiver Tracking of ACK Frames */ 2963 /* 13.2.3. Receiver Tracking of ACK Frames */
2964 if (ctx->largest_ack < max || ctx->largest_ack == NGX_QUIC_UNSET_PN) { 2964 if (ctx->largest_ack < max || ctx->largest_ack == NGX_QUIC_UNSET_PN) {
2965 ctx->largest_ack = max; 2965 ctx->largest_ack = max;
2966 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 2966 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
2967 "quic updated largest received ack: %uL", max); 2967 "quic updated largest received ack:%uL", max);
2968 2968
2969 /* 2969 /*
2970 * An endpoint generates an RTT sample on receiving an 2970 * An endpoint generates an RTT sample on receiving an
2971 * ACK frame that meets the following two conditions: 2971 * ACK frame that meets the following two conditions:
2972 * 2972 *
2991 pos += n; 2991 pos += n;
2992 2992
2993 if (gap + 2 > min) { 2993 if (gap + 2 > min) {
2994 qc->error = NGX_QUIC_ERR_FRAME_ENCODING_ERROR; 2994 qc->error = NGX_QUIC_ERR_FRAME_ENCODING_ERROR;
2995 ngx_log_error(NGX_LOG_INFO, c->log, 0, 2995 ngx_log_error(NGX_LOG_INFO, c->log, 0,
2996 "quic invalid range %ui in ack frame", i); 2996 "quic invalid range:%ui in ack frame", i);
2997 return NGX_ERROR; 2997 return NGX_ERROR;
2998 } 2998 }
2999 2999
3000 max = min - gap - 2; 3000 max = min - gap - 2;
3001 3001
3002 if (range > max) { 3002 if (range > max) {
3003 qc->error = NGX_QUIC_ERR_FRAME_ENCODING_ERROR; 3003 qc->error = NGX_QUIC_ERR_FRAME_ENCODING_ERROR;
3004 ngx_log_error(NGX_LOG_INFO, c->log, 0, 3004 ngx_log_error(NGX_LOG_INFO, c->log, 0,
3005 "quic invalid range %ui in ack frame", i); 3005 "quic invalid range:%ui in ack frame", i);
3006 return NGX_ERROR; 3006 return NGX_ERROR;
3007 } 3007 }
3008 3008
3009 min = max - range; 3009 min = max - range;
3010 3010
3028 ngx_queue_t *q; 3028 ngx_queue_t *q;
3029 ngx_quic_frame_t *f; 3029 ngx_quic_frame_t *f;
3030 ngx_quic_connection_t *qc; 3030 ngx_quic_connection_t *qc;
3031 3031
3032 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 3032 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
3033 "quic handle ack range: min:%uL max:%uL", min, max); 3033 "quic handle ack range min:%uL max:%uL", min, max);
3034 3034
3035 qc = c->quic; 3035 qc = c->quic;
3036 3036
3037 *send_time = NGX_TIMER_INFINITE; 3037 *send_time = NGX_TIMER_INFINITE;
3038 found = 0; 3038 found = 0;
3143 rttvar_sample = ngx_abs((ngx_msec_int_t) (qc->avg_rtt - adjusted_rtt)); 3143 rttvar_sample = ngx_abs((ngx_msec_int_t) (qc->avg_rtt - adjusted_rtt));
3144 qc->rttvar = 0.75 * qc->rttvar + 0.25 * rttvar_sample; 3144 qc->rttvar = 0.75 * qc->rttvar + 0.25 * rttvar_sample;
3145 } 3145 }
3146 3146
3147 ngx_log_debug4(NGX_LOG_DEBUG_EVENT, c->log, 0, 3147 ngx_log_debug4(NGX_LOG_DEBUG_EVENT, c->log, 0,
3148 "quic rtt sample: latest %M, min %M, avg %M, var %M", 3148 "quic rtt sample latest:%M min:%M avg:%M var:%M",
3149 latest_rtt, qc->min_rtt, qc->avg_rtt, qc->rttvar); 3149 latest_rtt, qc->min_rtt, qc->avg_rtt, qc->rttvar);
3150 } 3150 }
3151 3151
3152 3152
3153 static ngx_inline ngx_msec_t 3153 static ngx_inline ngx_msec_t
3203 } 3203 }
3204 3204
3205 sn->acked += f->u.stream.length; 3205 sn->acked += f->u.stream.length;
3206 3206
3207 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, sn->c->log, 0, 3207 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, sn->c->log, 0,
3208 "quic stream ack %uL acked:%uL, unacked:%uL", 3208 "quic stream ack len:%uL acked:%uL unacked:%uL",
3209 f->u.stream.length, sn->acked, sent - sn->acked); 3209 f->u.stream.length, sn->acked, sent - sn->acked);
3210 } 3210 }
3211 3211
3212 3212
3213 static ngx_int_t 3213 static ngx_int_t
3221 3221
3222 f = &frame->u.ord; 3222 f = &frame->u.ord;
3223 3223
3224 if (f->offset > fs->received) { 3224 if (f->offset > fs->received) {
3225 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 3225 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
3226 "quic out-of-order frame: expecting %uL got %uL", 3226 "quic out-of-order frame: expecting:%uL got:%uL",
3227 fs->received, f->offset); 3227 fs->received, f->offset);
3228 3228
3229 return ngx_quic_buffer_frame(c, fs, frame); 3229 return ngx_quic_buffer_frame(c, fs, frame);
3230 } 3230 }
3231 3231
3282 /* old/duplicate data range */ 3282 /* old/duplicate data range */
3283 ngx_queue_remove(q); 3283 ngx_queue_remove(q);
3284 fs->total -= f->length; 3284 fs->total -= f->length;
3285 3285
3286 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 3286 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
3287 "quic skipped buffered frame, total %ui", 3287 "quic skipped buffered frame, total:%ui",
3288 fs->total); 3288 fs->total);
3289 ngx_quic_free_frame(c, frame); 3289 ngx_quic_free_frame(c, frame);
3290 continue; 3290 continue;
3291 } 3291 }
3292 3292
3309 fs->total -= full_len; 3309 fs->total -= full_len;
3310 3310
3311 ngx_queue_remove(q); 3311 ngx_queue_remove(q);
3312 3312
3313 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 3313 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
3314 "quic consumed buffered frame, total %ui", fs->total); 3314 "quic consumed buffered frame, total:%ui", fs->total);
3315 3315
3316 ngx_quic_free_frame(c, frame); 3316 ngx_quic_free_frame(c, frame);
3317 3317
3318 } while (1); 3318 } while (1);
3319 3319
3385 3385
3386 fs->total += f->length; 3386 fs->total += f->length;
3387 3387
3388 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 3388 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
3389 "quic ordered frame with unexpected offset:" 3389 "quic ordered frame with unexpected offset:"
3390 " buffered, total %ui", fs->total); 3390 " buffered total:%ui", fs->total);
3391 3391
3392 if (ngx_queue_empty(&fs->frames)) { 3392 if (ngx_queue_empty(&fs->frames)) {
3393 ngx_queue_insert_after(&fs->frames, &dst->queue); 3393 ngx_queue_insert_after(&fs->frames, &dst->queue);
3394 return NGX_OK; 3394 return NGX_OK;
3395 } 3395 }
3466 f = &frame->u.crypto; 3466 f = &frame->u.crypto;
3467 3467
3468 ssl_conn = c->ssl->connection; 3468 ssl_conn = c->ssl->connection;
3469 3469
3470 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 3470 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
3471 "quic SSL_quic_read_level: %d, SSL_quic_write_level: %d", 3471 "quic SSL_quic_read_level:%d SSL_quic_write_level:%d",
3472 (int) SSL_quic_read_level(ssl_conn), 3472 (int) SSL_quic_read_level(ssl_conn),
3473 (int) SSL_quic_write_level(ssl_conn)); 3473 (int) SSL_quic_write_level(ssl_conn));
3474 3474
3475 if (!SSL_provide_quic_data(ssl_conn, SSL_quic_read_level(ssl_conn), 3475 if (!SSL_provide_quic_data(ssl_conn, SSL_quic_read_level(ssl_conn),
3476 f->data, f->length)) 3476 f->data, f->length))
3496 } 3496 }
3497 3497
3498 } else if (n == 1 && !SSL_in_init(ssl_conn)) { 3498 } else if (n == 1 && !SSL_in_init(ssl_conn)) {
3499 3499
3500 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 3500 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
3501 "quic ssl cipher: %s", SSL_get_cipher(ssl_conn)); 3501 "quic ssl cipher:%s", SSL_get_cipher(ssl_conn));
3502 3502
3503 ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0, 3503 ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0,
3504 "quic handshake completed successfully"); 3504 "quic handshake completed successfully");
3505 3505
3506 c->ssl->handshaked = 1; 3506 c->ssl->handshaked = 1;
3538 */ 3538 */
3539 ngx_quic_discard_ctx(c, ssl_encryption_handshake); 3539 ngx_quic_discard_ctx(c, ssl_encryption_handshake);
3540 } 3540 }
3541 3541
3542 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 3542 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
3543 "quic SSL_quic_read_level: %d, SSL_quic_write_level: %d", 3543 "quic SSL_quic_read_level:%d SSL_quic_write_level:%d",
3544 (int) SSL_quic_read_level(ssl_conn), 3544 (int) SSL_quic_read_level(ssl_conn),
3545 (int) SSL_quic_write_level(ssl_conn)); 3545 (int) SSL_quic_write_level(ssl_conn));
3546 3546
3547 return NGX_OK; 3547 return NGX_OK;
3548 } 3548 }
4328 */ 4328 */
4329 4329
4330 if (((c->sent + hlen + len + f->len) / 3) > qc->received) { 4330 if (((c->sent + hlen + len + f->len) / 3) > qc->received) {
4331 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 4331 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
4332 "quic hit amplification limit" 4332 "quic hit amplification limit"
4333 " received %uz sent %O", 4333 " received:%uz sent:%O",
4334 qc->received, c->sent); 4334 qc->received, c->sent);
4335 break; 4335 break;
4336 } 4336 }
4337 } 4337 }
4338 4338
4486 pkt.payload = out; 4486 pkt.payload = out;
4487 4487
4488 res.data = dst; 4488 res.data = dst;
4489 4489
4490 ngx_log_debug6(NGX_LOG_DEBUG_EVENT, c->log, 0, 4490 ngx_log_debug6(NGX_LOG_DEBUG_EVENT, c->log, 0,
4491 "quic packet ready: %ui bytes at level %d" 4491 "quic packet ready bytes:%ui level:%d"
4492 " need_ack: %d number: %L encoded %d:0x%xD", 4492 " need_ack:%d number:%L encoded nl:%d trunc:0x%xD",
4493 out.len, start->level, pkt.need_ack, pkt.number, 4493 out.len, start->level, pkt.need_ack, pkt.number,
4494 pkt.num_len, pkt.trunc); 4494 pkt.num_len, pkt.trunc);
4495 4495
4496 if (ngx_quic_encrypt(&pkt, ssl_conn, &res) != NGX_OK) { 4496 if (ngx_quic_encrypt(&pkt, ssl_conn, &res) != NGX_OK) {
4497 ngx_quic_free_frames(c, frames); 4497 ngx_quic_free_frames(c, frames);
4769 if (bidi) { 4769 if (bidi) {
4770 if (qc->streams.server_streams_bidi 4770 if (qc->streams.server_streams_bidi
4771 >= qc->streams.server_max_streams_bidi) 4771 >= qc->streams.server_max_streams_bidi)
4772 { 4772 {
4773 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 4773 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
4774 "quic too many server bidi streams: %uL", 4774 "quic too many server bidi streams:%uL",
4775 qc->streams.server_streams_bidi); 4775 qc->streams.server_streams_bidi);
4776 return NULL; 4776 return NULL;
4777 } 4777 }
4778 4778
4779 id = (qc->streams.server_streams_bidi << 2) 4779 id = (qc->streams.server_streams_bidi << 2)
4780 | NGX_QUIC_STREAM_SERVER_INITIATED; 4780 | NGX_QUIC_STREAM_SERVER_INITIATED;
4781 4781
4782 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 4782 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
4783 "quic creating server bidi stream %uL/%uL id:0x%xL", 4783 "quic creating server bidi stream"
4784 " streams:%uL max:%uL id:0x%xL",
4784 qc->streams.server_streams_bidi, 4785 qc->streams.server_streams_bidi,
4785 qc->streams.server_max_streams_bidi, id); 4786 qc->streams.server_max_streams_bidi, id);
4786 4787
4787 qc->streams.server_streams_bidi++; 4788 qc->streams.server_streams_bidi++;
4788 rcvbuf_size = qc->tp.initial_max_stream_data_bidi_local; 4789 rcvbuf_size = qc->tp.initial_max_stream_data_bidi_local;
4790 } else { 4791 } else {
4791 if (qc->streams.server_streams_uni 4792 if (qc->streams.server_streams_uni
4792 >= qc->streams.server_max_streams_uni) 4793 >= qc->streams.server_max_streams_uni)
4793 { 4794 {
4794 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 4795 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
4795 "quic too many server uni streams: %uL", 4796 "quic too many server uni streams:%uL",
4796 qc->streams.server_streams_uni); 4797 qc->streams.server_streams_uni);
4797 return NULL; 4798 return NULL;
4798 } 4799 }
4799 4800
4800 id = (qc->streams.server_streams_uni << 2) 4801 id = (qc->streams.server_streams_uni << 2)
4801 | NGX_QUIC_STREAM_SERVER_INITIATED 4802 | NGX_QUIC_STREAM_SERVER_INITIATED
4802 | NGX_QUIC_STREAM_UNIDIRECTIONAL; 4803 | NGX_QUIC_STREAM_UNIDIRECTIONAL;
4803 4804
4804 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 4805 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
4805 "quic creating server uni stream %uL/%uL id:0x%xL", 4806 "quic creating server uni stream"
4807 " streams:%uL max:%uL id:0x%xL",
4806 qc->streams.server_streams_uni, 4808 qc->streams.server_streams_uni,
4807 qc->streams.server_max_streams_uni, id); 4809 qc->streams.server_max_streams_uni, id);
4808 4810
4809 qc->streams.server_streams_uni++; 4811 qc->streams.server_streams_uni++;
4810 rcvbuf_size = 0; 4812 rcvbuf_size = 0;
4877 uint64_t min_id; 4879 uint64_t min_id;
4878 ngx_quic_stream_t *sn; 4880 ngx_quic_stream_t *sn;
4879 ngx_quic_connection_t *qc; 4881 ngx_quic_connection_t *qc;
4880 4882
4881 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 4883 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
4882 "quic stream id 0x%xL is new", id); 4884 "quic stream id:0x%xL is new", id);
4883 4885
4884 qc = c->quic; 4886 qc = c->quic;
4885 4887
4886 if (id & NGX_QUIC_STREAM_UNIDIRECTIONAL) { 4888 if (id & NGX_QUIC_STREAM_UNIDIRECTIONAL) {
4887 4889
4968 ngx_quic_stream_t *sn; 4970 ngx_quic_stream_t *sn;
4969 ngx_pool_cleanup_t *cln; 4971 ngx_pool_cleanup_t *cln;
4970 ngx_quic_connection_t *qc; 4972 ngx_quic_connection_t *qc;
4971 4973
4972 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 4974 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
4973 "quic stream id 0x%xL create", id); 4975 "quic stream id:0x%xL create", id);
4974 4976
4975 qc = c->quic; 4977 qc = c->quic;
4976 4978
4977 pool = ngx_create_pool(NGX_DEFAULT_POOL_SIZE, c->log); 4979 pool = ngx_create_pool(NGX_DEFAULT_POOL_SIZE, c->log);
4978 if (pool == NULL) { 4980 if (pool == NULL) {
5087 if (rev->error) { 5089 if (rev->error) {
5088 return NGX_ERROR; 5090 return NGX_ERROR;
5089 } 5091 }
5090 5092
5091 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5093 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5092 "quic stream id 0x%xL recv: eof:%d, avail:%z", 5094 "quic stream recv id:0x%xL eof:%d avail:%z",
5093 qs->id, rev->pending_eof, b->last - b->pos); 5095 qs->id, rev->pending_eof, b->last - b->pos);
5094 5096
5095 if (b->pos == b->last) { 5097 if (b->pos == b->last) {
5096 rev->ready = 0; 5098 rev->ready = 0;
5097 5099
5099 rev->eof = 1; 5101 rev->eof = 1;
5100 return 0; 5102 return 0;
5101 } 5103 }
5102 5104
5103 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 5105 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
5104 "quic stream id 0x%xL recv() not ready", qs->id); 5106 "quic stream id:0x%xL recv() not ready", qs->id);
5105 return NGX_AGAIN; 5107 return NGX_AGAIN;
5106 } 5108 }
5107 5109
5108 len = ngx_min(b->last - b->pos, (ssize_t) size); 5110 len = ngx_min(b->last - b->pos, (ssize_t) size);
5109 5111
5117 b->last = b->start; 5119 b->last = b->start;
5118 rev->ready = rev->pending_eof; 5120 rev->ready = rev->pending_eof;
5119 } 5121 }
5120 5122
5121 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5123 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5122 "quic stream id 0x%xL recv: %z of %uz", qs->id, len, size); 5124 "quic stream id:0x%xL recv len:%z of size:%uz",
5125 qs->id, len, size);
5123 5126
5124 if (!rev->pending_eof) { 5127 if (!rev->pending_eof) {
5125 frame = ngx_quic_alloc_frame(pc, 0); 5128 frame = ngx_quic_alloc_frame(pc, 0);
5126 if (frame == NULL) { 5129 if (frame == NULL) {
5127 return NGX_ERROR; 5130 return NGX_ERROR;
5151 frame->u.max_data.max_data = qc->streams.recv_max_data; 5154 frame->u.max_data.max_data = qc->streams.recv_max_data;
5152 5155
5153 ngx_quic_queue_frame(pc->quic, frame); 5156 ngx_quic_queue_frame(pc->quic, frame);
5154 5157
5155 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 5158 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
5156 "quic stream id 0x%xL recv: increased max data: %uL", 5159 "quic stream id:0x%xL recv: increased max_data:%uL",
5157 qs->id, qc->streams.recv_max_data); 5160 qs->id, qc->streams.recv_max_data);
5158 } 5161 }
5159 5162
5160 return len; 5163 return len;
5161 } 5164 }
5297 5300
5298 ngx_quic_queue_frame(qc, frame); 5301 ngx_quic_queue_frame(qc, frame);
5299 } 5302 }
5300 5303
5301 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, 5304 ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0,
5302 "quic send_chain sent:%uz, frames:%ui", sent, nframes); 5305 "quic send_chain sent:%uz nframes:%ui", sent, nframes);
5303 5306
5304 return in; 5307 return in;
5305 } 5308 }
5306 5309
5307 5310
5366 if (sent + size > qs->send_max_data) { 5369 if (sent + size > qs->send_max_data) {
5367 size = qs->send_max_data - sent; 5370 size = qs->send_max_data - sent;
5368 } 5371 }
5369 5372
5370 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 5373 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
5371 "quic send flow: %uz", size); 5374 "quic send flow:%uz", size);
5372 5375
5373 return size; 5376 return size;
5374 } 5377 }
5375 5378
5376 5379
5387 qs = c->qs; 5390 qs = c->qs;
5388 pc = qs->parent; 5391 pc = qs->parent;
5389 qc = pc->quic; 5392 qc = pc->quic;
5390 5393
5391 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 5394 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
5392 "quic stream id 0x%xL cleanup", qs->id); 5395 "quic stream id:0x%xL cleanup", qs->id);
5393 5396
5394 ngx_rbtree_delete(&qc->streams.tree, &qs->node); 5397 ngx_rbtree_delete(&qc->streams.tree, &qs->node);
5395 ngx_quic_free_frames(pc, &qs->fs.frames); 5398 ngx_quic_free_frames(pc, &qs->fs.frames);
5396 5399
5397 if (qc->closing) { 5400 if (qc->closing) {
5443 return; 5446 return;
5444 } 5447 }
5445 } 5448 }
5446 5449
5447 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0, 5450 ngx_log_debug1(NGX_LOG_DEBUG_EVENT, c->log, 0,
5448 "quic stream id 0x%xL send fin", qs->id); 5451 "quic stream id:0x%xL send fin", qs->id);
5449 5452
5450 frame = ngx_quic_alloc_frame(pc, 0); 5453 frame = ngx_quic_alloc_frame(pc, 0);
5451 if (frame == NULL) { 5454 if (frame == NULL) {
5452 return; 5455 return;
5453 } 5456 }
5545 5548
5546 timer = f->last - cg->recovery_start; 5549 timer = f->last - cg->recovery_start;
5547 5550
5548 if ((ngx_msec_int_t) timer <= 0) { 5551 if ((ngx_msec_int_t) timer <= 0) {
5549 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5552 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5550 "quic congestion ack recovery win:%uz, ss:%uz, if:%uz", 5553 "quic congestion ack recovery win:%uz ss:%uz if:%uz",
5551 cg->window, cg->ssthresh, cg->in_flight); 5554 cg->window, cg->ssthresh, cg->in_flight);
5552 5555
5553 return; 5556 return;
5554 } 5557 }
5555 5558
5556 if (cg->window < cg->ssthresh) { 5559 if (cg->window < cg->ssthresh) {
5557 cg->window += f->plen; 5560 cg->window += f->plen;
5558 5561
5559 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5562 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5560 "quic congestion slow start win:%uz, ss:%uz, if:%uz", 5563 "quic congestion slow start win:%uz ss:%uz if:%uz",
5561 cg->window, cg->ssthresh, cg->in_flight); 5564 cg->window, cg->ssthresh, cg->in_flight);
5562 5565
5563 } else { 5566 } else {
5564 cg->window += qc->tp.max_udp_payload_size * f->plen / cg->window; 5567 cg->window += qc->tp.max_udp_payload_size * f->plen / cg->window;
5565 5568
5566 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5569 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5567 "quic congestion avoidance win:%uz, ss:%uz, if:%uz", 5570 "quic congestion avoidance win:%uz ss:%uz if:%uz",
5568 cg->window, cg->ssthresh, cg->in_flight); 5571 cg->window, cg->ssthresh, cg->in_flight);
5569 } 5572 }
5570 5573
5571 /* prevent recovery_start from wrapping */ 5574 /* prevent recovery_start from wrapping */
5572 5575
5596 5599
5597 timer = f->last - cg->recovery_start; 5600 timer = f->last - cg->recovery_start;
5598 5601
5599 if ((ngx_msec_int_t) timer <= 0) { 5602 if ((ngx_msec_int_t) timer <= 0) {
5600 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5603 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5601 "quic congestion lost recovery win:%uz, ss:%uz, if:%uz", 5604 "quic congestion lost recovery win:%uz ss:%uz if:%uz",
5602 cg->window, cg->ssthresh, cg->in_flight); 5605 cg->window, cg->ssthresh, cg->in_flight);
5603 5606
5604 return; 5607 return;
5605 } 5608 }
5606 5609
5612 } 5615 }
5613 5616
5614 cg->ssthresh = cg->window; 5617 cg->ssthresh = cg->window;
5615 5618
5616 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, 5619 ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0,
5617 "quic congestion lost win:%uz, ss:%uz, if:%uz", 5620 "quic congestion lost win:%uz ss:%uz if:%uz",
5618 cg->window, cg->ssthresh, cg->in_flight); 5621 cg->window, cg->ssthresh, cg->in_flight);
5619 } 5622 }
5620 5623
5621 5624
5622 static void 5625 static void