чт, 11 янв. 2024 г. в 20:00, <izor...@gmail.com>: > Добрый вечер, Илья. > > > Да, только 9 раз. Сейчас в тестах вообще только 3 раза был вызов. И в > debug режиме > > чаще используется __libc_write вызов. > > > > 6965 69.8% 69.8% 6965 69.8% __libc_write > > 654 6.6% 76.3% 654 6.6% __sendmsg > > 357 3.6% 79.9% 357 3.6% _aesni_ctr32_ghash_6x > > 322 3.2% 83.1% 536 5.4% ngx_vslprintf > > 300 3.0% 86.1% 300 3.0% syscall > > 277 2.8% 88.9% 277 2.8% __libc_pread64 > > 226 2.3% 91.2% 226 2.3% __memmove_avx_unaligned_erms > > 142 1.4% 92.6% 190 1.9% ngx_sprintf_num > > 93 0.9% 93.5% 7911 79.2% ngx_log_error_core > > 63 0.6% 94.1% 63 0.6% epoll_wait > > 55 0.6% 94.7% 55 0.6% __recvmsg > > 35 0.4% 95.0% 300 3.0% ngx_slprintf > > 19 0.2% 95.2% 19 0.2% __strcmp_avx2 > > 17 0.2% 95.4% 89 0.9% ngx_quic_create_frame > > 16 0.2% 95.6% 16 0.2% _init@39000 > > ... > > 3 0.0% 98.6% 3 0.0% __sendmmsg > > ... > > > > Размер лог-файла получился очень большим, около 1.5 Gb. В нём около > нескольких сотен > > упоминаний sendmmsg. Что там искать, на что обратить внимание? >
я имею в виду вот этот код + if (n == -1) { + err = ngx_errno; + + switch (err) { + case NGX_EAGAIN: + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, err, + "sendmmsg() not ready"); + + ngx_quic_revert_send(c, ctx, preserved_pnum); + + ngx_add_timer(&qc->push, NGX_QUIC_SOCKET_RETRY_DELAY); + return NGX_OK; + + case NGX_EINTR: + ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, err, + "sendmmsg() was interrupted"); + goto eintr; + + default: + c->write->error = 1; + ngx_connection_error(c, err, "sendmsg() failed"); + return NGX_ERROR; + } + } ну то есть искать либо "sendmmsg()", либо явно поправить ngx_log_debug, чтобы удобнее было искать в том, что вы прислали, я не вижу такого патерна > > > cat /tmp/nginx/debug.log| grep 'sendmmsg' > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size > 69087 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size > 69087 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size > 69087 > > ... > > Часть лога с sendmmsg: > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx app STREAM > id:0x0 off:3145389 len:339 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet tx app bytes:1162 > need_ack:1 number:2784 encoded nl:1 trunc:0xe0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size > 69087 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:69087 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer: 9, old: > 863483412, new: 863483521 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic lost timer pto:48 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: > 48:863423569 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic state: send:59891 pto:48 > > 2024/01/11 21:32:36 [debug] 33853#33853: quic recvmsg on [::]:443, ready: 0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic recvmsg: fd:9 n:51 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic input handler > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx short flags:42 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx dcid len:20 > 000000000001a00183bd407243b7f2011ca86733 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx clearflags:40 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx number:52 len:1 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet len:51 via sock > seq:0 path seq:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic path seq:0 status > tx:3319325 rx:7668 valid:1 st:2 mtu:1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame rx app ACK n:0 > delay:15 2784-2669 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_handle_ack_frame > level:3 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion slow start > win:3379951 ss:-1 if:67887 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic stream id:0x0 ack > len:1152 fin:0 unacked:64384 > > 2024/01/11 21:32:36 [debug] 33853#33853: *6 post event 00006741DE771C80 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion slow start > win:3381151 ss:-1 if:66687 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic stream id:0x0 ack > len:1152 fin:0 unacked:63232 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion slow start > win:3382351 ss:-1 if:65487 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic stream id:0x0 ack > len:1152 fin:0 unacked:62080 > > > > Ещё часть лога с sendmsg: > > 024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_add_handshake_data > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > SSL_get_peer_quic_transport_params(): params_len:74 > > 2024/01/11 21:32:36 [info] 33853#33853: *1 quic unknown transport param > id:0x11, skipped while handling frames, client: ::1, server: [::]:443 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic transport parameters > parsed ok > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp disable active > migration: 0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp idle_timeout:60000 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > max_udp_payload_size:65527 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_data:1310720 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > max_stream_data_bidi_local:131072 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > max_stream_data_bidi_remote:131072 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > max_stream_data_uni:131072 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > initial_max_streams_bidi:262144 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > initial_max_streams_uni:262144 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp ack_delay_exponent:3 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_ack_delay:25 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp > active_connection_id_limit:2 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp initial > source_connection_id len:20 de1e73dcd4e6a4fdc6ecfb38ac840a34922b8517 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: > 00006741DE627800:512 @16 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE650000:4096 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 post event 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > ngx_quic_set_encryption_secrets() level:2 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > ngx_quic_add_handshake_data > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE651000:4096 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: > 00006741DE627A00:512 @16 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event > 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > ngx_quic_add_handshake_data > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE652000:4096 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event > 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > ngx_quic_add_handshake_data > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE653000:4096 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: > 00006741DE627C00:512 @16 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event > 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > ngx_quic_add_handshake_data > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE654000:4096 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event > 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_flush_flight() > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic > ngx_quic_set_encryption_secrets() level:3 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 SSL_do_handshake: -1 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 SSL_get_error: 2 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame rx init PADDING > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_ack_packet pn:0 > largest -1 fr:0 nranges:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event > 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet done rc:0 > level:init decr:1 pn:0 perr:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: > 60000:863483412 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: > 60000:863483412 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic state: read:60000 > close:60000 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 delete posted event > 00006741DE6D5608 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic push handler > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: > 00006741DE627E00:512 @16 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output init packet > max:1200 min:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx init ACK n:0 > delay:0 0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx init CRYPTO > len:123 off:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet tx init bytes:132 > need_ack:1 number:0 encoded nl:1 trunc:0x0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output hs packet max:1001 > min:1001 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO > len:163 off:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic split frame now:1403 > need:768 shrink:635 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO > len:763 off:163 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet tx hs bytes:935 > need_ack:1 number:0 encoded nl:1 trunc:0x0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmsg: 1200 of 1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:199 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output hs packet max:1200 > min:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO > len:635 off:926 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic split frame now:525 > need:494 shrink:31 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO > len:489 off:1561 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet tx hs bytes:1134 > need_ack:1 number:1 encoded nl:1 trunc:0x1 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmsg: 1200 of 1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2400 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2400 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output hs packet max:1200 > min:0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:31 > off:2050 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:36 > off:2081 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet tx hs bytes:75 > need_ack:1 number:2 encoded nl:1 trunc:0x2 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmsg: 141 of 141 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2400 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2541 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2541 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic path limit 1200 - 1059 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer: 9, old: > 863483412, new: 863483412 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic lost timer pto:997 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: > 997:863424409 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic state: send:60000 pto:997 > close:60000 > > 2024/01/11 21:32:36 [debug] 33853#33853: quic recvmsg on [::]:443, ready: 0 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic recvmsg: fd:9 n:1200 > > 2024/01/11 21:32:36 [debug] 33853#33853: *1 quic input handler > > > > > > Вы писали 11 января 2024 г., 16:59:54: > > > > 9 раз вызвался ? > есть подозрение, что произошла ошибка и перешли на sendmsg. > попробуйте в дебаге, в прилагаемом патче есть ngx_log_debug0(...) > >> > > -- > С уважением, > Izorkin mailto:izor...@gmail.com > <izor...@gmail.com> > _______________________________________________ > nginx-ru mailing list > nginx-ru@nginx.org > https://mailman.nginx.org/mailman/listinfo/nginx-ru >
_______________________________________________ nginx-ru mailing list nginx-ru@nginx.org https://mailman.nginx.org/mailman/listinfo/nginx-ru