Merge branch 'raimo/ssl/tls_dist-profiling' into maint

* raimo/ssl/tls_dist-profiling:
  Improve benchmark
  Implement print on other node
  Fix compiler warnings

3 files changed, 244 insertions, 39 deletions

diff --git a/lib/ssl/test/ssl_dist_bench_SUITE.erl b/lib/ssl/test/ssl_dist_bench_SUITE.erl
index 3c7904cf24..7409b69639 100644
--- a/lib/ssl/test/ssl_dist_bench_SUITE.erl
+++ b/lib/ssl/test/ssl_dist_bench_SUITE.erl
@@ -32,6 +32,8 @@
 -export(
    [setup/1,
     roundtrip/1,
+    throughput_0/1,
+    throughput_64/1,
     throughput_1024/1,
     throughput_4096/1,
     throughput_16384/1,
@@ -55,7 +57,9 @@ groups() ->
      {setup, [{repeat, 1}], [setup]},
      {roundtrip, [{repeat, 1}], [roundtrip]},
      {throughput, [{repeat, 1}],
-      [throughput_1024,
+      [throughput_0,
+       throughput_64,
+       throughput_1024,
        throughput_4096,
        throughput_16384,
        throughput_65536,
@@ -247,8 +251,9 @@ setup(A, B, Prefix, HA, HB) ->
     [] = ssl_apply(HB, erlang, nodes, []),
     {SetupTime, CycleTime} =
         ssl_apply(HA, fun () -> setup_runner(A, B, Rounds) end),
-    [] = ssl_apply(HA, erlang, nodes, []),
-    [] = ssl_apply(HB, erlang, nodes, []),
+    ok = ssl_apply(HB, fun () -> setup_wait_nodedown(A, 10000) end),
+    %% [] = ssl_apply(HA, erlang, nodes, []),
+    %% [] = ssl_apply(HB, erlang, nodes, []),
     SetupSpeed = round((Rounds*1000000*1000) / SetupTime),
     CycleSpeed = round((Rounds*1000000*1000) / CycleTime),
     _ = report(Prefix++" Setup", SetupSpeed, "setups/1000s"),
@@ -275,6 +280,22 @@ setup_loop(A, B, T, N) ->
             setup_loop(A, B, Time + T, N - 1)
     end.
 
+setup_wait_nodedown(A, Time) ->
+    ok = net_kernel:monitor_nodes(true),
+    case nodes() of
+        [] ->
+            ok;
+        [A] ->
+            receive
+                {nodedown,A} ->
+                    ok;
+                Unexpected ->
+                    {error,{unexpected,Unexpected}}
+            after Time ->
+                    {error,timeout}
+            end
+    end.
+
 
 %%----------------
 %% Roundtrip speed
@@ -334,6 +355,18 @@ roundtrip_client(Pid, Mon, StartTime, N) ->
 %%-----------------
 %% Throughput speed
 
+throughput_0(Config) ->
+    run_nodepair_test(
+      fun (A, B, Prefix, HA, HB) ->
+              throughput(A, B, Prefix, HA, HB, 500000, 0)
+      end, Config).
+
+throughput_64(Config) ->
+    run_nodepair_test(
+      fun (A, B, Prefix, HA, HB) ->
+              throughput(A, B, Prefix, HA, HB, 500000, 64)
+      end, Config).
+
 throughput_1024(Config) ->
     run_nodepair_test(
       fun (A, B, Prefix, HA, HB) ->
@@ -373,45 +406,198 @@ throughput_1048576(Config) ->
 throughput(A, B, Prefix, HA, HB, Packets, Size) ->
     [] = ssl_apply(HA, erlang, nodes, []),
     [] = ssl_apply(HB, erlang, nodes, []),
-    Time =
+    #{time := Time,
+      dist_stats := DistStats,
+      client_msacc_stats := ClientMsaccStats,
+      client_prof := ClientProf,
+      server_msacc_stats := ServerMsaccStats,
+      server_prof := ServerProf} =
         ssl_apply(HA, fun () -> throughput_runner(A, B, Packets, Size) end),
     [B] = ssl_apply(HA, erlang, nodes, []),
     [A] = ssl_apply(HB, erlang, nodes, []),
-    Speed = round((Packets*Size*1000000) / (1024*Time)),
+    ClientMsaccStats =:= undefined orelse
+        msacc:print(ClientMsaccStats),
+    io:format("DistStats: ~p~n", [DistStats]),
+    Overhead =
+        50 % Distribution protocol headers (empirical) (TLS+=54)
+        + byte_size(erlang:term_to_binary([0|<<>>])), % Benchmark overhead
+    Bytes = Packets * (Size + Overhead),
+    io:format("~w bytes, ~.4g s~n", [Bytes,Time/1000000]),
+    ClientMsaccStats =:= undefined orelse
+        io:format(
+          "Sender core usage ratio: ~.4g ns/byte~n",
+          [msacc:stats(system_runtime, ClientMsaccStats)*1000/Bytes]),
+    ServerMsaccStats =:= undefined orelse
+        begin
+            io:format(
+              "Receiver core usage ratio: ~.4g ns/byte~n",
+              [msacc:stats(system_runtime, ServerMsaccStats)*1000/Bytes]),
+            msacc:print(ServerMsaccStats)
+        end,
+    io:format("******* ClientProf:~n", []), prof_print(ClientProf),
+    io:format("******* ServerProf:~n", []), prof_print(ServerProf),
+    Speed = round((Bytes * 1000000) / (1024 * Time)),
     report(Prefix++" Throughput_"++integer_to_list(Size), Speed, "kB/s").
 
 %% Runs on node A and spawns a server on node B
 throughput_runner(A, B, Rounds, Size) ->
     Payload = payload(Size),
-    ClientPid = self(),
     [A] = rpc:call(B, erlang, nodes, []),
+    ClientPid = self(),
     ServerPid =
         erlang:spawn(
           B,
           fun () -> throughput_server(ClientPid, Rounds) end),
     ServerMon = erlang:monitor(process, ServerPid),
-    microseconds(
-      throughput_client(
-        ServerPid, ServerMon, Payload, start_time(), Rounds)).
+    msacc:available() andalso
+        begin
+            msacc:stop(),
+            msacc:reset(),
+            msacc:start(),
+            ok
+        end,
+    prof_start(),
+    {Time,ServerMsaccStats,ServerProf} =
+        throughput_client(ServerPid, ServerMon, Payload, Rounds),
+    prof_stop(),
+    ClientMsaccStats =
+        case msacc:available() of
+            true ->
+                MStats = msacc:stats(),
+                msacc:stop(),
+                MStats;
+            false ->
+                undefined
+        end,
+    ClientProf = prof_end(),
+    [{_Node,Socket}] = dig_dist_node_sockets(),
+    DistStats = inet:getstat(Socket),
+    #{time => microseconds(Time),
+      dist_stats => DistStats,
+      client_msacc_stats => ClientMsaccStats,
+      client_prof => ClientProf,
+      server_msacc_stats => ServerMsaccStats,
+      server_prof => ServerProf}.
+
+dig_dist_node_sockets() ->
+    [case DistCtrl of
+         {_Node,Socket} = NodeSocket when is_port(Socket) ->
+             NodeSocket;
+         {Node,DistCtrlPid} when is_pid(DistCtrlPid) ->
+             [{links,DistCtrlLinks}] = process_info(DistCtrlPid, [links]),
+             case [S || S <- DistCtrlLinks, is_port(S)] of
+                 [Socket] ->
+                     {Node,Socket};
+                 [] ->
+                     [{monitors,[{process,DistSenderPid}]}] =
+                         process_info(DistCtrlPid, [monitors]),
+                     [{links,DistSenderLinks}] =
+                         process_info(DistSenderPid, [links]),
+                     [Socket] = [S || S <- DistSenderLinks, is_port(S)],
+                     {Node,Socket}
+             end
+     end || DistCtrl <- erlang:system_info(dist_ctrl)].
+
 
-throughput_server(_Pid, 0) ->
-    ok;
 throughput_server(Pid, N) ->
+    msacc:available() andalso
+        begin
+            msacc:stop(),
+            msacc:reset(),
+            msacc:start(),
+            ok
+        end,
+    prof_start(),
+    throughput_server_loop(Pid, N).
+
+throughput_server_loop(_Pid, 0) ->
+    prof_stop(),
+    MsaccStats =
+        case msacc:available() of
+            true ->
+                msacc:stop(),
+                MStats = msacc:stats(),
+                msacc:reset(),
+                MStats;
+            false ->
+                undefined
+        end,
+    Prof = prof_end(),
+    exit({ok,MsaccStats,Prof});
+throughput_server_loop(Pid, N) ->
     receive
-        [N|_] ->
-            throughput_server(Pid, N-1)
+        {Pid, N, _} ->
+            throughput_server_loop(Pid, N-1)
     end.
 
-throughput_client(_Pid, Mon, _Payload, StartTime, 0) ->
+throughput_client(Pid, Mon, Payload, N) ->
+    throughput_client_loop(Pid, Mon, Payload, N, start_time()).
+
+throughput_client_loop(_Pid, Mon, _Payload, 0, StartTime) ->
     receive
-        {'DOWN', Mon, _, _, normal} ->
-            elapsed_time(StartTime);
+        {'DOWN', Mon, _, _, {ok,MsaccStats,Prof}} ->
+            {elapsed_time(StartTime),MsaccStats,Prof};
         {'DOWN', Mon, _, _, Other} ->
             exit(Other)
     end;
-throughput_client(Pid, Mon, Payload, StartTime, N) ->
-    Pid ! [N|Payload],
-    throughput_client(Pid, Mon, Payload, StartTime, N - 1).
+throughput_client_loop(Pid, Mon, Payload, N, StartTime) ->
+    Pid ! {self(), N, Payload},
+    throughput_client_loop(Pid, Mon, Payload, N - 1, StartTime).
+
+
+-define(prof, none). % none | cprof | eprof
+
+-if(?prof =:= cprof).
+prof_start() ->
+    cprof:stop(),
+    cprof:start(),
+    ok.
+-elif(?prof =:= eprof).
+prof_start() ->
+    {ok,_} = eprof:start(),
+    profiling = eprof:start_profiling(processes()),
+    ok.
+-elif(?prof =:= none).
+prof_start() ->
+    ok.
+-endif.
+
+-if(?prof =:= cprof).
+prof_stop() ->
+    cprof:pause(),
+    ok.
+-elif(?prof =:= eprof).
+prof_stop() ->
+    _ = eprof:stop_profiling(),
+    ok.
+-elif(?prof =:= none).
+prof_stop() ->
+    ok.
+-endif.
+
+-if(?prof =:= cprof).
+prof_end() ->
+    Prof = cprof:analyse(),
+    cprof:stop(),
+    Prof.
+-elif(?prof =:= eprof).
+prof_end() ->
+    eprof:dump_data().
+-elif(?prof =:= none).
+prof_end() ->
+    [].
+-endif.
+
+-if(?prof =:= cprof).
+prof_print(Prof) ->
+    io:format("~p.~n", [Prof]).
+-elif(?prof =:= eprof).
+prof_print(Dump) ->
+    eprof:analyze(undefined, total, [], Dump).
+-elif(?prof =:= none).
+prof_print([]) ->
+    ok.
+-endif.
 
 %%%-------------------------------------------------------------------
 %%% Test cases helpers
diff --git a/lib/ssl/test/ssl_test_lib.erl b/lib/ssl/test/ssl_test_lib.erl
index 8a2f0824fb..a8d62d6c4e 100644
--- a/lib/ssl/test/ssl_test_lib.erl
+++ b/lib/ssl/test/ssl_test_lib.erl
@@ -26,6 +26,7 @@
 
 %% Note: This directive should only be used in test suites.
 -compile(export_all).
+-compile(nowarn_export_all).
 
 -record(sslsocket, { fd = nil, pid = nil}).
 -define(SLEEP, 1000).
@@ -1706,10 +1707,10 @@ openssl_dsa_support() ->
             true;
         "LibreSSL"  ++ _ ->
             false;
-        "OpenSSL 1.1" ++ Rest ->
+        "OpenSSL 1.1" ++ _Rest ->
             false;
         "OpenSSL 1.0.1" ++ Rest ->
-            hd(Rest) >= s;
+            hd(Rest) >= $s;
         _ ->
             true
     end.
@@ -1746,8 +1747,6 @@ openssl_sane_client_cert() ->
             false; 
          "LibreSSL 2.0" ++ _ ->
             false; 
-         "LibreSSL 2.0" ++ _ ->
-            false; 
         "OpenSSL 1.0.1s-freebsd" ->
             false;
         "OpenSSL 1.0.0" ++ _ ->
diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl
index 535ddbcd04..86e3d3a8b8 100644
--- a/lib/tools/src/eprof.erl
+++ b/lib/tools/src/eprof.erl
@@ -1,7 +1,7 @@
 %%
 %% %CopyrightBegin%
 %%
-%% Copyright Ericsson AB 1996-2017. All Rights Reserved.
+%% Copyright Ericsson AB 1996-2018. All Rights Reserved.
 %%
 %% Licensed under the Apache License, Version 2.0 (the "License");
 %% you may not use this file except in compliance with the License.
@@ -26,11 +26,11 @@
 
 -export([start/0,
 	 stop/0,
-	 dump/0,
+	 dump/0, dump_data/0,
 	 start_profiling/1, start_profiling/2, start_profiling/3,
 	 profile/1, profile/2, profile/3, profile/4, profile/5,
 	 stop_profiling/0,
-	 analyze/0, analyze/1, analyze/2,
+	 analyze/0, analyze/1, analyze/2, analyze/4,
 	 log/1]).
 
 %% Internal exports 
@@ -117,6 +117,9 @@ profile(Rootset, M, F, A, Pattern, Options) ->
 dump() -> 
     gen_server:call(?MODULE, dump, infinity).
 
+dump_data() ->
+    gen_server:call(?MODULE, dump_data, infinity).
+
 log(File) ->
     gen_server:call(?MODULE, {logfile, File}, infinity).
 
@@ -151,22 +154,18 @@ init([]) ->
 
 %% analyze
 
-handle_call({analyze, _, _}, _, #state{ bpd = #bpd{ p = {0,nil}, us = 0, n = 0} = Bpd } = S) when is_record(Bpd, bpd) ->
+handle_call(
+  {analyze, _, _}, _,
+  #state{ bpd = #bpd{ p = {0,nil}, us = 0, n = 0 } } = S) ->
     {reply, nothing_to_analyze, S};
 
-handle_call({analyze, procs, Opts}, _, #state{ bpd = #bpd{ p = Ps, us = Tus} = Bpd, fd = Fd} = S) when is_record(Bpd, bpd) ->
-    lists:foreach(fun
-	    ({Pid, Mfas}) ->
-		{Pn, Pus} =  sum_bp_total_n_us(Mfas),
-		format(Fd, "~n****** Process ~w    -- ~s % of profiled time *** ~n", [Pid, s("~.2f", [100.0*divide(Pus,Tus)])]),
-		print_bp_mfa(Mfas, {Pn,Pus}, Fd, Opts),
-		ok
-	end, gb_trees:to_list(Ps)),
-    {reply, ok, S};
+handle_call({analyze, procs, Opts}, _, #state{ bpd = Bpd, fd = Fd } = S)
+  when is_record(Bpd, bpd) ->
+    {reply, analyze(Fd, procs, Opts, Bpd), S};
 
-handle_call({analyze, total, Opts}, _, #state{ bpd = #bpd{ mfa = Mfas, n = Tn, us = Tus} = Bpd, fd = Fd} = S) when is_record(Bpd, bpd) ->
-    print_bp_mfa(Mfas, {Tn, Tus}, Fd, Opts),
-    {reply, ok, S};
+handle_call({analyze, total, Opts}, _, #state{ bpd = Bpd, fd = Fd } = S)
+  when is_record(Bpd, bpd) ->
+    {reply, analyze(Fd, total, Opts, Bpd), S};
 
 handle_call({analyze, Type, _Opts}, _, S) ->
     {reply, {error, {undefined, Type}}, S};
@@ -260,6 +259,10 @@ handle_call({logfile, File}, _From, #state{ fd = OldFd } = S) ->
 handle_call(dump, _From, #state{ bpd = Bpd } = S) when is_record(Bpd, bpd) ->
     {reply, gb_trees:to_list(Bpd#bpd.p), S};
 
+handle_call(dump_data, _, #state{ bpd = #bpd{} = Bpd } = S)
+  when is_record(Bpd, bpd) ->
+    {reply, Bpd, S};
+
 handle_call(stop, _FromTag, S) ->
     {stop, normal, stopped, S}.
 
@@ -438,6 +441,23 @@ collect_bpdfp(Mfa, Tree, Data) ->
 	    {PTno + Ni, PTuso + Time, Ti1}
     end, {0,0, Tree}, Data).
 
+
+
+analyze(Fd, procs, Opts, #bpd{ p = Ps, us = Tus }) ->
+    lists:foreach(
+      fun
+          ({Pid, Mfas}) ->
+              {Pn, Pus} =  sum_bp_total_n_us(Mfas),
+              format(
+                Fd,
+                "~n****** Process ~w    -- ~s % of profiled time *** ~n",
+                [Pid, s("~.2f", [100.0*divide(Pus, Tus)])]),
+              print_bp_mfa(Mfas, {Pn,Pus}, Fd, Opts),
+              ok
+      end, gb_trees:to_list(Ps));
+analyze(Fd, total, Opts, #bpd{ mfa = Mfas, n = Tn, us = Tus } ) ->
+    print_bp_mfa(Mfas, {Tn, Tus}, Fd, Opts).
+
 %% manipulators
 sort_mfa(Bpfs, mfa) when is_list(Bpfs) ->
     lists:sort(fun