Log OS process I/O

Logging is based on an environment variable:

`COUCHDB_IO_LOG_DIR`

If set, logs will go to that directory.

Logs are per `couch_os_process` Erlang process. There are 3 files saved for
each process:

```
<unixtimestamp>_<erlangpid>.in.log : Input, data coming from the proess
<unixtimestamp>_<erlangpid>.out.log : Output, data going to the process
<unixtimestamp>_<erlangpid>.meta : Error reason
```

Log files are saved as named (visible) files only if an error occurs. If there
is no error, disk space will still be used as long the process is alive. But as
soon as it exists, file will be unlinked and space will be reclaimed.

Issue: #551

2 files changed, 121 insertions, 3 deletions

diff --git a/src/couch/src/couch_io_logger.erl b/src/couch/src/couch_io_logger.erl
new file mode 100644
index 000000000..188e031cb
--- /dev/null
+++ b/src/couch/src/couch_io_logger.erl
@@ -0,0 +1,107 @@
+% Licensed under the Apache License, Version 2.0 (the "License"); you may not
+% use this file except in compliance with the License. You may obtain a copy of
+% the License at
+%
+%   http://www.apache.org/licenses/LICENSE-2.0
+%
+% Unless required by applicable law or agreed to in writing, software
+% distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+% WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+% License for the specific language governing permissions and limitations under
+% the License.
+
+-module(couch_io_logger).
+
+-export([
+    start/1,
+    log_output/1,
+    log_input/1,
+    stop_noerror/0,
+    stop_error/1
+]).
+
+
+start(undefined) ->
+    ok;
+start(Dir) ->
+    case filelib:is_dir(Dir) of
+        true ->
+            Name = log_name(),
+            Path = Dir ++ "/" ++ Name,
+            OPath = Path ++ ".out.log_",
+            IPath = Path ++ ".in.log_",
+            {ok, OFd} = file:open(OPath, [read, write, raw]),
+            {ok, IFd} = file:open(IPath, [read, write, raw]),
+            ok = file:delete(OPath),
+            ok = file:delete(IPath),
+            put(logger_path, Path),
+            put(logger_out_fd, OFd),
+            put(logger_in_fd, IFd),
+            ok;
+        false ->
+            ok
+    end.
+
+
+stop_noerror() ->
+    case get(logger_path) of
+        undefined ->
+            ok;
+        _Path ->
+            close_logs()
+    end.
+
+
+stop_error(Err) ->
+    case get(logger_path) of
+        undefined ->
+            ok;
+        Path ->
+            save_error_logs(Path, Err),
+            close_logs()
+    end.
+
+
+log_output(Data) ->
+    log(get(logger_out_fd), Data).
+
+
+log_input(Data) ->
+    log(get(logger_in_fd), Data).
+
+
+unix_time() ->
+    {Mega, Sec, USec} = os:timestamp(),
+    UnixTs = (Mega * 1000000 + Sec) * 1000000 + USec,
+    integer_to_list(UnixTs).
+
+
+log_name() ->
+    Ts = unix_time(),
+    Pid0 = erlang:pid_to_list(self()),
+    Pid1 = string:strip(Pid0, left, $<),
+    Pid2 = string:strip(Pid1, right, $>),
+    lists:flatten(io_lib:format("~s_~s", [Ts, Pid2])).
+
+
+close_logs() ->
+    file:close(get(logger_out_fd)),
+    file:close(get(logger_in_fd)).
+
+
+save_error_logs(Path, Err) ->
+    Otp = erlang:system_info(otp_release),
+    Msg = io_lib:format("Error: ~p~nNode: ~p~nOTP: ~p~n", [Err, node(), Otp]),
+    file:write_file(Path ++ ".meta", Msg),
+    IFd = get(logger_out_fd),
+    OFd = get(logger_in_fd),
+    file:position(IFd, 0),
+    file:position(OFd, 0),
+    file:copy(IFd, Path ++  ".out.log"),
+    file:copy(OFd, Path ++ ".in.log").
+
+
+log(undefined, _Data) ->
+    ok;
+log(Fd, Data) ->
+    ok = file:write(Fd, [Data, io_lib:nl()]).
diff --git a/src/couch/src/couch_os_process.erl b/src/couch/src/couch_os_process.erl
index 58522332d..fb1f1427f 100644
--- a/src/couch/src/couch_os_process.erl
+++ b/src/couch/src/couch_os_process.erl
@@ -62,10 +62,14 @@ prompt(Pid, Data) ->
 % Utility functions for reading and writing
 % in custom functions
 writeline(OsProc, Data) when is_record(OsProc, os_proc) ->
-    port_command(OsProc#os_proc.port, [Data, $\n]).
+    Res = port_command(OsProc#os_proc.port, [Data, $\n]),
+    couch_io_logger:log_output(Data),
+    Res.
 
 readline(#os_proc{} = OsProc) ->
-    readline(OsProc, []).
+    Res = readline(OsProc, []),
+    couch_io_logger:log_input(Res),
+    Res.
 readline(#os_proc{port = Port} = OsProc, Acc) ->
     receive
     {Port, {data, {noeol, Data}}} when is_binary(Acc) ->
@@ -145,6 +149,7 @@ pick_command1(_) ->
 
 % gen_server API
 init([Command, Options, PortOptions]) ->
+    couch_io_logger:start(os:getenv("COUCHDB_IO_LOG_DIR")),
     PrivDir = couch_util:priv_dir(),
     Spawnkiller = "\"" ++ filename:join(PrivDir, "couchspawnkillable") ++ "\"",
     V = config:get("query_server_config", "os_process_idle_limit", "300"),
@@ -178,8 +183,14 @@ init([Command, Options, PortOptions]) ->
     end, BaseProc, Options),
     {ok, OsProc, IdleLimit}.
 
-terminate(_Reason, #os_proc{port=Port}) ->
+terminate(Reason, #os_proc{port=Port}) ->
     catch port_close(Port),
+    case Reason of
+        normal ->
+            couch_io_logger:stop_noerror();
+        Error ->
+            couch_io_logger:stop_error(Error)
+    end,
     ok.
 
 handle_call({set_timeout, TimeOut}, _From, #os_proc{idle=Idle}=OsProc) ->