basho/webmachine — Issue #59: Client disconnects are not logged
Author: beerriot
Created: 2012-02-27 22:32:57+00:00
State: open

If a client disconnects during a streaming response (and maybe also during a non-streaming response, if the body is larger than the buffer?), the request will never reach the logger.

The issue is in `webmachine_request:send/2`: https://github.com/basho/webmachine/blob/master/src/webmachine_request.erl#L263-268

When not using ssl, the return value from `mochiweb_socket:send/2` when the client has disconnected is `{error, enotconn}`. This falls to the catch-all match of `webmachien_request:send/2`, and the process is summarily terminated via `exit(normal)`, which prevents the calls to the logger that would normally follow sending the response.

When using ssl, the return value is instead `{error, closed}`, which is matched and ignored by the function. The request will continue "sending" the rest of the response, and eventually call the logger. A similar patch could be made for `{error, enotconn}`, though it is somewhat unfortunate that the extra work has to be done.

## Sample code

A resource that produces one byte per second, for ten seconds:

```erlang

-module(logdis_resource).
-export([init/1, to_html/2]).

-include_lib("webmachine/include/webmachine.hrl").

init([]) -> {ok, undefined}.

to_html(ReqData, State) ->
{{stream, {<<"a">>, fun() -> slow_response(10) end}}, ReqData, State}.

slow_response(0) ->
{<<>>, done};
slow_response(N) ->
timer:sleep(1000),
{<<"a">>, fun() -> slow_response(N-1) end }.
```

A dumb Webmachine logger that prints "Logging access!" when it is triggered:

```erlang
-module(logdis_logger).

-export([start_link/1, log_access/1]).

start_link(_) ->
{ok, spawn(fun() -> receive never -> ok end end)}.

log_access(_) ->
io:format("Logging access!~n").
```

Enable this dumb logger before your start the `webmachine_mochiweb` server:

```erlang
application:set_env(webmachine, webmachine_logger_module, logdis_logger)
```

Request the URL you pointed at that resource, and allow it to run for 10 seconds; you'll see 11 `a`s, and a "Logging access!" in the console. Request it again, and kill your client before all 11 `a`s come back; you'll never see "Logging access!" in the console. You can check that the process has, indeed, gone away by evaluating `length(processes())` while the client is connected, and again a second after you have disconnected it (because it has to *try* to send another chunk before it can know about the disconnect).