error_logger "deadlock" problem

Question

I added an event handler to redirect error_logger reports to syslog. The handler looks like this:

handle_event({info_msg, _Gleader, {_Pid, Format, Data}}, #state{info_logger=Logger}=State) ->
    syslog_write("I", Logger, Format, Data),
    {ok, State};
handle_event({error, _Gleader, {_Pid, Format, Data}}, #state{error_logger=Logger}=State) ->
    syslog_write("E", Logger, Format, Data),
    {ok, State};
handle_event(_Event, State) ->
    {ok, State}.

syslog_write(Prefix, Facility, Format, Data) ->
    Cmd = try
              Message = lists:flatten(io_lib:format(Format, Data)),
              lists:flatten(io_lib:format("logger -t essmsd -p ~s.Debug \'<~s> ~s\'",
                                           [Facility, Prefix, Message]))
          catch 
              _:_ ->
                  lists:flatten(io_lib:format("logger -t essmsd -p ~s.Debug \'~p\'", 
                                              [Facility, [Prefix, Format, Data]]))
          end,
    os:cmd(Cmd).

I used logger command to write to syslog files. It works at first, but after running for one or two days, the error_logger stopped working. It outputs nothing (when I invoke error_logger:info_msg("test") on the console, it only returns an ok) no matter what the input, neither to the log file, nor to the console.

Any suggestions? thx in advance.

update: I put traces in syslog_write and error_logger:info_msg, and I got the following:

(essmsd@xx.xx.xx.xx)11> dbg:tracer(), dbg:p(all, c), dbg:tpl(error_logger, info_msg, x). {ok,[{matched,'essmsd@xx.xx.xx.xx',2},{saved,x}]} 

(essmsd@xx.xx.xx.xx)12> error_logger:info_msg("xx"). 
ok 
(<0.1735.0>) call error_logger:info_msg("xx") 

(essmsd@xx.xx.xx.xx)13> 
(<0.1735.0>) call error_logger:info_msg("xx",[]) 
(<0.1735.0>) returned from error_logger:info_msg/2 -> ok 
(<0.1735.0>) returned from error_logger:info_msg/1 -> ok

Which means the error_logger:info_msg is being called, but it never output anything but returned an ok!

score 1 · Answer 1 · edited May 23 '17 at 12:04

1

The question is:

Does error_logger stop handling messages or does your syslogd cause problems?

You need to debug it, if you have a system where it already stopped working use:

dbg:tracer(),dbg:p(all,c),dbg:tpl(Mod,Func,x)

For all relevant functions in your module on a shell connected to your node.

For details see How to refine the debugging? and Using trace and dbg in Erlang.

Then you can see what is actually happeing and if your syslog_write function is still called and with what parameters.

BTW what sometimes can be the reason for syslog "problems": when you look at the log file with less or tail and keep it running. Then once the log files get rotated you still have the old file open and it looks like logging just stopped. In reality it is going to a different file.

edited May 23 '17 at 12:04

Community

1
1

answered Apr 12 '11 at 09:45

Peer Stritzinger

8,232
2
30
43

syslog works fine, but error_logger stopped working. I can use error_logger to output to console at first, but after the problem occurred I see not output when I call error_logger:info_msg. Thanks for the reply, I'll go check what's going on. – Chi Zhang Apr 13 '11 at 04:23
to_syslog_handler:syslog_write was not called. – Chi Zhang Apr 16 '11 at 09:33
In fact, if I trace the error_logger, it reults in the following: (essmsd@xx.xx.xx.xx)11> dbg:tracer(), dbg:p(all, c), dbg:tpl(error_logger, info_msg, x). {ok,[{matched,'essmsd@xx.xx.xx.xx',2},{saved,x}]} (essmsd@xx.xx.xx.xx)12> error_logger:info_msg("xx"). ok (<0.1735.0>) call error_logger:info_msg("xx") (essmsd@xx.xx.xx.xx)13> (<0.1735.0>) call error_logger:info_msg("xx",[]) (<0.1735.0>) returned from error_logger:info_msg/2 -> ok (<0.1735.0>) returned from error_logger:info_msg/1 -> ok – Chi Zhang Apr 16 '11 at 09:33
error_logger was called judging from the tracer, but there was not any output! – Chi Zhang Apr 16 '11 at 09:36
Can you edit your question and add the traces. They are a Bit hard to read in the comments. – Peer Stritzinger Apr 16 '11 at 17:12

score 0 · Accepted Answer · answered Apr 18 '11 at 11:03

0

I found the problem: When I have an empty message, I have the logger command running forever!

answered Apr 18 '11 at 11:03

Chi Zhang

771
2
8
22

error_logger "deadlock" problem

2 Answers2