From b91eceaf71e0009346d119346a33894ed53be7b0 Mon Sep 17 00:00:00 2001
From: Peter Andersson <peppe@erlang.org>
Date: Thu, 7 Jun 2018 10:59:04 +0200
Subject: [logger] Implement logging of handler overload status

Conflicts:
	lib/kernel/src/logger_disk_log_h.erl
	lib/kernel/src/logger_std_h.erl
---
 lib/kernel/test/logger_std_h_SUITE.erl | 47 +++++++++++++++++++++-------------
 1 file changed, 29 insertions(+), 18 deletions(-)

(limited to 'lib/kernel/test/logger_std_h_SUITE.erl')

diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index fd1840b9ff..a67b55eee1 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -707,7 +707,7 @@ op_switch_to_sync_file(Config) ->
     %%    TRecvPid = start_op_trace(),
     send_burst({n,NumOfReqs}, seq, {chars,79}, info),
     Lines = count_lines(Log),
-    ok = file:delete(Log),
+    ok = file_delete(Log),
     %% true = analyse_trace(TRecvPid,
     %%                      fun(Events) -> find_mode(async,Events) end),
     %% true = analyse_trace(TRecvPid,
@@ -764,7 +764,7 @@ op_switch_to_drop_file(Config) ->
                     _ <- lists:seq(1, Bursts)],
                 Logged = count_lines(Log),
                 ok = stop_handler(?MODULE),
-                _ = file:delete(Log),
+                _ = file_delete(Log),
                 ct:pal("Number of messages dropped = ~w (~w)",
                        [Procs*NumOfReqs*Bursts-Logged,Procs*NumOfReqs*Bursts]),
                 true = (Logged < (Procs*NumOfReqs*Bursts)),
@@ -799,7 +799,7 @@ op_switch_to_drop_tty(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
 op_switch_to_flush_file() ->
-    [{timetrap,{minutes,3}}].
+    [{timetrap,{minutes,5}}].
 op_switch_to_flush_file(Config) ->
     Test =
         fun() ->
@@ -832,7 +832,7 @@ op_switch_to_flush_file(Config) ->
                     _ <- lists:seq(1,Bursts)],
                 Logged = count_lines(Log),
                 ok = stop_handler(?MODULE),
-                _ = file:delete(Log),
+                _ = file_delete(Log),
                 ct:pal("Number of messages flushed/dropped = ~w (~w)",
                        [NumOfReqs*Procs*Bursts-Logged,NumOfReqs*Procs*Bursts]),
                 true = (Logged < (NumOfReqs*Procs*Bursts)),
@@ -850,6 +850,8 @@ op_switch_to_flush_file(Config) ->
 op_switch_to_flush_file(cleanup, _Config) ->
     _ = stop_handler(?MODULE).
 
+op_switch_to_flush_tty() ->
+    [{timetrap,{minutes,5}}].
 op_switch_to_flush_tty(Config) ->
     {HConfig,StdHConfig} = start_handler(?MODULE, standard_io, Config),
 
@@ -883,7 +885,7 @@ limit_burst_disabled(Config) ->
     send_burst({n,NumOfReqs}, seq, {chars,79}, info),
     Logged = count_lines(Log),
     ct:pal("Number of messages logged = ~w", [Logged]),
-    ok = file:delete(Log),
+    ok = file_delete(Log),
     NumOfReqs = Logged.
 limit_burst_disabled(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
@@ -902,7 +904,7 @@ limit_burst_enabled_one(Config) ->
     send_burst({n,NumOfReqs}, seq, {chars,79}, info),
     Logged = count_lines(Log),
     ct:pal("Number of messages logged = ~w", [Logged]),
-    ok = file:delete(Log),
+    ok = file_delete(Log),
     ReqLimit = Logged.
 limit_burst_enabled_one(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
@@ -924,7 +926,7 @@ limit_burst_enabled_period(Config) ->
     Logged = count_lines(Log),
     ct:pal("Number of messages sent = ~w~nNumber of messages logged = ~w",
            [Sent,Logged]),
-    ok = file:delete(Log),
+    ok = file_delete(Log),
     true = (Logged > (ReqLimit*Windows)) andalso
            (Logged < (ReqLimit*(Windows+2))).
 limit_burst_enabled_period(cleanup, _Config) ->
@@ -941,7 +943,7 @@ kill_disabled(Config) ->
     send_burst({n,NumOfReqs}, seq, {chars,79}, info),
     Logged = count_lines(Log),
     ct:pal("Number of messages logged = ~w", [Logged]),
-    ok = file:delete(Log),
+    ok = file_delete(Log),
     true = is_pid(whereis(h_proc_name())),
     ok.
 kill_disabled(cleanup, _Config) ->
@@ -1117,7 +1119,7 @@ handler_requests_under_load(Config) ->
     Errors = [{Req,FindError(Res)} || {Req,Res} <- ReqResult],
     NoOfReqs = lists:foldl(fun({_,Res}, N) -> N + length(Res) end, 0, ReqResult),
     ct:pal("~w requests made. Errors: ~n~p", [NoOfReqs,Errors]),
-    ok = file:delete(Log).
+    ok = file_delete(Log).
 handler_requests_under_load(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
@@ -1192,17 +1194,21 @@ wait_until_written(File, Sz) ->
     end.
     
 count_lines1(File) ->
-    Counter = fun Cnt(Dev,LC) ->
-                      case file:read_line(Dev) of
-                          eof -> LC;
-                          _   -> Cnt(Dev,LC+1)
-                      end
-              end,
     {_,Dev} = file:open(File, [read]),
-    Lines = Counter(Dev, 0),
+    Lines = count_lines2(Dev, 0),
     file:close(Dev),
     Lines.
 
+count_lines2(Dev, LC) ->
+    case file:read_line(Dev) of
+        {ok,"Handler logger_std_h_SUITE " ++_} ->
+            %% Not counting handler info
+            count_lines2(Dev,LC);
+        {ok,_} ->
+            count_lines2(Dev,LC+1);
+        eof -> LC
+    end.
+
 send_burst(NorT, Type, {chars,Sz}, Class) ->
     Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,Sz)],
     case NorT of
@@ -1271,9 +1277,11 @@ format(#{msg:={report,#{label:={gen_server,terminate}}}},op) ->
     "";
 format(#{msg:={report,#{label:={proc_lib,crash}}}},op) ->
     "";
-format(#{msg:={F,A}},Pid) when is_list(F), is_list(A) ->
+format(#{msg:={F,A}},OpOrPid) when is_list(F), is_list(A) ->
     String = lists:flatten(io_lib:format(F,A)),
-    Pid ! {log,String},
+    if is_pid(OpOrPid) -> OpOrPid ! {log,String};
+       true -> ok
+    end,
     String++"\n";
 format(#{msg:={string,String0}},Pid) ->
     String = unicode:characters_to_list(String0),
@@ -1530,3 +1538,6 @@ h_proc_name() ->
     h_proc_name(?MODULE).
 h_proc_name(Name) ->
     ?name_to_reg_name(logger_std_h,Name).
+
+file_delete(Log) ->
+   file:delete(Log).
-- 
cgit v1.2.3