<div dir="ltr"><div><div>Hello,<br><br></div>If you do not use {send_timeout_close, true} on the socket, the stack will try to send the data until it succeeds or the remote end closes the connection. This means that the close will wait for the send buffer to clear before closing the connection. <br>
<br>The same is true when using port_close. The inet driver logic will detect that the<span class=""></span><span class="">re is data on the way out and wait for that data to be sent before closing.<br><br></span>So to get the behaviour you want you should set send_timeout_close to true, setting this to true is also the recommended in the setting in the documentation. <br>
<br></div><div>I also noticed that in your testcase you did not close the listen socket after the test was done which caused the testcase to leave the listen socket open in between runs.<br></div><div><br></div>Lukas<br></div>
<div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Jan 31, 2013 at 12:45 AM, Paul Cager <span dir="ltr"><<a href="mailto:paul.cager@gmail.com" target="_blank">paul.cager@gmail.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div>I am seeing a problem with erts-5.9.3.1 regarding TCP and send_timeout. Please see the example program, below, but to summarise it:</div>
<div><br></div><div> * A server accepts an incoming connection with options {send_timeout, 250}.</div>
<div> * The server continually writes data until it gets an {error, timeout}. The server then calls inet:close(Sock).</div><div> * However the socket isn't actually closed - netstat reports that it is still established (and stays that way for at least an hour, probably for ever).</div>
<div> * I've enabled debug tracing in drivers/common/inet_drv.c (+ added a couple of debugs to show the return value of inet_subscribe). I've also added tracing to show when desc_close is being called in that module.</div>
<div> * Normally calling inet:close() results in tcp_inet_stop and desc_close being called. When inet:close() is called *after* an {error, timeout} response "inet_ctl(606): INET_REQ_SUBSCRIBE" is called, but not tcp_inet_stop (or desc_close), which is consistent with the socket remaining ESTABLISHED.</div>
<div> * Using port_close rather than inet:close shows the same behaviour.</div><div><br></div><div>That does not sound like the correct behaviour.</div><div><br></div><div>Here is the debug output for a "normal" inet:close():</div>
<div><br></div><div><span style="white-space:pre-wrap"> </span>tcp_inet_ctl(606): 24</div><div><span style="white-space:pre-wrap"> </span>inet_ctl(606): INET_REQ_SUBSCRIBE</div><div><span style="white-space:pre-wrap"> </span>inet_ctl(606): Calling inet_subscribe</div>
<div><span style="white-space:pre-wrap"> </span>inet_subscribe returned 6</div><div><span style="white-space:pre-wrap"> </span>tcp_inet_stop(606) {s=10</div><div><span style="white-space:pre-wrap"> </span>deq(606): queue empty</div>
<div><span style="white-space:pre-wrap"> </span>release_buffer: 1460</div><div><span style="white-space:pre-wrap"> </span>tcp_inet_stop(606) }</div><div><span style="white-space:pre-wrap"> </span>desc_close(606): 10</div>
<div><br></div><div>Here is the debug output when receiving a {error, timeout} and calling inet:close():</div><div><br></div><div><span style="white-space:pre-wrap"> </span>tcp_sendv(606): s=10, about to send 0,8192 bytes</div>
<div><span style="white-space:pre-wrap"> </span>tcp_sendv(606): s=10, only sent 512/2 of 8192/2 bytes/items</div><div><span style="white-space:pre-wrap"> </span>tcp_sendv(606): s=10, Send failed, queuing</div>
<div><span style="white-space:pre-wrap"> </span>sock_select(606): flags=02, onoff=1, event_mask=03</div><div><span style="white-space:pre-wrap"> </span>tcp_inet_commandv(606) }</div><div>
<span style="white-space:pre-wrap"> </span>tcp_inet_commanv(606) {s=10</div><div><span style="white-space:pre-wrap"> </span>tcp_sendv(606): s=10, sender forced busy</div><div><span style="white-space:pre-wrap"> </span>tcp_inet_commandv(606) }</div>
<div><span style="white-space:pre-wrap"> </span>tcp_inet_timeout(606) {s=10</div><div><span style="white-space:pre-wrap"> </span>inet_reply_error_am 35 523</div><div><span style="white-space:pre-wrap"> </span>tcp_inet_timeout(606) }</div>
<div><span style="white-space:pre-wrap"> </span>** timeout - closing</div><div><span style="white-space:pre-wrap"> </span>** CLOSING port_info: {connected,<0.2.0>}</div><div><span style="white-space:pre-wrap"> </span>tcp_inet_ctl(606): 24</div>
<div><span style="white-space:pre-wrap"> </span>inet_ctl(606): INET_REQ_SUBSCRIBE</div><div><span style="white-space:pre-wrap"> </span>inet_ctl(606): Calling inet_subscribe</div><div><span style="white-space:pre-wrap"> </span>inet_subscribe returned 6</div>
<div><span style="white-space:pre-wrap"> </span>tcp_inet_ctl(606): 11</div><div><span style="white-space:pre-wrap"> </span>inet_ctl(606): GETSTAT</div><div><br></div><div>Do you have any ideas why this happens?</div>
<div><br></div><div><br></div><div>TEST PROGRAM</div><div>=============</div><div><br></div><div>-module(test_tcp_close).</div><div><br></div><div>-compile(export_all).</div><div><br></div><div>main() -></div><div><span style="white-space:pre-wrap"> </span>{ok, LSock} = gen_tcp:listen(1616, [binary, {packet,0}, {active, false}, {reuseaddr, true}]),</div>
<div><br></div><div><span style="white-space:pre-wrap"> </span>spawn(?MODULE, connect_and_idle, [1616]),</div><div><br></div><div><span style="white-space:pre-wrap"> </span>{ok, Sock} = gen_tcp:accept(LSock),</div>
<div><br></div><div><span style="white-space:pre-wrap"> </span>io:format("** Accepted a connection~n", []),</div><div><br></div><div><span style="white-space:pre-wrap"> </span>ok = inet:setopts(Sock, [</div>
<div><span style="white-space:pre-wrap"> </span>%% {send_timeout, 250}, {send_timeout_close, true},</div><div><span style="white-space:pre-wrap"> </span>{send_timeout, 250},</div><div>
<span style="white-space:pre-wrap"> </span>{active, once}, {nodelay, true}, {sndbuf, 131072}, {keepalive, true}</div><div><span style="white-space:pre-wrap"> </span>]),</div><div><br></div>
<div><span style="white-space:pre-wrap"> </span>fill_write(Sock).</div><div><br></div><div>fill_write(Sock) -></div><div><span style="white-space:pre-wrap"> </span>%% Make sure the output buffer becomes full so we trigger send_timeout.</div>
<div><span style="white-space:pre-wrap"> </span></div><div><span style="white-space:pre-wrap"> </span>Size = 8 * 1024 * 8,<span style="white-space:pre-wrap"> </span>%% 8 KB (k *bytes*).</div>
<div><span style="white-space:pre-wrap"> </span>case gen_tcp:send(Sock, <<0:Size>>) of</div><div><span style="white-space:pre-wrap"> </span>{error, timeout} -></div><div>
<span style="white-space:pre-wrap"> </span>io:format("** timeout - closing~n", []),</div><div><span style="white-space:pre-wrap"> </span>io:format("** CLOSING port_info: ~p~n", [catch erlang:port_info(Sock, connected)]),</div>
<div><span style="white-space:pre-wrap"> </span>inet:close(Sock),</div><div><span style="white-space:pre-wrap"> </span>%% Wait at least INET_CLOSE_TIMEOUT and a bit</div><div><span style="white-space:pre-wrap"> </span>timer:sleep(10000),</div>
<div><span style="white-space:pre-wrap"> </span>io:format("** CLOSED port_info: ~p~n", [catch erlang:port_info(Sock, connected)]);</div><div><span style="white-space:pre-wrap"> </span>{error, X} -></div>
<div><span style="white-space:pre-wrap"> </span>io:format("** Unexpected send error: ~p~n", [X]),</div><div><span style="white-space:pre-wrap"> </span>io:format("** port_info: ~p~n", [catch erlang:port_info(Sock, connected)]);</div>
<div><span style="white-space:pre-wrap"> </span>ok -></div><div><span style="white-space:pre-wrap"> </span>%% Uncomment to test an early close</div><div><span style="white-space:pre-wrap"> </span>%% io:format("** Closing Sock early~n", []),</div>
<div><span style="white-space:pre-wrap"> </span>%% inet:close(Sock),</div><div><span style="white-space:pre-wrap"> </span>%% io:format("** Closed~n", []),</div><div><span style="white-space:pre-wrap"> </span>timer:sleep(1000),</div>
<div><span style="white-space:pre-wrap"> </span>fill_write(Sock)</div><div><span style="white-space:pre-wrap"> </span>end.</div><div><br></div><div>connect_and_idle(Port) -></div><div>
<span style="white-space:pre-wrap"> </span>{ok, _Sock} = gen_tcp:connect("localhost", Port, [{active,false}, {mode,binary}, {packet, 0}]),</div><div><span style="white-space:pre-wrap"> </span>timer:sleep(infinity).</div>
<br>_______________________________________________<br>
erlang-questions mailing list<br>
<a href="mailto:erlang-questions@erlang.org">erlang-questions@erlang.org</a><br>
<a href="http://erlang.org/mailman/listinfo/erlang-questions" target="_blank">http://erlang.org/mailman/listinfo/erlang-questions</a><br>
<br></blockquote></div><br></div>