basho/webmachine — pull request #197 by cobusc (2014-04-03 14:18:32+00:00)
Title: Fix logger deadlock situation when log file is rotated

I see an issue when rotating the log file which causes the logger to deadlock and seems to block processing of new requests.

Call-cycle causing the deadlock situation:
`webmachine_log:log_access/1` --> `gen_event:sync_notify(?EVENT_LOGGER, {log_access, LogData})` --> `webmachine_access_log_handler:handle_event({log_access, ...)` -->
`webmachine_log:maybe_rotate/3` --> `webmachine_log:log_close/3` --> `webmachine_log:log_info/1` --> `gen_event:sync_notify(?EVENT_LOGGER, {log_info, LogMsg})`, which will deadlock.

I have included a (partial) backtrace below for reference. As far as I can see the `webmachine_log:log_close/3` function must not make a call to `log_info/1`, but rather to `error_logger:info_msg`, similar to what the `log_open/2` function does. Or, alternatively, `gen_event:notify` should be used. My patch uses `error_logger`.

Backtrace of the `webmachine_log_event` process (of type `gen_event`):

```
Program counter: 0x00007fceca51fa18 (gen:do_call/4 + 392)
CP: 0x0000000000000000 (invalid)
arity = 0

0x00007fce1bbb9058 Return addr 0x00007fcec81916b0 (gen_event:rpc/2 + 96)
y(0) #Ref<0.0.1.225068>
y(1) infinity
y(2) {sync_notify,{log_info,[webmachine_access_log_handler,": closing log file: ","log/access.log",10]}}
y(3) <0.89.0>
y(4) <0.89.0>
y(5) []

0x00007fce1bbb9090 Return addr 0x00007fcec555e8b0 (webmachine_log:log_close/3 + 128)

0x00007fce1bbb9098 Return addr 0x00007fcec555efe8 (webmachine_log:maybe_rotate/3 + 472)
y(0) {file_descriptor,prim_file,{#Port<0.4273>,11}}

0x00007fce1bbb90a8 Return addr 0x00007fcec5557710 (webmachine_access_log_handler:handle_event/2 + 200)
y(0) {2014,4,3,10}
y(1) []
y(2) "log/access.log"
```