<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body bgcolor="#FFFFFF" text="#000000">
<p><tt>Hi Ben,</tt></p>
<p><tt>Regarding the "blocking rest_get()" problem: due to the
specifics of the libcurl API, there is<br>
no direct access to the socket file descriptors during the
initial TCP connect handshake. Thus,<br>
this phase will be synchronous (blocking), while all transfers
(send HTTP req, receive reply) are<br>
done asynchronously, regardless of how the data gets send or
arrives (all at once, in chunks,<br>
byte-by-byte, etc.).</tt></p>
<p><tt>So, indeed: on the specific test case that the remote TCP
endpoint is either unresponsive or it is<br>
blocked by a firewall, the throughput of your OpenSIPS may be
significantly affected when talking HTTP<br>
to such peers even if you perform async HTTP requests. Maybe
this is just my opinion, but I believe<br>
that the average case is when the HTTP server/API is down and
the TCP connect attempt will get rejected.<br>
See [1] for more on this topic.<br>
</tt></p>
<p><tt>Regarding the 5s vs. 8s timeouts, I will have to confirm the
behavior first and get back to you.<br>
Async is heavily reliant on tm, so I wouldn't exclude the
possibility that the transaction timeout<br>
overrides, in some cases, the async logic's timeout.<br>
</tt></p>
<p><tt>Best regards,<br>
</tt></p>
<p><tt>[1]: </tt><tt><a
href="https://serverfault.com/questions/521359/why-do-some-connections-time-out-and-others-get-refused">https://serverfault.com/questions/521359/why-do-some-connections-time-out-and-others-get-refused</a></tt></p>
<pre class="moz-signature" cols="72">Liviu Chircu
OpenSIPS Developer
<a class="moz-txt-link-freetext" href="http://www.opensips-solutions.com">http://www.opensips-solutions.com</a></pre>
<div class="moz-cite-prefix">On 25.06.2019 00:33, Ben Newlin wrote:<br>
</div>
<blockquote type="cite"
cite="mid:6ED95883-2E26-477B-A8DF-6F6C130093AF@genesys.com">
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
<meta name="Generator" content="Microsoft Word 15 (filtered
medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:12.0pt;
font-family:"Calibri",sans-serif;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:#0563C1;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:#954F72;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri",sans-serif;
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri",sans-serif;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
<div class="WordSection1">
<p class="MsoNormal"><span style="font-size:11.0pt">Hello all,<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt">During
testing I have found behavior that I cannot explain based on
our current understanding of the operation of the async and
rest_client functionality. I have reproduced this behavior
with a fairly simple script configuration, the relevant
piece of which is below:<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">children=8<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New""><o:p> </o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">loadmodule
"rest_client.so"<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">modparam("rest_client",
"connection_timeout", 5)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">modparam("rest_client",
"connect_poll_interval", 1)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">modparam("rest_client",
"curl_timeout", 5)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New""><o:p> </o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">route
{<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
xlog("L_ALERT", "before t_newtran()\r\n");<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
t_newtran();<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
xlog("L_ALERT", "after t_newtran()\r\n");<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
async(rest_post(<a class="moz-txt-link-rfc2396E" href="http://0.0.0.0">"http://0.0.0.0"</a>, "{}", "application/json",
"$var(body)", "$var(ctype)", "$var(rcode)"), test_resume);<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
xlog("L_ALERT", "after async\r\n");<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">}<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New""><o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">route[test_resume]
{<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
xlog("L_ALERT", "test_resume: $retcode\r\n");<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">
t_reply("503", "Service Unavailable");<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">}<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt">The expected
operation is to immediately trigger t_newtran() which sends
a 100 response, then timeout on the rest_post call in 5
seconds and respond with a 503. For individual calls this
does occur, although the timeout consistently takes several
seconds too long, usually ~8s, as can be seen in the logs
from the above code:<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 19:10:56 [337] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 19:10:56 [337] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 19:11:04 [337] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 19:11:04 [337] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt">The extra
time is troubling, but the bigger concern is that when I run
multiple concurrent calls, I find that the 8 UDP children
are still all blocking against the rest_post call. Here are
the logs for that test:<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [337] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [337] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [338] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [338] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [335] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [335] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [333] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:51 [333] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [331] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [331] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [336] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [336] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [332] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [332] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [334] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:52 [334] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [337] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [337] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [337] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [337] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [338] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [338] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [338] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [338] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [335] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [335] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [335] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [335] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [333] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [333] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [333] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [333] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [331] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [331] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [331] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [331] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [336] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [336] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [336] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [336] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [332] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [332] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [332] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:19:59 [332] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:00 [334] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:00 [334] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:00 [334] before t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:00 [334] after t_newtran()<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [337] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [337] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [338] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [338] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [335] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [335] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [333] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [333] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [331] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [331] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [336] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [336] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [332] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [332] test_resume: -2<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [334] ERROR:rest_client:start_async_http_req:
connect timeout on <a class="moz-txt-link-freetext" href="http://0.0.0.0">http://0.0.0.0</a> (5s)<o:p></o:p></span></p>
<p class="MsoNormal"><span
style="font-size:10.0pt;font-family:"Courier New"">Jun
24 21:20:07 [334] test_resume: -2</span><span
style="font-size:11.0pt"><o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt">You can
clearly see that the first 8 Invites are processed
immediately, but then no new messages are processed until
the rest queries begin to timeout. As each query times out,
freeing a child process, a new inbound request is processed.
Clearly the message processing is being blocked on the rest
queries, which is not supposed to happen when using async.
Am I missing something in my configuration or am I not
understanding how async is supposed to work somehow?<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;color:black">Ben
Newlin </span>
<o:p></o:p></p>
</div>
<br>
<fieldset class="mimeAttachmentHeader"></fieldset>
<pre class="moz-quote-pre" wrap="">_______________________________________________
Users mailing list
<a class="moz-txt-link-abbreviated" href="mailto:Users@lists.opensips.org">Users@lists.opensips.org</a>
<a class="moz-txt-link-freetext" href="http://lists.opensips.org/cgi-bin/mailman/listinfo/users">http://lists.opensips.org/cgi-bin/mailman/listinfo/users</a>
</pre>
</blockquote>
</body>
</html>