Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

Disable console backend if oldshell is used #139

Merged
merged 2 commits into from

3 participants

@Vagabond
Collaborator

This is a redux of #138 with some changes of my own.

@slfritchie slfritchie Disable I/O to the console if the old-style Erlang console is used
There's a nasty problem with the Erlang VM + lager when the old-style
Erlang console is used.  You can use the "-oldshell" flag to explicitly
get the old-style shell.  However, if the Erlang VM is started when
*not* associated with a pseudo-tty, the VM will silently use the
old-style shell (because the new-style shell requires a pty to
support command line editing, etc.).  The most common way of starting
the Erlang VM without a pty is to start it via a non-interactive
SSH session.

This patch is opinionated in what to do in the case when the old-
style shell is detected.  My opinion is:

1. Shout loudly to the console log (in a separate Erlang process, so
   that the main lager event handler proc won't be blocked by any
   problems with the old-style console).  It's almost certainly
   likely that you really don't want to run Erlang with the old-style
   shell.  But many sysadmins don't look closely at their systems'
   log files, so (for example) shouting the same message 10x in a row
   is legit.  Reviewers: YMMV.
2. Set a SASL alarm.  Again, many sysadmins' are bad at looking at
   log messages.  Setting a SASL alarm is another method to try to
   get their attention.

To test, create a test script called `/tmp/testit.sh`, changing the
`-pz` parameter to point to the correct place for lager's `ebin`
subdirectory:

    #!/bin/sh

    erl -pz /Users/fritchie/b/src/lager/ebin -eval '{application:start(sasl), lager_console_backend:init([error, true]), timer:sleep(5*1000), io:format("\n\nInfo: ~p\n\n", [{{alarms, alarm_handler:get_alarms()}, {user_drv, whereis(user_drv)}}]), erlang:halt()}.'

Then run it twice, using the following:

    First time: ssh -t localhost sh /tmp/testit.sh
    Second time: ssh localhost sh /tmp/testit.sh

The last lines of the first time should look like:

    Info: {{alarms,[]},{user_drv,<0.22.0>}}

The last lines of the second time should look like:

    Info: {{alarms,
               [{lager_console_backend,
                    "WARNING: old-style console is in use, so lager_console_backend log output to the console is disabled.  Restart the VM on a pseudo-tty to ensure use of the new-style VM console."}]},
           {user_drv,undefined}}
1ea378a
@slfritchie
Owner

Looks good, +1, and feel free to close my PR in favor of this one.

@Vagabond Vagabond Rework the 'old shell' warning, and some related work
Add ability for handlers to 'fatally' fail, so they won't attempt to
reinstall themselves later.

Also fix an issue with the INT_LOG macro not doing the right thing when
only the lager_throttle_backend was installed.
ccdc4d4
@Vagabond Vagabond merged commit e58a33d into from
@Vagabond Vagabond deleted the branch
@maxlapshin

What for is it done? This patch breaks logging via capturing stdout.

