You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@couchdb.apache.org by va...@apache.org on 2024/06/21 18:48:35 UTC
(couchdb) branch main updated: Remove couch_io_logger
This is an automated email from the ASF dual-hosted git repository.
vatamane pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/couchdb.git
The following commit(s) were added to refs/heads/main by this push:
new 39721bd44 Remove couch_io_logger
39721bd44 is described below
commit 39721bd443132982046a4a3ac9c9ed379c957451
Author: Nick Vatamaniuc <va...@gmail.com>
AuthorDate: Fri Jun 21 13:40:13 2024 -0400
Remove couch_io_logger
Replace it with a simpler logging based scheme.
Previously, `couch_io_logger` would log to a directory provided via an
environment variable. However since it was introduced, we hadn't used it that
much. Debugging a few recent couchjs issue it was useful just to be able to log
the commands, so simplified the IO logging to just dump commands to the logs.
To make it easier to filter out just "OS Process" log lines, make the log line
a bit more uniform so they have the general form "OS Process ~p $type ::
$extra...". Staying with an environment variable pattern, made that pass in a
log level.
So it's possible to do:
```
make && COUCHDB_IO_LOG_LEVEL=warning make eunit apps=couch_quickjs
suites=couch_quickjs_scanner_plugin_tests
```
And then logs would show:
```
[warning] 2024-06-21T04:33:57.825302Z nonode@nohost <0.2204.0> -------- OS Process #Port<0.40> Started :: "couchjs_mainjs"
[warning] 2024-06-21T04:33:57.825408Z nonode@nohost <0.2204.0> -------- OS Process #Port<0.40> Input :: ["reset",{"reduce_limit":false,"timeout":5000}]
[warning] 2024-06-21T04:33:57.834957Z nonode@nohost <0.2204.0> -------- OS Process #Port<0.40> Output :: true
[warning] 2024-06-21T04:33:57.866028Z nonode@nohost <0.2206.0> -------- OS Process #Port<0.41> Started :: "couchjs"
[warning] 2024-06-21T04:33:57.866110Z nonode@nohost <0.2206.0> -------- OS Process #Port<0.41> Input :: ["reset",{"reduce_limit":false,"timeout":5000}]
[warning] 2024-06-21T04:33:57.914930Z nonode@nohost <0.2206.0> -------- OS Process #Port<0.41> Output :: true
[warning] 2024-06-21T04:33:57.915036Z nonode@nohost <0.2206.0> -------- OS
Process #Port<0.41> Input :: ["add_fun","function(doc, req) {\n if(doc.a ==
'z') {\n doc.a.search(/(z+)/);\n if(RegExp.$1 == 'z') {return true} else
{return false};\n } else {\n return true;\n }\n}"]
```
---
src/couch/src/couch_io_logger.erl | 97 --------------------------------------
src/couch/src/couch_os_process.erl | 46 +++++++++++-------
2 files changed, 30 insertions(+), 113 deletions(-)
diff --git a/src/couch/src/couch_io_logger.erl b/src/couch/src/couch_io_logger.erl
deleted file mode 100644
index f859874b6..000000000
--- a/src/couch/src/couch_io_logger.erl
+++ /dev/null
@@ -1,97 +0,0 @@
-% 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 afd7e09a5..225ce3d53 100644
--- a/src/couch/src/couch_os_process.erl
+++ b/src/couch/src/couch_os_process.erl
@@ -25,7 +25,8 @@
command,
port,
timeout = 5000,
- idle
+ idle,
+ log_level
}).
start_link(Command) ->
@@ -52,7 +53,6 @@ prompt(Pid, Data) ->
readline(#os_proc{} = OsProc) ->
Res = readline(OsProc, []),
- couch_io_logger:log_input(Res),
Res.
readline(#os_proc{port = Port} = OsProc, Acc) ->
receive
@@ -73,12 +73,13 @@ readline(#os_proc{port = Port} = OsProc, Acc) ->
throw({os_process_error, Err})
after OsProc#os_proc.timeout ->
catch port_close(Port),
+ log(OsProc, "OS Process ~p Timed out :: ~p msec", [Port, OsProc#os_proc.timeout]),
throw({os_process_error, "OS process timed out."})
end.
readjson(OsProc) when is_record(OsProc, os_proc) ->
Line = iolist_to_binary(readline(OsProc)),
- couch_log:debug("OS Process ~p Output :: ~s", [OsProc#os_proc.port, Line]),
+ log(OsProc, "OS Process ~p Output :: ~s", [OsProc#os_proc.port, Line]),
try
% Don't actually parse the whole JSON. Just try to see if it's
% a command or a doc map/reduce/filter/show/list/update output.
@@ -129,23 +130,26 @@ pick_command1(_) ->
% gen_server API
init([Command]) ->
- 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"),
IdleLimit = list_to_integer(V) * 1000,
+ LogLevel = log_level(os:getenv("COUCHDB_IO_LOG_LEVEL")),
T0 = erlang:monotonic_time(),
OsProc = #os_proc{
command = Command,
port = open_port({spawn, Spawnkiller ++ " " ++ Command}, ?PORT_OPTIONS),
- idle = IdleLimit
+ idle = IdleLimit,
+ log_level = LogLevel
},
KillCmd = iolist_to_binary(readline(OsProc)),
T1 = erlang:monotonic_time(),
DtUSec = erlang:convert_time_unit(T1 - T0, native, microsecond),
bump_time_stat(spawn_proc, DtUSec),
Pid = self(),
- couch_log:debug("OS Process Start :: ~p", [OsProc#os_proc.port]),
+ [CmdLog | _] = string:split(Command, " "),
+ CmdLog1 = filename:basename(CmdLog),
+ log(OsProc, "OS Process ~p Started :: ~p", [OsProc#os_proc.port, CmdLog1]),
couch_stats:increment_counter([couchdb, query_server, process_starts]),
spawn(fun() ->
% this ensure the real os process is killed when this process dies.
@@ -154,14 +158,9 @@ init([Command]) ->
end),
{ok, OsProc, IdleLimit}.
-terminate(Reason, #os_proc{port = Port}) ->
+terminate(Reason, #os_proc{port = Port} = OsProc) ->
catch port_close(Port),
- case Reason of
- normal ->
- couch_io_logger:stop_noerror();
- Error ->
- couch_io_logger:stop_error(Error)
- end,
+ log(OsProc, "OS Process ~p Terminated :: ~p", [Port, Reason]),
ok.
handle_call({set_timeout, TimeOut}, _From, #os_proc{idle = Idle} = OsProc) ->
@@ -170,8 +169,7 @@ handle_call({prompt, Data}, _From, #os_proc{idle = Idle} = OsProc) ->
try
couch_stats:increment_counter([couchdb, query_server, process_prompts]),
JsonData = ?JSON_ENCODE(Data),
- couch_log:debug("OS Process ~p Input :: ~s", [OsProc#os_proc.port, JsonData]),
- couch_io_logger:log_output(JsonData),
+ log(OsProc, "OS Process ~p Input :: ~s", [OsProc#os_proc.port, JsonData]),
T0 = erlang:monotonic_time(),
true = port_command(OsProc#os_proc.port, [JsonData, $\n]),
Response = readjson(OsProc),
@@ -215,7 +213,7 @@ handle_info({Port, {exit_status, Status}}, #os_proc{port = Port} = OsProc) ->
couch_stats:increment_counter([couchdb, query_server, process_error_exits]),
{stop, {exit_status, Status}, OsProc};
handle_info(Msg, #os_proc{idle = Idle} = OsProc) ->
- couch_log:debug("OS Proc: Unknown info: ~p", [Msg]),
+ log(OsProc, "OS Process ~p Unknown info :: ~p", [OsProc#os_proc.port, Msg]),
{noreply, OsProc, Idle}.
killer(KillCmd) ->
@@ -253,3 +251,19 @@ bump_cmd_time_stat(Cmd, USec) when is_list(Cmd), is_integer(USec) ->
bump_time_stat(Stat, USec) when is_atom(Stat), is_integer(USec) ->
couch_stats:increment_counter([couchdb, query_server, calls, Stat]),
couch_stats:increment_counter([couchdb, query_server, time, Stat], USec).
+
+log_level("debug") ->
+ debug;
+log_level("info") ->
+ info;
+log_level("notice") ->
+ notice;
+log_level("warning") ->
+ warning;
+log_level("error") ->
+ error;
+log_level(_) ->
+ debug.
+
+log(#os_proc{log_level = LogLevel}, Fmt, Args) ->
+ couch_log:LogLevel(Fmt, Args).