File 2812-ssh-Enable-foreign-dbg-messages-in-ssh_dbg.patch of Package erlang
From f74464fa5f713642cc4726b2831cad17f81b9a83 Mon Sep 17 00:00:00 2001
From: Hans Nilsson <hans@erlang.org>
Date: Wed, 15 Apr 2020 09:34:24 +0200
Subject: [PATCH 2/5] ssh: Enable foreign dbg messages in ssh_dbg
---
lib/ssh/src/ssh_acceptor.erl | 5 +++
lib/ssh/src/ssh_cli.erl | 5 ++-
lib/ssh/src/ssh_client_channel.erl | 6 ++++
lib/ssh/src/ssh_connection_handler.erl | 19 +++++++++--
lib/ssh/src/ssh_dbg.erl | 45 +++++++++++++++++---------
lib/ssh/src/ssh_message.erl | 11 +++++++
lib/ssh/src/ssh_sftp.erl | 4 ++-
lib/ssh/src/ssh_sftpd.erl | 4 ++-
lib/ssh/src/ssh_shell.erl | 4 ++-
lib/ssh/src/ssh_transport.erl | 9 ++++++
lib/ssh/test/ssh_dbg_SUITE.erl | 9 +++++-
11 files changed, 98 insertions(+), 23 deletions(-)
diff --git a/lib/ssh/src/ssh_acceptor.erl b/lib/ssh/src/ssh_acceptor.erl
index 15e59dd1fe..960058fa38 100644
--- a/lib/ssh/src/ssh_acceptor.erl
+++ b/lib/ssh/src/ssh_acceptor.erl
@@ -217,6 +217,11 @@ ssh_dbg_format(connections, {call, {?MODULE,acceptor_init,
[_Parent, Port, Address, _Opts, _AcceptTimeout]}}) ->
[io_lib:format("Starting LISTENER on ~s:~p\n", [ntoa(Address),Port])
];
+ssh_dbg_format(connections, {return_from, {?MODULE,acceptor_init,5}, _Ret}) ->
+ skip;
+
+ssh_dbg_format(connections, {call, {?MODULE,handle_connection,[_,_,_,_,_]}}) ->
+ skip;
ssh_dbg_format(connections, {return_from, {?MODULE,handle_connection,5}, {error,Error}}) ->
["Starting connection to server failed:\n",
io_lib:format("Error = ~p", [Error])
diff --git a/lib/ssh/src/ssh_cli.erl b/lib/ssh/src/ssh_cli.erl
index d6c8cf84ed..729ce67968 100644
--- a/lib/ssh/src/ssh_cli.erl
+++ b/lib/ssh/src/ssh_cli.erl
@@ -663,6 +663,9 @@ ssh_dbg_off(terminate) -> dbg:ctpg(?MODULE, terminate, 2).
ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, State]}}) ->
["Cli Terminating:\n",
io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)])
- ].
+ ];
+ssh_dbg_format(terminate, {return_from, {?MODULE,terminate,2}, _Ret}) ->
+ skip.
+
?wr_record(state).
diff --git a/lib/ssh/src/ssh_client_channel.erl b/lib/ssh/src/ssh_client_channel.erl
index 6de897e1b2..5ffdf49e9b 100644
--- a/lib/ssh/src/ssh_client_channel.erl
+++ b/lib/ssh/src/ssh_client_channel.erl
@@ -419,12 +419,16 @@ ssh_dbg_format(channels, {return_from, {?MODULE,init,1}, {stop,Reason}}) ->
["Server Channel Start FAILED!\n",
io_lib:format("Reason = ~p", [Reason])
];
+
ssh_dbg_format(channels, F) ->
ssh_dbg_format(terminate, F);
+
ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, State]}}) ->
["Server Channel Terminating:\n",
io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)])
];
+ssh_dbg_format(terminate, {return_from, {?MODULE,terminate,2}, _Ret}) ->
+ skip;
ssh_dbg_format(channel_events, {call, {?MODULE,handle_call, [Call,From,State]}}) ->
[hdr("is called", State),
@@ -434,6 +438,7 @@ ssh_dbg_format(channel_events, {return_from, {?MODULE,handle_call,3}, Ret}) ->
["Server Channel call returned:\n",
io_lib:format("~p~n", [ssh_dbg:reduce_state(Ret)])
];
+
ssh_dbg_format(channel_events, {call, {?MODULE,handle_cast, [Cast,State]}}) ->
[hdr("got cast", State),
io_lib:format("Cast: ~p~n", [Cast])
@@ -442,6 +447,7 @@ ssh_dbg_format(channel_events, {return_from, {?MODULE,handle_cast,2}, Ret}) ->
["Server Channel cast returned:\n",
io_lib:format("~p~n", [ssh_dbg:reduce_state(Ret)])
];
+
ssh_dbg_format(channel_events, {call, {?MODULE,handle_info, [Info,State]}}) ->
[hdr("got info", State),
io_lib:format("Info: ~p~n", [Info])
diff --git a/lib/ssh/src/ssh_connection_handler.erl b/lib/ssh/src/ssh_connection_handler.erl
index 73ddc190d4..88338eda85 100644
--- a/lib/ssh/src/ssh_connection_handler.erl
+++ b/lib/ssh/src/ssh_connection_handler.erl
@@ -2561,17 +2561,26 @@ ssh_dbg_format(renegotiation, {call, {?MODULE,init_renegotiate_timers,[_State,D]
[?GET_OPT(rekey_limit, (D#data.ssh_params)#ssh.opts),
?REKEY_DATA_TIMOUT])
];
+ssh_dbg_format(renegotiation, {return_from, {?MODULE,init_renegotiate_timers,2}, _Ret}) ->
+ skip;
+
ssh_dbg_format(renegotiation, {call, {?MODULE,pause_renegotiate_timers,[_State,_D]}}) ->
["Renegotiation pause\n"];
+ssh_dbg_format(renegotiation, {return_from, {?MODULE,pause_renegotiate_timers,2}, _Ret}) ->
+ skip;
+
ssh_dbg_format(renegotiation, {call, {?MODULE,start_rekeying,[_Role,_D]}}) ->
["Renegotiation start rekeying\n"];
+ssh_dbg_format(renegotiation, {return_from, {?MODULE,start_rekeying,2}, _Ret}) ->
+ skip;
+
ssh_dbg_format(renegotiation, {call, {?MODULE,check_data_rekeying_dbg,[SentSinceRekey, MaxSent]}}) ->
["Renegotiation check data sent\n",
io_lib:format("TotalSentSinceRekey: ~p~nMaxBeforeRekey: ~p~nStartRekey: ~p~n",
[SentSinceRekey, MaxSent, SentSinceRekey >= MaxSent])
];
-
-
+ssh_dbg_format(renegotiation, {return_from, {?MODULE,check_data_rekeying_dbg,2}, _Ret}) ->
+ skip;
ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, StateName, D]}}) ->
ExtraInfo =
@@ -2605,6 +2614,8 @@ ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, StateName, D]}}) -
[Reason, StateName, ExtraInfo, state_data2proplist(D)])
]
end;
+ssh_dbg_format(renegotiation, {return_from, {?MODULE,terminate,3}, _Ret}) ->
+ skip;
ssh_dbg_format(disconnect, {call,{?MODULE,send_disconnect,
[Code, Reason, DetailedText, Module, Line, StateName, _D]}}) ->
@@ -2614,7 +2625,9 @@ ssh_dbg_format(disconnect, {call,{?MODULE,send_disconnect,
" DetailedText =~n"
" ~p",
[Module, Line, StateName, Code, Reason, lists:flatten(DetailedText)])
- ].
+ ];
+ssh_dbg_format(renegotiation, {return_from, {?MODULE,send_disconnect,7}, _Ret}) ->
+ skip.
event_handler_result({next_state, NextState, _NewData}) ->
diff --git a/lib/ssh/src/ssh_dbg.erl b/lib/ssh/src/ssh_dbg.erl
index 5e3c48d468..5188b74f72 100644
--- a/lib/ssh/src/ssh_dbg.erl
+++ b/lib/ssh/src/ssh_dbg.erl
@@ -89,7 +89,7 @@
-callback ssh_dbg_flags(trace_point()) -> [atom()].
-callback ssh_dbg_on(trace_point() | trace_points()) -> term().
-callback ssh_dbg_off(trace_point() | trace_points()) -> term().
--callback ssh_dbg_format(trace_point(), term()) -> iolist().
+-callback ssh_dbg_format(trace_point(), term()) -> iolist() | skip.
%%%================================================================
@@ -325,20 +325,35 @@ try_all_types_in_all_modules(TypesOn, Arg, WriteFun, Acc0) ->
TS = trace_ts(Arg),
PID = trace_pid(Arg),
INFO = trace_info(Arg),
- lists:foldl(
- fun(Type, Acc1) ->
- lists:foldl(
- fun(SshMod,Acc) ->
- try WriteFun("~n~s ~p ~s~n",
- [lists:flatten(TS),
- PID,
- lists:flatten(SshMod:ssh_dbg_format(Type, INFO))],
- Acc)
- catch
- _:_ -> Acc
- end
- end, Acc1, SshModules)
- end, Acc0, TypesOn).
+ Acc =
+ lists:foldl(
+ fun(Type, Acc1) ->
+ lists:foldl(
+ fun(SshMod,Acc) ->
+ try SshMod:ssh_dbg_format(Type, INFO)
+ of
+ skip ->
+ %% Don't try to print this later
+ written;
+ Txt when is_list(Txt) ->
+ WriteFun("~n~s ~p ~s~n",
+ [lists:flatten(TS),
+ PID,
+ lists:flatten(Txt)],
+ written % this is returned
+ )
+ catch
+ _:_ -> Acc
+ end
+ end, Acc1, SshModules)
+ end, Acc0, TypesOn),
+ case Acc of
+ Acc0 ->
+ %% INFO :: any()
+ WriteFun("~n~s ~p DEBUG~n~p~n", [lists:flatten(TS),PID,INFO], Acc0);
+ written ->
+ Acc0
+ end.
%%%----------------------------------------------------------------
wr_record(T, Fs, BL) when is_tuple(T) ->
diff --git a/lib/ssh/src/ssh_message.erl b/lib/ssh/src/ssh_message.erl
index 30b0c89144..804775bd75 100644
--- a/lib/ssh/src/ssh_message.erl
+++ b/lib/ssh/src/ssh_message.erl
@@ -762,15 +762,26 @@ ssh_dbg_format(ssh_messages, {call,{?MODULE,encode,[Msg]}}) ->
["Going to send ",Name,":\n",
wr_record(ssh_dbg:shrink_bin(Msg))
];
+ssh_dbg_format(ssh_messages, {return_from, {?MODULE,encode,1}, _Ret}) ->
+ skip;
+
+ssh_dbg_format(ssh_messages, {call, {?MODULE,decode,[_]}}) ->
+ skip;
ssh_dbg_format(ssh_messages, {return_from,{?MODULE,decode,1},Msg}) ->
Name = string:to_upper(atom_to_list(element(1,Msg))),
["Received ",Name,":\n",
wr_record(ssh_dbg:shrink_bin(Msg))
];
+
ssh_dbg_format(raw_messages, {call,{?MODULE,decode,[BytesPT]}}) ->
["Received plain text bytes (shown after decryption):\n",
io_lib:format("~p",[BytesPT])
];
+ssh_dbg_format(raw_messages, {return_from, {?MODULE,decode,1}, _Ret}) ->
+ skip;
+
+ssh_dbg_format(raw_messages, {call, {?MODULE,encode,[_]}}) ->
+ skip;
ssh_dbg_format(raw_messages, {return_from,{?MODULE,encode,1},BytesPT}) ->
["Going to send plain text bytes (shown before encryption):\n",
io_lib:format("~p",[BytesPT])
diff --git a/lib/ssh/src/ssh_sftp.erl b/lib/ssh/src/ssh_sftp.erl
index 9ee6ed68c1..69fff09979 100644
--- a/lib/ssh/src/ssh_sftp.erl
+++ b/lib/ssh/src/ssh_sftp.erl
@@ -1843,7 +1843,9 @@ ssh_dbg_off(terminate) -> dbg:ctpg(?MODULE, terminate, 2).
ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, State]}}) ->
["Sftp Terminating:\n",
io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)])
- ].
+ ];
+ssh_dbg_format(terminate, {return_from, {?MODULE,terminate,2}, _Ret}) ->
+ skip.
?wr_record(state).
diff --git a/lib/ssh/src/ssh_sftpd.erl b/lib/ssh/src/ssh_sftpd.erl
index 78277705d8..158ef3d5ae 100644
--- a/lib/ssh/src/ssh_sftpd.erl
+++ b/lib/ssh/src/ssh_sftpd.erl
@@ -964,6 +964,8 @@ ssh_dbg_off(terminate) -> dbg:ctpg(?MODULE, terminate, 2).
ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, State]}}) ->
["SftpD Terminating:\n",
io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)])
- ].
+ ];
+ssh_dbg_format(terminate, {return_from, {?MODULE,terminate,2}, _Ret}) ->
+ skip.
?wr_record(state).
diff --git a/lib/ssh/src/ssh_shell.erl b/lib/ssh/src/ssh_shell.erl
index b5862b2395..be8a6aa8cc 100644
--- a/lib/ssh/src/ssh_shell.erl
+++ b/lib/ssh/src/ssh_shell.erl
@@ -200,6 +200,8 @@ ssh_dbg_off(terminate) -> dbg:ctpg(?MODULE, terminate, 2).
ssh_dbg_format(terminate, {call, {?MODULE,terminate, [Reason, State]}}) ->
["Shell Terminating:\n",
io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)])
- ].
+ ];
+ssh_dbg_format(terminate, {return_from, {?MODULE,terminate,2}, _Ret}) ->
+ skip.
?wr_record(state).
diff --git a/lib/ssh/src/ssh_transport.erl b/lib/ssh/src/ssh_transport.erl
index 86d4ef951c..bd901c99e0 100644
--- a/lib/ssh/src/ssh_transport.erl
+++ b/lib/ssh/src/ssh_transport.erl
@@ -2081,18 +2081,27 @@ ssh_dbg_off(ssh_messages) -> ssh_dbg_off(hello).
+ssh_dbg_format(hello, {call,{?MODULE,hello_version_msg,[_]}}) ->
+ skip;
ssh_dbg_format(hello, {return_from,{?MODULE,hello_version_msg,1},Hello}) ->
["Going to send hello message:\n",
Hello
];
+
ssh_dbg_format(hello, {call,{?MODULE,handle_hello_version,[Hello]}}) ->
["Received hello message:\n",
Hello
];
+ssh_dbg_format(hello, {return_from,{?MODULE,handle_hello_version,1},_Ret}) ->
+ skip;
+
+ssh_dbg_format(alg, {call,{?MODULE,select_algorithm,[_,_,_,_]}}) ->
+ skip;
ssh_dbg_format(alg, {return_from,{?MODULE,select_algorithm,5},{ok,Alg}}) ->
["Negotiated algorithms:\n",
wr_record(Alg)
];
+
ssh_dbg_format(raw_messages, X) -> ssh_dbg_format(hello, X);
ssh_dbg_format(ssh_messages, X) -> ssh_dbg_format(hello, X).
diff --git a/lib/ssh/test/ssh_dbg_SUITE.erl b/lib/ssh/test/ssh_dbg_SUITE.erl
index ab7918fa90..8df9c8093a 100644
--- a/lib/ssh/test/ssh_dbg_SUITE.erl
+++ b/lib/ssh/test/ssh_dbg_SUITE.erl
@@ -82,6 +82,8 @@ end_per_testcase(_TC, Config) ->
ok
after 5000 ->
+ ct:log("~p:~p Messages:~n~p",
+ [?MODULE,?LINE, process_info(self(),messages)]),
ssh_dbg:stop(),
ssh:stop_daemon(Pid),
ct:fail("No '~s' debug message",[ExpectPfx])
@@ -448,10 +450,15 @@ dbg_SKIP(Ref, Prefixes) ->
dbg_SKIP(Ref, Prefixes, UnexpectedAcc) ->
receive
+ {Ref, [_, _C, Msg]} when is_tuple(Msg) ->
+ %% filter non ssh_dbg messages, for example from dbg:tp(..) etc
+ dbg_SKIP(Ref, Prefixes, UnexpectedAcc);
{Ref, [_, _C, Msg]=M} ->
case lists:any(
fun(Pfx) ->
- lists:prefix(Pfx, Msg)
+ try lists:prefix(Pfx, Msg)
+ catch _:_ -> false
+ end
end, Prefixes) of
true ->
ct:log("Skip:~n~p", [M]),
--
2.26.1
