1%%
2%% %CopyrightBegin%
3%%
4%% Copyright Ericsson AB 2017-2020. All Rights Reserved.
5%%
6%% Licensed under the Apache License, Version 2.0 (the "License");
7%% you may not use this file except in compliance with the License.
8%% You may obtain a copy of the License at
9%%
10%%     http://www.apache.org/licenses/LICENSE-2.0
11%%
12%% Unless required by applicable law or agreed to in writing, software
13%% distributed under the License is distributed on an "AS IS" BASIS,
14%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15%% See the License for the specific language governing permissions and
16%% limitations under the License.
17%%
18%% %CopyrightEnd%
19%%
20-module(logger_simple_h).
21
22-export([adding_handler/1, removing_handler/1, log/2]).
23
24%% This module implements a simple handler for logger. It is the
25%% default used during system start.
26
27%%%-----------------------------------------------------------------
28%%% Logger callback
29
30adding_handler(#{id:=simple}=Config) ->
31    Me = self(),
32    case whereis(?MODULE) of
33        undefined ->
34            {Pid,Ref} = spawn_opt(fun() -> init(Me) end,
35                                  [link,monitor,{message_queue_data,off_heap}]),
36            receive
37                {'DOWN',Ref,process,Pid,Reason} ->
38                    {error,Reason};
39                {Pid,started} ->
40                    erlang:demonitor(Ref),
41                    {ok,Config}
42            end;
43        _ ->
44            {error,{handler_process_name_already_exists,?MODULE}}
45    end.
46
47removing_handler(#{id:=simple}) ->
48    case whereis(?MODULE) of
49        undefined ->
50            ok;
51        Pid ->
52            Ref = erlang:monitor(process,Pid),
53            Pid ! stop,
54            receive {'DOWN',Ref,process,Pid,_} ->
55                    ok
56            end
57    end.
58
59log(#{meta:=#{error_logger:=#{tag:=info_report,type:=Type}}},_Config)
60  when Type=/=std_info ->
61    %% Skip info reports that are not 'std_info' (ref simple logger in
62    %% error_logger)
63    ok;
64log(#{msg:=_,meta:=#{time:=_}=M}=Log,_Config) ->
65    _ = case whereis(?MODULE) of
66            undefined ->
67                %% Is the node on the way down? Real emergency?
68                %% Log directly from client just to get it out
69                case maps:get(internal_log_event, M, false) of
70                    false ->
71                        do_log(
72                          #{level=>error,
73                            msg=>{report,{error,simple_handler_process_dead}},
74                            meta=>#{time=>logger:timestamp()}});
75                    true ->
76                        ok
77                end,
78                do_log(Log);
79            _ ->
80                ?MODULE ! {log,Log}
81        end,
82    ok;
83log(_,_) ->
84    %% Unexpected log.
85    %% We don't want to crash the simple logger, so ignore this.
86    ok.
87
88%%%-----------------------------------------------------------------
89%%% Process
90init(Starter) ->
91    register(?MODULE,self()),
92    Starter ! {self(),started},
93    loop(#{buffer_size=>10,dropped=>0,buffer=>[]}).
94
95loop(Buffer) ->
96    receive
97        stop ->
98            %% We replay the logger messages if there is
99            %% a default handler when the simple handler
100            %% is removed.
101            case logger:get_handler_config(default) of
102                {ok, _} ->
103                    replay_buffer(Buffer);
104                _ ->
105                    ok
106            end,
107            %% Before stopping, we unlink the logger process to avoid
108            %% an unexpected EXIT message
109            unlink(whereis(logger)),
110            ok;
111        {log,#{msg:=_,meta:=#{time:=_}}=Log} ->
112            do_log(Log),
113            loop(update_buffer(Buffer,Log));
114        _ ->
115            %% Unexpected message - flush it!
116            loop(Buffer)
117    end.
118
119update_buffer(#{buffer_size:=0,dropped:=D}=Buffer,_Log) ->
120    Buffer#{dropped=>D+1};
121update_buffer(#{buffer_size:=S,buffer:=B}=Buffer,Log) ->
122    Buffer#{buffer_size=>S-1,buffer=>[Log|B]}.
123
124replay_buffer(#{ dropped := D, buffer := Buffer }) ->
125    lists:foreach(
126      fun F(#{msg := {Tag, Msg}} = L) when Tag =:= string; Tag =:= report ->
127              F(L#{ msg := Msg });
128          F(#{ level := Level, msg := Msg, meta := MD}) ->
129              logger:log(Level, Msg, MD)
130      end, lists:reverse(Buffer, drop_msg(D))).
131
132drop_msg(0) ->
133    [];
134drop_msg(N) ->
135    [#{level=>info,
136       msg=>{"Simple handler buffer full, dropped ~w messages",[N]},
137       meta=>#{time=>logger:timestamp()}}].
138
139%%%-----------------------------------------------------------------
140%%% Internal
141
142do_log(Log) ->
143    try
144        Str = logger_formatter:format(Log,
145                 #{ legacy_header => true, single_line => false
146                   ,depth => unlimited, time_offset => ""
147                 }),
148        erlang:display_string(lists:flatten(unicode:characters_to_list(Str)))
149    catch _E:_R:_ST ->
150        % erlang:display({_E,_R,_ST}),
151        display_log(Log)
152    end.
153
154display_log(#{msg:={report,Report},
155         meta:=#{time:=T,error_logger:=#{type:=Type}}}) ->
156    display_date(T),
157    display_report(Type,Report);
158display_log(#{msg:=Msg,meta:=#{time:=T}}) ->
159    display_date(T),
160    display(Msg).
161
162display_date(Timestamp) when is_integer(Timestamp) ->
163    Micro = Timestamp rem 1000000,
164    Sec = Timestamp div 1000000,
165    {{Y,Mo,D},{H,Mi,S}} = erlang:universaltime_to_localtime(
166                            erlang:posixtime_to_universaltime(Sec)),
167    erlang:display_string(
168      integer_to_list(Y) ++ "-" ++
169	  pad(Mo,2) ++ "-" ++
170	  pad(D,2)  ++ " " ++
171	  pad(H,2)  ++ ":" ++
172	  pad(Mi,2) ++ ":" ++
173	  pad(S,2)  ++ "." ++
174          pad(Micro,6) ++ " ").
175
176pad(Int,Size) when is_integer(Int) ->
177    pad(integer_to_list(Int),Size);
178pad(Str,Size) when length(Str)==Size ->
179    Str;
180pad(Str,Size) ->
181    pad([$0|Str],Size).
182
183display({string,Chardata}) ->
184    try unicode:characters_to_list(Chardata) of
185        String -> erlang:display_string(String), erlang:display_string("\n")
186    catch _:_ -> erlang:display(Chardata)
187    end;
188display({report,Report}) when is_map(Report) ->
189    display_report(maps:to_list(Report));
190display({report,Report}) ->
191    display_report(Report);
192display({F, A}) when is_list(F), is_list(A) ->
193    erlang:display_string(F ++ "\n"),
194    [begin
195	 erlang:display_string("\t"),
196	 erlang:display(Arg)
197     end || Arg <- A],
198    ok.
199
200display_report(Atom, A) when is_atom(Atom) ->
201    %% The widest atom seems to be 'supervisor_report' at 17.
202    ColumnWidth = 20,
203    AtomString = atom_to_list(Atom),
204    AtomLength = length(AtomString),
205    Padding = lists:duplicate(ColumnWidth - AtomLength, $\s),
206    erlang:display_string(AtomString ++ Padding),
207    display_report(A);
208display_report(F, A) ->
209    erlang:display({F, A}).
210
211display_report(#{ report := Report }) ->
212    display_report(Report);
213display_report([A, []]) ->
214    %% Special case for crash reports when process has no links
215    display_report(A);
216display_report(A = [_|_]) ->
217    case lists:all(fun({Key,_Value}) -> is_atom(Key); (_) -> false end, A) of
218	true ->
219	    erlang:display_string("\n"),
220	    lists:foreach(
221	      fun({Key, Value}) ->
222		      erlang:display_string(
223			"    " ++
224			    atom_to_list(Key) ++
225			    ": "),
226		      erlang:display(Value)
227	      end, A);
228	false ->
229	    erlang:display(A)
230    end;
231display_report(A) ->
232    erlang:display(A).
233