<html><head> <style type="text/css" title="rt_noDelete">
blockquote.rt {
margin: 0 0 15px;
border-left: 4px solid #81c784;
padding: 0 0 0 12px;
display: block;
}
p { margin: 0 0 0 0 }
.email-signature {font-family:"Arial"; font-size: 8pt; font-style: italic; font-weight: normal; text-decoration: none; }
</style></head><body><p class="norm">Добрый вечер, Илья.</p><p class="norm"><br/></p><p>Да, только 9 раз. Сейчас в тестах вообще только 3 раза был вызов. И в debug режиме</p><p>чаще используется __libc_write вызов.</p><p> </p><p> 6965 69.8% 69.8% 6965 69.8% __libc_write</p><p> 654 6.6% 76.3% 654 6.6% __sendmsg</p><p> 357 3.6% 79.9% 357 3.6% _aesni_ctr32_ghash_6x</p><p> 322 3.2% 83.1% 536 5.4% ngx_vslprintf</p><p> 300 3.0% 86.1% 300 3.0% syscall</p><p> 277 2.8% 88.9% 277 2.8% __libc_pread64</p><p> 226 2.3% 91.2% 226 2.3% __memmove_avx_unaligned_erms</p><p> 142 1.4% 92.6% 190 1.9% ngx_sprintf_num</p><p> 93 0.9% 93.5% 7911 79.2% ngx_log_error_core</p><p> 63 0.6% 94.1% 63 0.6% epoll_wait</p><p> 55 0.6% 94.7% 55 0.6% __recvmsg</p><p> 35 0.4% 95.0% 300 3.0% ngx_slprintf</p><p> 19 0.2% 95.2% 19 0.2% __strcmp_avx2</p><p> 17 0.2% 95.4% 89 0.9% ngx_quic_create_frame</p><p> 16 0.2% 95.6% 16 0.2% _init@39000</p><p>...</p><p> 3 0.0% 98.6% 3 0.0% __sendmmsg </p><p>...</p><p> </p><p>Размер лог-файла получился очень большим, около 1.5 Gb. В нём около нескольких сотен</p><p>упоминаний sendmmsg. Что там искать, на что обратить внимание?</p><p> </p><p>cat /tmp/nginx/debug.log| grep 'sendmmsg' </p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size 69087</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size 69087</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size 69087</p><p>...</p><p>Часть лога с sendmmsg:</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx app STREAM id:0x0 off:3145389 len:339</p><p>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</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmmsg: 2 of 2 msg of size 69087</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:69087</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer: 9, old: 863483412, new: 863483521</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic lost timer pto:48</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: 48:863423569</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic state: send:59891 pto:48</p><p>2024/01/11 21:32:36 [debug] 33853#33853: quic recvmsg on [::]:443, ready: 0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic recvmsg: fd:9 n:51</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic input handler</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx short flags:42</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx dcid len:20 000000000001a00183bd407243b7f2011ca86733</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx clearflags:40</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet rx number:52 len:1</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet len:51 via sock seq:0 path seq:0</p><p>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</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame rx app ACK n:0 delay:15 2784-2669</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_handle_ack_frame level:3</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion slow start win:3379951 ss:-1 if:67887</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic stream id:0x0 ack len:1152 fin:0 unacked:64384</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *6 post event 00006741DE771C80</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion slow start win:3381151 ss:-1 if:66687</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic stream id:0x0 ack len:1152 fin:0 unacked:63232</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion slow start win:3382351 ss:-1 if:65487</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic stream id:0x0 ack len:1152 fin:0 unacked:62080</p><p> </p><p>Ещё часть лога с sendmsg:</p><p>024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_add_handshake_data</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic SSL_get_peer_quic_transport_params(): params_len:74</p><p>2024/01/11 21:32:36 [info] 33853#33853: *1 quic unknown transport param id:0x11, skipped while handling frames, client: ::1, server: [::]:443</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic transport parameters parsed ok</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp disable active migration: 0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp idle_timeout:60000</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_udp_payload_size:65527</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_data:1310720</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_stream_data_bidi_local:131072</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_stream_data_bidi_remote:131072</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_stream_data_uni:131072</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp initial_max_streams_bidi:262144</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp initial_max_streams_uni:262144</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp ack_delay_exponent:3</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp max_ack_delay:25</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp active_connection_id_limit:2</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic tp initial source_connection_id len:20 de1e73dcd4e6a4fdc6ecfb38ac840a34922b8517</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: 00006741DE627800:512 @16</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE650000:4096</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 post event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_set_encryption_secrets() level:2</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_add_handshake_data</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE651000:4096</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: 00006741DE627A00:512 @16</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_add_handshake_data</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE652000:4096</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_add_handshake_data</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE653000:4096</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: 00006741DE627C00:512 @16</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_add_handshake_data</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 malloc: 00006741DE654000:4096</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_flush_flight()</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_set_encryption_secrets() level:3</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 SSL_do_handshake: -1</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 SSL_get_error: 2</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame rx init PADDING</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic ngx_quic_ack_packet pn:0 largest -1 fr:0 nranges:0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 update posted event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic packet done rc:0 level:init decr:1 pn:0 perr:0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: 60000:863483412</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: 60000:863483412</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic state: read:60000 close:60000</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 delete posted event 00006741DE6D5608</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic push handler</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 posix_memalign: 00006741DE627E00:512 @16</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output init packet max:1200 min:0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx init ACK n:0 delay:0 0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx init CRYPTO len:123 off:0</p><p>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</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output hs packet max:1001 min:1001</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:163 off:0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic split frame now:1403 need:768 shrink:635</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:763 off:163</p><p>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</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmsg: 1200 of 1200</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:199</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:1200</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:1200</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output hs packet max:1200 min:0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:635 off:926</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic split frame now:525 need:494 shrink:31</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:489 off:1561</p><p>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</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmsg: 1200 of 1200</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:1200</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2400</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2400</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic output hs packet max:1200 min:0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:31 off:2050</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic frame tx hs CRYPTO len:36 off:2081</p><p>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</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 sendmsg: 141 of 141</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2400</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2541</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic congestion send if:2541</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic path limit 1200 - 1059</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer: 9, old: 863483412, new: 863483412</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic lost timer pto:997</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 event timer add: 9: 997:863424409</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic state: send:60000 pto:997 close:60000</p><p>2024/01/11 21:32:36 [debug] 33853#33853: quic recvmsg on [::]:443, ready: 0</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic recvmsg: fd:9 n:1200</p><p>2024/01/11 21:32:36 [debug] 33853#33853: *1 quic input handler</p><p> </p><p> </p><p class="norm">Вы писали 11 января 2024 г., 16:59:54:</p><p> </p><blockquote class="rt"><div dir="ltr"><div class="gmail_quote"><div>9 раз вызвался ?</div><div>есть подозрение, что произошла ошибка и перешли на sendmsg.</div><div>попробуйте в дебаге, в прилагаемом патче есть ngx_log_debug0(...)</div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
</blockquote></div></div>
</blockquote><p class="norm"></p><p class="norm"><br/></p><p> </p><div class="email-signature">-- <br/>
С уважением,<br/>
Izorkin <a class="HR" href="mailto:izorkin@gmail.com">mailto:izorkin@gmail.com</a></div></body>