@stupakov stupakov referenced this pull request from a commit in cloudfoundry/cf-riak-cs-release
@stupakov stupakov Remove faulty lager_console_backend logging handler
- it does not work with our version of erlang (see basho/lager#139)
- the remaining lager_file_backends route all logging to files
[#64946316]
163af97
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Commits on Apr 24, 2013
  1. @slfritchie @Vagabond

    Disable I/O to the console if the old-style Erlang console is used

    slfritchie authored Vagabond committed
    There's a nasty problem with the Erlang VM + lager when the old-style
    Erlang console is used.  You can use the "-oldshell" flag to explicitly
    get the old-style shell.  However, if the Erlang VM is started when
    *not* associated with a pseudo-tty, the VM will silently use the
    old-style shell (because the new-style shell requires a pty to
    support command line editing, etc.).  The most common way of starting
    the Erlang VM without a pty is to start it via a non-interactive
    SSH session.
    
    This patch is opinionated in what to do in the case when the old-
    style shell is detected.  My opinion is:
    
    1. Shout loudly to the console log (in a separate Erlang process, so
       that the main lager event handler proc won't be blocked by any
       problems with the old-style console).  It's almost certainly
       likely that you really don't want to run Erlang with the old-style
       shell.  But many sysadmins don't look closely at their systems'
       log files, so (for example) shouting the same message 10x in a row
       is legit.  Reviewers: YMMV.
    2. Set a SASL alarm.  Again, many sysadmins' are bad at looking at
       log messages.  Setting a SASL alarm is another method to try to
       get their attention.
    
    To test, create a test script called `/tmp/testit.sh`, changing the
    `-pz` parameter to point to the correct place for lager's `ebin`
    subdirectory:
    
        #!/bin/sh
    
        erl -pz /Users/fritchie/b/src/lager/ebin -eval '{application:start(sasl), lager_console_backend:init([error, true]), timer:sleep(5*1000), io:format("\n\nInfo: ~p\n\n", [{{alarms, alarm_handler:get_alarms()}, {user_drv, whereis(user_drv)}}]), erlang:halt()}.'
    
    Then run it twice, using the following:
    
        First time: ssh -t localhost sh /tmp/testit.sh
        Second time: ssh localhost sh /tmp/testit.sh
    
    The last lines of the first time should look like:
    
        Info: {{alarms,[]},{user_drv,<0.22.0>}}
    
    The last lines of the second time should look like:
    
        Info: {{alarms,
                   [{lager_console_backend,
                        "WARNING: old-style console is in use, so lager_console_backend log output to the console is disabled.  Restart the VM on a pseudo-tty to ensure use of the new-style VM console."}]},
               {user_drv,undefined}}
  2. @Vagabond

    Rework the 'old shell' warning, and some related work

    Vagabond authored
    Add ability for handlers to 'fatally' fail, so they won't attempt to
    reinstall themselves later.
    
    Also fix an issue with the INT_LOG macro not doing the right thing when
    only the lager_throttle_backend was installed.
This page is out of date. Refresh to see the latest.
View
2  include/lager.hrl
@@ -84,7 +84,7 @@
%% from a gen_event handler
spawn(fun() ->
case catch(gen_event:which_handlers(lager_event)) of
- X when X == []; X == {'EXIT', noproc} ->
+ X when X == []; X == {'EXIT', noproc}; X == [lager_backend_throttle] ->
%% there's no handlers yet or lager isn't running, try again
%% in half a second.
timer:sleep(500),
View
35 src/lager_console_backend.erl
@@ -47,15 +47,27 @@ init([Level,{Formatter,FormatterConfig}]) when is_atom(Formatter) ->
_ -> []
end,
- try lager_util:config_to_mask(Level) of
- Levels ->
+ try {is_new_style_console_available(), lager_util:config_to_mask(Level)} of
+ {false, _} ->
+ Msg = "Lager's console backend is incompatible with the 'old' shell, not enabling it",
+ %% be as noisy as possible, log to every possible place
+ try
+ alarm_handler:set_alarm({?MODULE, "WARNING: " ++ Msg})
+ catch
+ _:_ ->
+ error_logger:warning_msg(Msg ++ "~n")
+ end,
+ io:format("WARNING: " ++ Msg ++ "~n"),
+ ?INT_LOG(warning, Msg, []),
+ {error, {fatal, old_shell}};
+ {true, Levels} ->
{ok, #state{level=Levels,
formatter=Formatter,
format_config=FormatterConfig,
colors=Colors}}
catch
_:_ ->
- {error, bad_log_level}
+ {error, {fatal, bad_log_level}}
end;
init(Level) ->
init([Level,{lager_default_formatter,?TERSE_FORMAT ++ [eol()]}]).
@@ -109,6 +121,23 @@ eol() ->
end.
-ifdef(TEST).
+is_new_style_console_available() ->
+ true.
+-else.
+is_new_style_console_available() ->
+ %% Criteria:
+ %% 1. If the user has specified '-noshell' on the command line,
+ %% then we will pretend that the new-style console is available.
+ %% If there is no shell at all, then we don't have to worry
+ %% about log events being blocked by the old-style shell.
+ %% 2. If the user_drv process iss registered, all is OK.
+ %% 'user_drv' is a registered proc name used by the "new"
+ %% console driver.
+ init:get_argument(noshell) /= error orelse
+ is_pid(whereis(user_drv)).
+-endif.
+
+-ifdef(TEST).
console_log_test_() ->
%% tiny recursive fun that pretends to be a group leader
F = fun(Self) ->
View
2  src/lager_file_backend.erl
@@ -99,7 +99,7 @@ init(LogFileConfig) when is_list(LogFileConfig) ->
case validate_logfile_proplist(LogFileConfig) of
false ->
%% falied to validate config
- {error, bad_config};
+ {error, {fatal, bad_config}};
Config ->
%% probabably a better way to do this, but whatever
[Name, Level, Date, Size, Count, SyncInterval, SyncSize, SyncOn, CheckInterval, Formatter, FormatterConfig] =
View
22 src/lager_handler_watcher.erl
@@ -23,6 +23,8 @@
-behaviour(gen_server).
+-include("lager.hrl").
+
-ifdef(TEST).
-include_lib("eunit/include/eunit.hrl").
-endif.
@@ -73,6 +75,8 @@ handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module,
handle_info(reinstall_handler, #state{module=Module, config=Config, event=Event} = State) ->
install_handler(Event, Module, Config),
{noreply, State};
+handle_info(stop, State) ->
+ {stop, normal, State};
handle_info(_Info, State) ->
{noreply, State}.
@@ -87,12 +91,18 @@ code_change(_OldVsn, State, _Extra) ->
install_handler(Event, Module, Config) ->
case gen_event:add_sup_handler(Event, Module, Config) of
ok ->
- _ = lager:log(debug, self(), "Lager installed handler ~p into ~p", [Module, Event]),
+ ?INT_LOG(debug, "Lager installed handler ~p into ~p", [Module, Event]),
lager:update_loglevel_config(),
ok;
+ {error, {fatal, Reason}} ->
+ ?INT_LOG(error, "Lager fatally failed to install handler ~p into"
+ " ~p, NOT retrying: ~p", [Module, Event, Reason]),
+ %% tell ourselves to stop
+ self() ! stop,
+ ok;
Error ->
%% try to reinstall it later
- _ = lager:log(error, self(), "Lager failed to install handler ~p into"
+ ?INT_LOG(error, "Lager failed to install handler ~p into"
" ~p, retrying later : ~p", [Module, Event, Error]),
erlang:send_after(5000, self(), reinstall_handler),
ok
@@ -145,10 +155,10 @@ reinstall_on_runtime_failure_test_() ->
?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))),
timer:sleep(6000),
?assertEqual(2, lager_test_backend:count()),
- {_Level, _Time, Message, _Metadata} = lager_test_backend:pop(),
- ?assertEqual("Lager event handler lager_crash_backend exited with reason crash", lists:flatten(Message)),
- {_Level2, _Time2, Message2, _Metadata} = lager_test_backend:pop(),
- ?assertMatch("Lager failed to install handler lager_crash_backend into lager_event, retrying later :"++_, lists:flatten(Message2)),
+ {_Severity, _Date, Msg, _Metadata} = lager_test_backend:pop(),
+ ?assertEqual("Lager event handler lager_crash_backend exited with reason crash", lists:flatten(Msg)),
+ {_Severity2, _Date2, Msg2, _Metadata2} = lager_test_backend:pop(),
+ ?assertMatch("Lager failed to install handler lager_crash_backend into lager_event, retrying later :"++_, lists:flatten(Msg2)),
?assertEqual(false, lists:member(lager_crash_backend, gen_event:which_handlers(lager_event)))
after
application:stop(lager),
View
2  src/lager_handler_watcher_sup.erl
@@ -35,5 +35,5 @@ init([]) ->
{ok, {{simple_one_for_one, 10, 60},
[
{lager_handler_watcher, {lager_handler_watcher, start_link, []},
- transient, 5000, worker, [lager_handler_watcher]}
+ temporary, 5000, worker, [lager_handler_watcher]}
]}}.
Something went wrong with that request. Please try again.