<div dir="ltr"><div dir="ltr"><br></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">вт, 4 февр. 2020 г. в 21:07, Valentin Micic <<a href="mailto:v@micic.co.za" target="_blank">v@micic.co.za</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div><br><div><br><blockquote type="cite"><div>On 04 Feb 2020, at 16:53, Alexander Petrovsky <<a href="mailto:askjuise@gmail.com" target="_blank">askjuise@gmail.com</a>> wrote:</div><br><div><div dir="ltr"><div dir="ltr"><br></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">вт, 4 февр. 2020 г. в 16:52, Valentin Micic <<a href="mailto:v@micic.co.za" target="_blank">v@micic.co.za</a>>:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div><div><br><div><blockquote type="cite"><div>On 04 Feb 2020, at 10:31, Alexander Petrovsky <<a href="mailto:askjuise@gmail.com" target="_blank">askjuise@gmail.com</a>> wrote:</div><br><div><div dir="ltr"><div dir="ltr">Hello!<div><br></div><div>The first of all, my erlang version OTP-21.3 (without any minor patches)</div><div><br></div><div>I've got the strange floating problem with UDP to receive, which I couldn't debug by myself. Let me describe briefly what I have: There is UDP socket which used for send packets to many peers and receives responses from them (rate ~1pps):</div><div><br></div><div>send request: SIP options</div><div>receive a response: 100</div><div>receive a response: 200</div><div><div><br></div><div>In erlang it's implemented like gen_server which receives messages, the sockets options are: <font face="monospace">binary, {active, once}</font>.</div><div><br></div><div>Every time, when the message is received from the mailbox, code try to do some job, after that try to handle message bursts by calling in the loop (by example 5 times):</div><div><code><span>gen_udp</span><span>:</span><span>recv</span><span>(</span><span>Socket</span><span>,</span> <span>0</span><span>,</span> <span>0</span><span>), <font face="arial, sans-serif">bursts and after that set the socket option </font></span></code>{active, once} <span style="font-family:arial,sans-serif">back.</span></div><div><br></div><div>So, here I'm observing floating strange behavior, from time to time the second!! and always the second!! response is absent. I see this UDP missing packets in tcpdump, I don't see any drops in UDP stack at all.</div><div><br></div><div>When I'm trying to add some logs into my erlang code, the problem disappears, when I'm run <font face="monospace">strace</font> to <font face="monospace">recvfrom</font> syscall the problem disappears... I't try to debug VM with <font face="monospace">gdb</font> and make some breakpoints on <font face="monospace">sock_recvfrom</font> in <font face="monospace">inet_drv.c</font><font face="arial, sans-serif"> (it's OTP-<font style="background-color:rgb(255,255,255)"><span style="white-space:pre-wrap">21.</span><span style="box-sizing:border-box;border-radius:0.2em;white-space:pre-wrap">3), but </span></font></font>the problem disappears (((</div><div><br></div><div>I can't find the problem root cause, is it in my code or is it in VM? Maybe someone could help me with that? </div><div><br></div>-- <br><div dir="ltr"><div dir="ltr"><div><div dir="ltr">Петровский Александр / Alexander Petrovsky,<br><br>Skype: askjuise<br><div>Phone: +7 931 9877991<div><br></div></div></div></div></div></div></div></div></div>
</div></blockquote></div><div><br></div><div>So, I suppose this is related to SIP communication, and I’ll go out on a limb here…</div><div><br></div><div>Considering that SIP message, when transported using UDP, must fit into a single UDP message, then, your statement that second and only second response packet is missing, may imply that you are sending response using two UDP packets.</div><div><br></div><div>(A) AFAIK, SIP over UDP does not have any continuation, hence, must fit into a single packet.</div><div>If you (by any chance) send SIP message over multiple UDP packets, this shouldl not work — saying this just in case.</div><div><br></div><div>(B) OTOH, if tcpdump reveals UDP fragmentation (where a single UDP datagram is fragmented over multiple IP packets), then maybe your UDP buffer it to small to assemble the whole message, in which case message might be truncated, and your SIP parser may see it as the part of the message (second!! and always second!!), that’s gone missing.</div><div><br></div><div>(C) Finally, when your server processing is too slow for the size of the buffer, then, there’s a chance that receive buffer may get full, in which case it would drop the packet that cannot be added to the receive buffer.</div><div><br></div><div>However, judging from your “second!! and always second!!” statement, I’d say that (A) or (B), are more likely, barring something completely different (e.g some other bug, perhaps ;-))</div><div><br></div><div>Kind regards</div><div><br></div><div>V/</div><div><br></div><div><br></div><div>.</div><div><br></div><div><br></div></div></div></blockquote></div><br clear="all"><div>Accordingly to tcpdump the size on packets from 300 to 400 bytes... also, I've double-checked, there are no fragmented packets at all, my <font face="monospace">ss -anump</font> for beam shows:</div><div><br></div><div><font face="monospace">skmem:(r0,rb16384,t0,tb212992,f4096,w0,o0,bl0,d0)</font><br></div><div><br></div><div>where:</div><div> - <font face="monospace">rb16384</font> - rx buffer;</div><div> - <font face="monospace">tb212992</font> - tx buffer;</div><div> - <font face="monospace">d0</font><font face="arial, sans-serif"> - drop counter.</font></div><div><br></div><div>So, I guess it's not an (A) nor (B). My internal erlang buffer <strong style="color:rgb(26,26,26);font-family:sans-serif;font-size:16px;background-color:rgb(254,254,254)"><span style="font-family:mono,Courier,monospace;font-weight:normal;background-color:rgb(243,243,243)">{buffer, </span></strong><strong style="color:rgb(26,26,26);font-family:sans-serif;font-size:16px;background-color:rgb(254,254,254)"><span style="font-family:mono,Courier,monospace;font-weight:normal;background-color:rgb(243,243,243)">Size}</span></strong> (<a href="https://erlang.org/doc/man/inet.html" target="_blank">https://erlang.org/doc/man/inet.html</a>) is 8192. It's could be (C), but the incoming packet rate is really low. Also, it's not a SIP parser for messages received over UDP, due to I don't see and packets in my receive process...</div><div><br></div>-- <br><div dir="ltr"><div dir="ltr"><div><div dir="ltr">Петровский Александр / Alexander Petrovsky,<br><br>Skype: askjuise<br><div>Phone: +7 931 9877991<div><br></div></div></div></div></div></div></div>
</div></blockquote><br></div><div>We (and by that I include myself as well) have been using {active, once}, followed by gen_udp:recv/3 construct quite often, and I do not recall ever loosing a packet when rates were less than, say,  80,000 UDP messages/second — provided that the server processing  is fast enough (but that's a different conversation).</div><div><br></div><div>Transition between {active, once} and gen_udp:recv/3 will *never* loose any packets, as the packet will be in the UDP buffer until recalled by gen_udp:recv or another {active, once} </div><div><br></div><div>Maybe you should  consider a situation when the second packet is *not* in the buffer yet (e.g. enroute).  In that case gen_udp:recv(sock, 0, 0 ) will fail with {error, timeout}, and you’ll pick up the “second” UDP message only next time when you call {active once}.</div><div><br></div><div>So, why don’t you go and change this timeout value to something other than zero, say, 1000 (one second) just to see if the behaviour changes in any way. Then you could reduce it to something smaller… say 10, or even 5 ms.</div><div><br></div><div><br></div><div>V/</div><div><br></div></div></blockquote></div><br clear="all"><div>Using <font face="monospace">systemtap</font>, thanks to Andreas Schultz for a good idea, I find out, that all UDP packets are read by erlang VM from Linux kernel buffers without any losses.</div><div><br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Maybe you should  consider a situation when the second packet is *not* in the buffer yet (e.g. enroute).  In that case gen_udp:recv(sock, 0, 0 ) will fail with {error, timeout}, and you’ll pick up the “second” UDP message only next time when you call {active once}.</blockquote><div><br></div><div>Yeah, it seems like you are right, the problem in pair <font face="monospace">{active, once}</font> and <font face="monospace">gen_udp:recv(sock, 0, 0)</font><font face="arial, sans-serif">.</font> After packet delivered and read from the mailbox, <font face="monospace">gen_udp:recv(sock, 0, 0)</font> is called (socket state is <font face="monospace">{active, false})</font> and it will fail with <font face="monospace">{error, timeout}.</font> It's doesn't matter how many times I'll call <font face="monospace">gen_udp:recv(sock, 0, 0)</font> one time, one million times, or one million times with 1-second interval - the result always will be<font face="monospace"> {error, timeout}</font>. But if I'll call <font face="monospace">gen_udp:recv(sock, 0, 1)</font> (timeout is 1ms by example) the result will be <font face="monospace">{error, timeout}</font> too, but! after that, each of N calls of <font face="monospace">gen_udp:recv(sock, 0, 0)</font> (pay attention, the timeout is 0ms) will gives UDP packet.</div><div><br></div><div>So, what I found next: I create UDP socket and set the<font face="monospace"> {active, once}</font> on it, after the message is delivered, just call <font face="monospace">gen_udp:recv(sock, 0, 0)</font> by hand several times and see what happens in <font face="monospace">systemtap</font> and in <font face="monospace">gdb</font>.</div><div><br></div><div>a) the data evenly comes into UDP socket from network...</div><div>b) socket in state {active, once} and <font face="monospace">systemtap</font> shows me that VM thread read data from the socket (into the internal buffer) with <font face="monospace">recvfrom</font> syscall "in the loop";</div><div>c) socket in state {active, false} and  <font face="monospace">systemtap</font> shows me that VM thread read data from the socket (into the internal buffer) with <font face="monospace">recvfrom</font> syscall "in the loop";</div><div>d) call <font face="monospace">gen_udp:recv(sock, 0, 0)</font> several times by hand, got <font face="monospace">{error, timeout}</font>; <font face="monospace">systemtap</font> still shows me that VM thread read data from the socket (into the internal buffer) with <font face="monospace">recvfrom</font> syscall;</div><div>e) call <font face="monospace">gen_udp:recv(sock, 0, 0)</font><font face="arial, sans-serif"> </font>with gdb breakpoint on <a href="https://github.com/erlang/otp/blob/OTP-21.3/erts/emulator/drivers/common/inet_drv.c#L12528">https://github.com/erlang/otp/blob/OTP-21.3/erts/emulator/drivers/common/inet_drv.c#L12528</a>, I see that call VM try to read from socket (in my mind it's strange, there is data in the internal buffer...), <font face="monospace">recvfrom</font> syscall return -1, the erlang code got <font face="monospace">{error, timeout};</font></div><div><font face="monospace">f) </font><font face="monospace">systemtap</font> still shows me that VM thread read data from the socket (into the internal buffer) with <font face="monospace">recvfrom</font> syscall "in the loop";</div><div><br></div><div><font face="monospace">g) </font>call <font face="monospace">gen_udp:recv(sock, 0, 1)</font><font face="arial, sans-serif"> </font>with gdb breakpoint once again, the <font face="monospace">recvfrom</font> syscall return -1, but in this case VM calls <a href="https://github.com/erlang/otp/blob/OTP-21.3/erts/emulator/drivers/common/inet_drv.c#L12533">https://github.com/erlang/otp/blob/OTP-21.3/erts/emulator/drivers/common/inet_drv.c#L12533</a> and thread don't read data from the socket "in the loop" anymore. Next N calls gen_udp:recv(sock, 0, 0) will return data, and each will call <font face="monospace">recvfrom</font> syscall. At this point, just for note, if incoming rate it more than reading rate, I see UDP packet drops in the kernel buffers...</div><div>h) when N+1...N+M call of <font face="monospace">gen_udp:recv(sock, 0, 0)</font> returns <font face="monospace">{error, timeout}</font>, VM thread start read data from the socket "in the loop" once again...</div><div><br></div><div>So, this behaviour (strange in my mind) shed the light a little bit on my missing UDP packets... I'm still wondering, why <font face="monospace">gen_udp:recv(sock, 0, 1)</font> moves socket into "manual control", why <font face="monospace">gen_udp:recv(sock, 0, 1)</font> don't read the data from the internal buffer?</div><div><br></div>-- <br><div dir="ltr"><div dir="ltr"><div><div dir="ltr">Петровский Александр / Alexander Petrovsky,<br><br>Skype: askjuise<br><div>Phone: +7 931 9877991<div><br></div></div></div></div></div></div></div>