diff options
author | Hans Nilsson <[email protected]> | 2018-02-28 16:47:20 +0100 |
---|---|---|
committer | Hans Nilsson <[email protected]> | 2018-03-29 11:58:28 +0200 |
commit | 3715deff44f38aa35873106cd1f116c74c65040a (patch) | |
tree | 858ee3c036609eab1f717c5fd42a9b606465026a | |
parent | 3352eaf189c55e60778fc76b94530fac0c314fba (diff) | |
download | otp-3715deff44f38aa35873106cd1f116c74c65040a.tar.gz otp-3715deff44f38aa35873106cd1f116c74c65040a.tar.bz2 otp-3715deff44f38aa35873106cd1f116c74c65040a.zip |
ssh: Use the new ssh_dbg module
-rw-r--r-- | lib/ssh/src/ssh.hrl | 2 | ||||
-rw-r--r-- | lib/ssh/src/ssh_acceptor.erl | 32 | ||||
-rw-r--r-- | lib/ssh/src/ssh_auth.erl | 37 | ||||
-rw-r--r-- | lib/ssh/src/ssh_channel.erl | 93 | ||||
-rw-r--r-- | lib/ssh/src/ssh_cli.erl | 18 | ||||
-rw-r--r-- | lib/ssh/src/ssh_connection.erl | 1 | ||||
-rw-r--r-- | lib/ssh/src/ssh_connection_handler.erl | 614 | ||||
-rw-r--r-- | lib/ssh/src/ssh_message.erl | 85 | ||||
-rw-r--r-- | lib/ssh/src/ssh_no_io.erl | 27 | ||||
-rw-r--r-- | lib/ssh/src/ssh_sftp.erl | 20 | ||||
-rw-r--r-- | lib/ssh/src/ssh_sftpd.erl | 19 | ||||
-rw-r--r-- | lib/ssh/src/ssh_shell.erl | 20 | ||||
-rw-r--r-- | lib/ssh/src/ssh_transport.erl | 208 | ||||
-rw-r--r-- | lib/ssh/src/ssh_transport.hrl | 3 |
14 files changed, 850 insertions, 329 deletions
diff --git a/lib/ssh/src/ssh.hrl b/lib/ssh/src/ssh.hrl index 48af72210c..0e118ac13f 100644 --- a/lib/ssh/src/ssh.hrl +++ b/lib/ssh/src/ssh.hrl @@ -137,6 +137,8 @@ {inet:hostname(), {inet:ip_address(),inet:port_number()}}, %% string version of peer address + local, %% Local sockname. Need this AFTER a socket is closed by i.e. a crash + c_vsn, %% client version {Major,Minor} s_vsn, %% server version {Major,Minor} diff --git a/lib/ssh/src/ssh_acceptor.erl b/lib/ssh/src/ssh_acceptor.erl index 27d4242dd4..516a9febaa 100644 --- a/lib/ssh/src/ssh_acceptor.erl +++ b/lib/ssh/src/ssh_acceptor.erl @@ -33,6 +33,8 @@ %% spawn export -export([acceptor_init/5, acceptor_loop/6]). +-export([dbg_trace/3]). + -define(SLEEP_TIME, 200). %%==================================================================== @@ -195,3 +197,33 @@ handle_error(Reason) -> error_logger:error_report(String), exit({accept_failed, String}). +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [connections]; + +dbg_trace(flags, connections, _) -> [c]; +dbg_trace(on, connections, _) -> dbg:tp(?MODULE, acceptor_init, 5, x), + dbg:tpl(?MODULE, handle_connection, 5, x); +dbg_trace(off, connections, _) -> dbg:ctp(?MODULE, acceptor_init, 5), + dbg:ctp(?MODULE, handle_connection, 5); +dbg_trace(format, connections, {call, {?MODULE,acceptor_init, + [_Parent, Port, Address, _Opts, _AcceptTimeout]}}) -> + [io_lib:format("Starting LISTENER on ~s:~p\n", [ntoa(Address),Port]) + ]; +dbg_trace(format, connections, {return_from, {?MODULE,handle_connection,5}, {error,Error}}) -> + ["Starting connection to server failed:\n", + io_lib:format("Error = ~p", [Error]) + ]. + + + +ntoa(A) -> + try inet:ntoa(A) + catch + _:_ when is_list(A) -> A; + _:_ -> io_lib:format('~p',[A]) + end. + diff --git a/lib/ssh/src/ssh_auth.erl b/lib/ssh/src/ssh_auth.erl index 03d264745b..bf3f5a68e4 100644 --- a/lib/ssh/src/ssh_auth.erl +++ b/lib/ssh/src/ssh_auth.erl @@ -40,15 +40,12 @@ %%-------------------------------------------------------------------- %%%---------------------------------------------------------------- userauth_request_msg(#ssh{userauth_methods = ServerMethods, - userauth_supported_methods = UserPrefMethods, % Note: this is not documented as supported for clients + userauth_supported_methods = UserPrefMethods, userauth_preference = ClientMethods0 } = Ssh0) -> case sort_select_mthds(ClientMethods0, UserPrefMethods, ServerMethods) of [] -> - Msg = #ssh_msg_disconnect{code = ?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE, - description = "Unable to connect using the available authentication methods", - language = "en"}, - {disconnect, Msg, ssh_transport:ssh_packet(Msg, Ssh0)}; + {send_disconnect, ?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE, Ssh0}; [{Pref,Module,Function,Args} | Prefs] -> Ssh = case Pref of @@ -196,11 +193,8 @@ init_userauth_request_msg(#ssh{opts = Opts} = Ssh) -> %% Client side case ?GET_OPT(user, Opts) of undefined -> - ErrStr = "Could not determine the users name", - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_ILLEGAL_USER_NAME, - description = ErrStr}); - + ?DISCONNECT(?SSH_DISCONNECT_ILLEGAL_USER_NAME, + "Could not determine the users name"); User -> ssh_transport:ssh_packet( #ssh_msg_userauth_request{user = User, @@ -451,11 +445,8 @@ handle_userauth_info_response({extra,#ssh_msg_userauth_info_response{}}, handle_userauth_info_response(#ssh_msg_userauth_info_response{}, _Auth) -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "Server does not support keyboard-interactive" - }). - + ?DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + "Server does not support keyboard-interactive"). %%-------------------------------------------------------------------- %%% Internal functions @@ -492,10 +483,8 @@ check_password(User, Password, Opts, Ssh) -> {false,NewState} -> {false, Ssh#ssh{pwdfun_user_state=NewState}}; disconnect -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "Unable to connect using the available authentication methods" - }) + ?DISCONNECT(?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE, + "") end end. @@ -591,16 +580,12 @@ keyboard_interact_fun(KbdInteractFun, Name, Instr, PromptInfos, NumPrompts) -> case KbdInteractFun(Name, Instr, Prompts) of Rs when length(Rs) == NumPrompts -> Rs; - Rs -> - throw({mismatching_number_of_responses, - {got,Rs}, - {expected, NumPrompts}, - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "User interaction failed", - language = "en"}}) + _Rs -> + nok end. key_alg('rsa-sha2-256') -> 'ssh-rsa'; key_alg('rsa-sha2-512') -> 'ssh-rsa'; key_alg(Alg) -> Alg. + diff --git a/lib/ssh/src/ssh_channel.erl b/lib/ssh/src/ssh_channel.erl index 85b31f3669..b90e571448 100644 --- a/lib/ssh/src/ssh_channel.erl +++ b/lib/ssh/src/ssh_channel.erl @@ -22,6 +22,7 @@ -module(ssh_channel). +-include("ssh.hrl"). -include("ssh_connect.hrl"). -callback init(Args :: term()) -> @@ -71,6 +72,8 @@ cache_info/2, cache_find/2, get_print_info/1]). +-export([dbg_trace/3]). + -record(state, { cm, channel_cb, @@ -159,14 +162,7 @@ init([Options]) -> ConnectionManager = proplists:get_value(cm, Options), ChannelId = proplists:get_value(channel_id, Options), process_flag(trap_exit, true), - InitArgs = - case proplists:get_value(exec, Options) of - undefined -> - proplists:get_value(init_args, Options); - Exec -> - proplists:get_value(init_args, Options) ++ [Exec] - end, - try Cb:init(InitArgs) of + try Cb:init(channel_cb_init_args(Options)) of {ok, ChannelState} -> State = #state{cm = ConnectionManager, channel_cb = Cb, @@ -188,6 +184,14 @@ init([Options]) -> {stop, Reason} end. +channel_cb_init_args(Options) -> + case proplists:get_value(exec, Options) of + undefined -> + proplists:get_value(init_args, Options); + Exec -> + proplists:get_value(init_args, Options) ++ [Exec] + end. + %%-------------------------------------------------------------------- %% Function: %% handle_call(Request, From, State) -> {reply, Reply, State} | %% {reply, Reply, State, Timeout} | @@ -377,3 +381,76 @@ adjust_window(_) -> ok. +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [terminate, channels, channel_events]; + + +dbg_trace(flags, channels, A) -> [c] ++ dbg_trace(flags, terminate, A); +dbg_trace(on, channels, A) -> dbg:tp(?MODULE, init, 1, x), + dbg_trace(on, terminate, A); +dbg_trace(off, channels, A) -> dbg:ctpg(?MODULE, init, 1), + dbg_trace(off, terminate, A); +dbg_trace(format, channels, {call, {?MODULE,init, [[KVs]]}}) -> + ["Server Channel Starting:\n", + io_lib:format("Connection: ~p, ChannelId: ~p, CallBack: ~p\nCallBack init args = ~p", + [proplists:get_value(K,KVs) || K <- [cm, channel_id, channel_cb]] + ++ [channel_cb_init_args(KVs)]) + ]; +dbg_trace(format, channels, {return_from, {?MODULE,init,1}, {stop,Reason}}) -> + ["Server Channel Start FAILED!\n", + io_lib:format("Reason = ~p", [Reason]) + ]; +dbg_trace(format, channels, F) -> + dbg_trace(format, terminate, F); + + +dbg_trace(flags, terminate, _) -> [c]; +dbg_trace(on, terminate, _) -> dbg:tp(?MODULE, terminate, 2, x); +dbg_trace(off, terminate, _) -> dbg:ctpg(?MODULE, terminate, 2); +dbg_trace(format, terminate, {call, {?MODULE,terminate, [Reason, State]}}) -> + ["Server Channel Terminating:\n", + io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)]) + ]; + +dbg_trace(flags, channel_events, _) -> [c]; +dbg_trace(on, channel_events, _) -> dbg:tp(?MODULE, handle_call, 3, x), + dbg:tp(?MODULE, handle_cast, 2, x), + dbg:tp(?MODULE, handle_info, 2, x); +dbg_trace(off, channel_events, _) -> dbg:ctpg(?MODULE, handle_call, 3), + dbg:ctpg(?MODULE, handle_cast, 2), + dbg:ctpg(?MODULE, handle_info, 2); +dbg_trace(format, channel_events, {call, {?MODULE,handle_call, [Call,From,State]}}) -> + [hdr("is called", State), + io_lib:format("From: ~p~nCall: ~p~n", [From, Call]) + ]; +dbg_trace(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)]) + ]; +dbg_trace(format, channel_events, {call, {?MODULE,handle_cast, [Cast,State]}}) -> + [hdr("got cast", State), + io_lib:format("Cast: ~p~n", [Cast]) + ]; +dbg_trace(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)]) + ]; +dbg_trace(format, channel_events, {call, {?MODULE,handle_info, [Info,State]}}) -> + [hdr("got info", State), + io_lib:format("Info: ~p~n", [Info]) + ]; +dbg_trace(format, channel_events, {return_from, {?MODULE,handle_info,2}, Ret}) -> + ["Server Channel info returned:\n", + io_lib:format("~p~n", [ssh_dbg:reduce_state(Ret)]) + ]. + +hdr(Title, S) -> + io_lib:format("Server Channel (Id=~p, CB=~p) ~s:\n", [S#state.channel_id, S#state.channel_cb, Title]). + +?wr_record(state). + + diff --git a/lib/ssh/src/ssh_cli.erl b/lib/ssh/src/ssh_cli.erl index 783f2f80c0..26c7cb45aa 100644 --- a/lib/ssh/src/ssh_cli.erl +++ b/lib/ssh/src/ssh_cli.erl @@ -33,6 +33,8 @@ %% ssh_channel callbacks -export([init/1, handle_ssh_msg/2, handle_msg/2, terminate/2]). +-export([dbg_trace/3]). + %% state -record(state, { cm, @@ -638,3 +640,19 @@ not_zero(0, B) -> not_zero(A, _) -> A. +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [terminate]; + +dbg_trace(flags, terminate, _) -> [c]; +dbg_trace(on, terminate, _) -> dbg:tp(?MODULE, terminate, 2, x); +dbg_trace(off, terminate, _) -> dbg:ctpg(?MODULE, terminate, 2); +dbg_trace(format, terminate, {call, {?MODULE,terminate, [Reason, State]}}) -> + ["Cli Terminating:\n", + io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)]) + ]. + +?wr_record(state). diff --git a/lib/ssh/src/ssh_connection.erl b/lib/ssh/src/ssh_connection.erl index 03336d6b25..2b8780a991 100644 --- a/lib/ssh/src/ssh_connection.erl +++ b/lib/ssh/src/ssh_connection.erl @@ -601,6 +601,7 @@ handle_msg(#ssh_msg_request_failure{}, #connection{requests = [{_, From} | Rest]} = Connection, _) -> {[{channel_request_reply, From, {failure, <<>>}}], Connection#connection{requests = Rest}}; + handle_msg(#ssh_msg_request_success{data = Data}, #connection{requests = [{_, From} | Rest]} = Connection, _) -> {[{channel_request_reply, From, {success, Data}}], diff --git a/lib/ssh/src/ssh_connection_handler.erl b/lib/ssh/src/ssh_connection_handler.erl index 907ecef860..4261e5bf13 100644 --- a/lib/ssh/src/ssh_connection_handler.erl +++ b/lib/ssh/src/ssh_connection_handler.erl @@ -56,7 +56,7 @@ connection_info/2, channel_info/3, adjust_window/3, close/2, - disconnect/1, disconnect/2, + disconnect/4, get_print_info/1 ]). @@ -71,6 +71,18 @@ renegotiate/1, renegotiate_data/1, alg/1 % Export intended for test cases ]). +-export([dbg_trace/3]). + + +-define(send_disconnect(Code, DetailedText, StateName, State), + send_disconnect(Code, DetailedText, ?MODULE, ?LINE, StateName, State)). + +-define(send_disconnect(Code, Reason, DetailedText, StateName, State), + send_disconnect(Code, Reason, DetailedText, ?MODULE, ?LINE, StateName, State)). + +-define(call_disconnectfun_and_log_cond(LogMsg, DetailedText, StateName, D), + call_disconnectfun_and_log_cond(LogMsg, DetailedText, ?MODULE, ?LINE, StateName, D)). + %%==================================================================== %% Start / stop %%==================================================================== @@ -149,17 +161,16 @@ start_connection(server = Role, Socket, Options, Timeout) -> %%-------------------------------------------------------------------- %%% Some other module has decided to disconnect. --spec disconnect(#ssh_msg_disconnect{}) -> no_return(). --spec disconnect(#ssh_msg_disconnect{}, iodata()) -> no_return(). + +-spec disconnect(Code::integer(), Details::iodata(), + Module::atom(), Line::integer()) -> no_return(). %% . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . -disconnect(Msg = #ssh_msg_disconnect{}) -> - throw({keep_state_and_data, - [{next_event, internal, {disconnect, Msg, Msg#ssh_msg_disconnect.description}}]}). -disconnect(Msg = #ssh_msg_disconnect{}, ExtraInfo) -> - throw({keep_state_and_data, - [{next_event, internal, {disconnect, Msg, {Msg#ssh_msg_disconnect.description,ExtraInfo}}}]}). +% Preferable called with the macro ?DISCONNECT +disconnect(Code, DetailedText, Module, Line) -> + throw({keep_state_and_data, + [{next_event, internal, {send_disconnect, Code, DetailedText, Module, Line}}]}). %%-------------------------------------------------------------------- -spec open_channel(connection_ref(), @@ -445,7 +456,7 @@ init_ssh_record(Role, Socket, Opts) -> {ok,PeerAddr} = inet:peername(Socket), init_ssh_record(Role, Socket, PeerAddr, Opts). -init_ssh_record(Role, _Socket, PeerAddr, Opts) -> +init_ssh_record(Role, Socket, PeerAddr, Opts) -> AuthMethods = ?GET_OPT(auth_methods, Opts), S0 = #ssh{role = Role, key_cb = ?GET_OPT(key_cb, Opts), @@ -456,6 +467,10 @@ init_ssh_record(Role, _Socket, PeerAddr, Opts) -> }, {Vsn, Version} = ssh_transport:versions(Role, Opts), + LocalName = case inet:sockname(Socket) of + {ok,Local} -> Local; + _ -> undefined + end, case Role of client -> PeerName = case ?GET_INTERNAL_OPT(host, Opts) of @@ -474,7 +489,8 @@ init_ssh_record(Role, _Socket, PeerAddr, Opts) -> false -> ssh_no_io end, userauth_quiet_mode = ?GET_OPT(quiet_mode, Opts), - peer = {PeerName, PeerAddr} + peer = {PeerName, PeerAddr}, + local = LocalName }, S1#ssh{userauth_pubkeys = [K || K <- ?GET_OPT(pref_public_key_algs, Opts), is_usable_user_pubkey(K, S1) @@ -487,7 +503,8 @@ init_ssh_record(Role, _Socket, PeerAddr, Opts) -> io_cb = ?GET_INTERNAL_OPT(io_cb, Opts, ssh_io), userauth_methods = string:tokens(AuthMethods, ","), kb_tries_left = 3, - peer = {undefined, PeerAddr} + peer = {undefined, PeerAddr}, + local = LocalName } end. @@ -545,7 +562,7 @@ callback_mode() -> handle_event_function. -handle_event(_, _Event, {init_error,Error}, _) -> +handle_event(_, _Event, {init_error,Error}=StateName, D) -> case Error of enotconn -> %% Handles the abnormal sequence: @@ -553,6 +570,9 @@ handle_event(_, _Event, {init_error,Error}, _) -> %% <-SYNACK %% ACK-> %% RST-> + ?call_disconnectfun_and_log_cond("Protocol Error", + "TCP connenction to server was prematurely closed by the client", + StateName, D), {stop, {shutdown,"TCP connenction to server was prematurely closed by the client"}}; OtherError -> @@ -561,7 +581,7 @@ handle_event(_, _Event, {init_error,Error}, _) -> %%% ######## {hello, client|server} #### %% The very first event that is sent when the we are set as controlling process of Socket -handle_event(_, socket_control, {hello,_}, D) -> +handle_event(_, socket_control, {hello,_}=StateName, D) -> VsnMsg = ssh_transport:hello_version_msg(string_version(D#data.ssh_params)), send_bytes(VsnMsg, D), case inet:getopts(Socket=D#data.socket, [recbuf]) of @@ -576,10 +596,13 @@ handle_event(_, socket_control, {hello,_}, D) -> {keep_state, D#data{inet_initial_recbuf_size=Size}}; Other -> + ?call_disconnectfun_and_log_cond("Option return", + io_lib:format("Unexpected getopts return:~n ~p",[Other]), + StateName, D), {stop, {shutdown,{unexpected_getopts_return, Other}}} end; -handle_event(_, {info_line,_Line}, {hello,Role}, D) -> +handle_event(_, {info_line,_Line}, {hello,Role}=StateName, D) -> case Role of client -> %% The server may send info lines to the client before the version_exchange @@ -590,28 +613,33 @@ handle_event(_, {info_line,_Line}, {hello,Role}, D) -> %% But the client may NOT send them to the server. Openssh answers with cleartext, %% and so do we send_bytes("Protocol mismatch.", D), + ?call_disconnectfun_and_log_cond("Protocol mismatch.", + "Protocol mismatch in version exchange. Client sent info lines.", + StateName, D), {stop, {shutdown,"Protocol mismatch in version exchange. Client sent info lines."}} end; -handle_event(_, {version_exchange,Version}, {hello,Role}, D) -> +handle_event(_, {version_exchange,Version}, {hello,Role}, D0) -> {NumVsn, StrVsn} = ssh_transport:handle_hello_version(Version), - case handle_version(NumVsn, StrVsn, D#data.ssh_params) of + case handle_version(NumVsn, StrVsn, D0#data.ssh_params) of {ok, Ssh1} -> %% Since the hello part is finnished correctly, we set the %% socket to the packet handling mode (including recbuf size): - inet:setopts(D#data.socket, [{packet,0}, + inet:setopts(D0#data.socket, [{packet,0}, {mode,binary}, {active, once}, - {recbuf, D#data.inet_initial_recbuf_size}]), + {recbuf, D0#data.inet_initial_recbuf_size}]), {KeyInitMsg, SshPacket, Ssh} = ssh_transport:key_exchange_init_msg(Ssh1), - send_bytes(SshPacket, D), - {next_state, {kexinit,Role,init}, D#data{ssh_params = Ssh, + send_bytes(SshPacket, D0), + {next_state, {kexinit,Role,init}, D0#data{ssh_params = Ssh, key_exchange_init_msg = KeyInitMsg}}; not_supported -> - disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_VERSION_NOT_SUPPORTED, - description = ["Protocol version ",StrVsn," not supported"]}, - {next_state, {hello,Role}, D}) + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_VERSION_NOT_SUPPORTED, + io_lib:format("Offending version is ~p",[string:chomp(Version)]), + {hello,Role}, + D0), + {stop, Shutdown, D} end; @@ -757,18 +785,20 @@ handle_event(internal, Msg, {ext_info,Role,_ReNegFlag}, D) when is_tuple(Msg) -> %%% ######## {service_request, client|server} #### -handle_event(_, Msg = #ssh_msg_service_request{name=ServiceName}, StateName = {service_request,server}, D) -> +handle_event(_, Msg = #ssh_msg_service_request{name=ServiceName}, StateName = {service_request,server}, D0) -> case ServiceName of "ssh-userauth" -> - Ssh0 = #ssh{session_id=SessionId} = D#data.ssh_params, + Ssh0 = #ssh{session_id=SessionId} = D0#data.ssh_params, {ok, {Reply, Ssh}} = ssh_auth:handle_userauth_request(Msg, SessionId, Ssh0), - send_bytes(Reply, D), - {next_state, {userauth,server}, D#data{ssh_params = Ssh}}; + send_bytes(Reply, D0), + {next_state, {userauth,server}, D0#data{ssh_params = Ssh}}; _ -> - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "Unknown service"}, - StateName, D) + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + io_lib:format("Unknown service: ~p",[ServiceName]), + StateName, D0), + {stop, Shutdown, D} end; handle_event(_, #ssh_msg_service_accept{name = "ssh-userauth"}, {service_request,client}, @@ -784,15 +814,15 @@ handle_event(_, #ssh_msg_service_accept{name = "ssh-userauth"}, {service_request handle_event(_, Msg = #ssh_msg_userauth_request{service = ServiceName, method = Method}, StateName = {userauth,server}, - D = #data{ssh_params=Ssh0}) -> + D0 = #data{ssh_params=Ssh0}) -> case {ServiceName, Ssh0#ssh.service, Method} of {"ssh-connection", "ssh-connection", "none"} -> %% Probably the very first userauth_request but we deny unauthorized login {not_authorized, _, {Reply,Ssh}} = ssh_auth:handle_userauth_request(Msg, Ssh0#ssh.session_id, Ssh0), - send_bytes(Reply, D), - {keep_state, D#data{ssh_params = Ssh}}; + send_bytes(Reply, D0), + {keep_state, D0#data{ssh_params = Ssh}}; {"ssh-connection", "ssh-connection", Method} -> %% Userauth request with a method like "password" or so @@ -801,20 +831,20 @@ handle_event(_, %% Yepp! we support this method case ssh_auth:handle_userauth_request(Msg, Ssh0#ssh.session_id, Ssh0) of {authorized, User, {Reply, Ssh}} -> - send_bytes(Reply, D), - D#data.starter ! ssh_connected, - connected_fun(User, Method, D), + send_bytes(Reply, D0), + D0#data.starter ! ssh_connected, + connected_fun(User, Method, D0), {next_state, {connected,server}, - D#data{auth_user = User, + D0#data{auth_user = User, ssh_params = Ssh#ssh{authenticated = true}}}; {not_authorized, {User, Reason}, {Reply, Ssh}} when Method == "keyboard-interactive" -> - retry_fun(User, Reason, D), - send_bytes(Reply, D), - {next_state, {userauth_keyboard_interactive,server}, D#data{ssh_params = Ssh}}; + retry_fun(User, Reason, D0), + send_bytes(Reply, D0), + {next_state, {userauth_keyboard_interactive,server}, D0#data{ssh_params = Ssh}}; {not_authorized, {User, Reason}, {Reply, Ssh}} -> - retry_fun(User, Reason, D), - send_bytes(Reply, D), - {keep_state, D#data{ssh_params = Ssh}} + retry_fun(User, Reason, D0), + send_bytes(Reply, D0), + {keep_state, D0#data{ssh_params = Ssh}} end; false -> %% No we do not support this method (=/= none) @@ -828,9 +858,11 @@ handle_event(_, %% {ServiceName, Expected, Method} when Expected =/= ServiceName -> Do what? {ServiceName, _, _} when ServiceName =/= "ssh-connection" -> - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "Unknown service"}, - StateName, D) + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + io_lib:format("Unknown service: ~p",[ServiceName]), + StateName, D0), + {stop, Shutdown, D} end; %%---- userauth success to client @@ -846,14 +878,14 @@ handle_event(_, #ssh_msg_userauth_success{}, {userauth,client}, D=#data{ssh_para %%---- userauth failure response to client handle_event(_, #ssh_msg_userauth_failure{}, {userauth,client}=StateName, - D = #data{ssh_params = #ssh{userauth_methods = []}}) -> - Msg = #ssh_msg_disconnect{code = ?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE, - description = "Unable to connect using the available" - " authentication methods"}, - disconnect(Msg, StateName, D); - + #data{ssh_params = #ssh{userauth_methods = []}} = D0) -> + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE, + io_lib:format("User auth failed for: ~p",[D0#data.auth_user]), + StateName, D0), + {stop, Shutdown, D}; handle_event(_, #ssh_msg_userauth_failure{authentications = Methods}, StateName={userauth,client}, - D = #data{ssh_params = Ssh0}) -> + D0 = #data{ssh_params = Ssh0}) -> %% The prefered authentication method failed try next method Ssh1 = case Ssh0#ssh.userauth_methods of none -> @@ -864,15 +896,18 @@ handle_event(_, #ssh_msg_userauth_failure{authentications = Methods}, StateName= Ssh0 end, case ssh_auth:userauth_request_msg(Ssh1) of - {disconnect, DisconnectMsg, {Msg, Ssh}} -> - send_bytes(Msg, D), - disconnect(DisconnectMsg, StateName, D#data{ssh_params = Ssh}); + {send_disconnect, Code, Ssh} -> + {Shutdown, D} = + ?send_disconnect(Code, + io_lib:format("User auth failed for: ~p",[D0#data.auth_user]), + StateName, D0#data{ssh_params = Ssh}), + {stop, Shutdown, D}; {"keyboard-interactive", {Msg, Ssh}} -> - send_bytes(Msg, D), - {next_state, {userauth_keyboard_interactive,client}, D#data{ssh_params = Ssh}}; + send_bytes(Msg, D0), + {next_state, {userauth_keyboard_interactive,client}, D0#data{ssh_params = Ssh}}; {_Method, {Msg, Ssh}} -> - send_bytes(Msg, D), - {keep_state, D#data{ssh_params = Ssh}} + send_bytes(Msg, D0), + {keep_state, D0#data{ssh_params = Ssh}} end; %%---- banner to client @@ -966,7 +1001,7 @@ handle_event(_, #ssh_msg_disconnect{description=Desc} = Msg, StateName, D0) -> {disconnect, _, RepliesCon} = ssh_connection:handle_msg(Msg, D0#data.connection_state, role(StateName)), {Actions,D} = send_replies(RepliesCon, D0), - disconnect_fun(Desc, D), + disconnect_fun("Received disconnect: "++Desc, D), {stop_and_reply, {shutdown,Desc}, Actions, D}; handle_event(_, #ssh_msg_ignore{}, _, _) -> @@ -1288,29 +1323,32 @@ handle_event(info, {Proto, Sock, NewData}, StateName, D0 = #data{socket = Sock, D0#data.ssh_params) of {packet_decrypted, DecryptedBytes, EncryptedDataRest, Ssh1} -> - D = D0#data{ssh_params = + D1 = D0#data{ssh_params = Ssh1#ssh{recv_sequence = ssh_transport:next_seqnum(Ssh1#ssh.recv_sequence)}, decrypted_data_buffer = <<>>, undecrypted_packet_length = undefined, encrypted_data_buffer = EncryptedDataRest}, try - ssh_message:decode(set_kex_overload_prefix(DecryptedBytes,D)) + ssh_message:decode(set_kex_overload_prefix(DecryptedBytes,D1)) of Msg = #ssh_msg_kexinit{} -> - {keep_state, D, [{next_event, internal, prepare_next_packet}, + {keep_state, D1, [{next_event, internal, prepare_next_packet}, {next_event, internal, {Msg,DecryptedBytes}} ]}; Msg -> - {keep_state, D, [{next_event, internal, prepare_next_packet}, + {keep_state, D1, [{next_event, internal, prepare_next_packet}, {next_event, internal, Msg} ]} catch - _C:_E -> - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "Bad packet"}, - StateName, D) + C:E -> + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, + io_lib:format("Bad packet: Decrypted, but can't decode~n~p:~p~n~p", + [C,E,erlang:get_stacktrace()]), + StateName, D1), + {stop, Shutdown, D} end; - + {get_more, DecryptedBytes, EncryptedDataRest, RemainingSshPacketLen, Ssh1} -> %% Here we know that there are not enough bytes in %% EncryptedDataRest to use. We must wait for more. @@ -1321,19 +1359,26 @@ handle_event(info, {Proto, Sock, NewData}, StateName, D0 = #data{socket = Sock, ssh_params = Ssh1}}; {bad_mac, Ssh1} -> - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "Bad packet"}, - StateName, D0#data{ssh_params=Ssh1}); - - {error, {exceeds_max_size,_PacketLen}} -> - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "Bad packet"}, - StateName, D0) + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, + "Bad packet: bad mac", + StateName, D0#data{ssh_params=Ssh1}), + {stop, Shutdown, D}; + + {error, {exceeds_max_size,PacketLen}} -> + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, + io_lib:format("Bad packet: Size (~p bytes) exceeds max size", + [PacketLen]), + StateName, D0), + {stop, Shutdown, D} catch - _C:_E -> - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "Bad packet"}, - StateName, D0) + C:E -> + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, + io_lib:format("Bad packet: Couldn't decrypt~n~p:~p~n~p",[C,E,erlang:get_stacktrace()]), + StateName, D0), + {stop, Shutdown, D} end; @@ -1349,15 +1394,13 @@ handle_event(internal, prepare_next_packet, _, D) -> inet:setopts(D#data.socket, [{active, once}]), keep_state_and_data; -handle_event(info, {CloseTag,Socket}, StateName, - D = #data{socket = Socket, - transport_close_tag = CloseTag}) -> - %% Simulate a disconnect from the peer - handle_event(info, - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_BY_APPLICATION, - description = "Connection closed"}, - StateName, - D); +handle_event(info, {CloseTag,Socket}, _StateName, + D0 = #data{socket = Socket, + transport_close_tag = CloseTag, + connection_state = C0}) -> + {Repls, D} = send_replies(ssh_connection:handle_stop(C0), D0), + disconnect_fun("Received a transport close", D), + {stop_and_reply, {shutdown,"Connection closed"}, Repls, D}; handle_event(info, {timeout, {_, From} = Request}, _, #data{connection_state = #connection{requests = Requests} = C0} = D) -> @@ -1423,25 +1466,26 @@ handle_event(info, UnexpectedMessage, StateName, D = #data{ssh_params = Ssh}) -> keep_state_and_data end; -handle_event(internal, {disconnect,Msg,_Reason}, StateName, D) -> - disconnect(Msg, StateName, D); +handle_event(internal, {send_disconnect,Code,DetailedText,Module,Line}, StateName, D0) -> + {Shutdown, D} = + send_disconnect(Code, DetailedText, Module, Line, StateName, D0), + {stop, Shutdown, D}; handle_event(_Type, _Msg, {ext_info,Role,_ReNegFlag}, D) -> %% If something else arrives, goto next state and handle the event in that one {next_state, {connected,Role}, D, [postpone]}; -handle_event(Type, Ev, StateName, D) -> - Descr = +handle_event(Type, Ev, StateName, D0) -> + Details = case catch atom_to_list(element(1,Ev)) of "ssh_msg_" ++_ when Type==internal -> -%% "Message in wrong state"; lists:flatten(io_lib:format("Message ~p in wrong state (~p)", [element(1,Ev), StateName])); _ -> - "Internal error" + io_lib:format("Unhandled event in state ~p:~n~p", [StateName,Ev]) end, - disconnect(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = Descr}, - StateName, D). + {Shutdown, D} = + ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D0), + {stop, Shutdown, D}. %%-------------------------------------------------------------------- @@ -1452,39 +1496,49 @@ handle_event(Type, Ev, StateName, D) -> %% . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . -terminate(normal, StateName, State) -> - stop_subsystem(State), - close_transport(State); +terminate(normal, _StateName, D) -> + stop_subsystem(D), + close_transport(D); + +terminate({shutdown,"Connection closed"}, _StateName, D) -> + %% Normal: terminated by a sent by peer + stop_subsystem(D), + close_transport(D); -terminate({shutdown,{init,Reason}}, StateName, State) -> - error_logger:info_report(io_lib:format("Erlang ssh in connection handler init: ~p~n",[Reason])), - stop_subsystem(State), - close_transport(State); +terminate({shutdown,{init,Reason}}, StateName, D) -> + %% Error in initiation. "This error should not occur". + log(error, D, io_lib:format("Shutdown in init (StateName=~p): ~p~n",[StateName,Reason])), + stop_subsystem(D), + close_transport(D); -terminate(shutdown, StateName, State0) -> +terminate({shutdown,_R}, _StateName, D) -> + %% Internal termination, usually already reported via ?send_disconnect resulting in a log entry + stop_subsystem(D), + close_transport(D); + +terminate(shutdown, _StateName, D0) -> %% Terminated by supervisor - State = send_msg(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_BY_APPLICATION, - description = "Application shutdown"}, - State0), - close_transport(State); - -terminate({shutdown,_R}, StateName, State) -> - %% Internal termination - stop_subsystem(State), - close_transport(State); - -terminate(kill, StateName, State) -> - stop_subsystem(State), - close_transport(State); - -terminate(Reason, StateName, State0) -> - %% Others, e.g undef, {badmatch,_} - log_error(Reason), - State = send_msg(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_BY_APPLICATION, - description = "Internal error"}, - State0), - stop_subsystem(State), - close_transport(State). + %% Use send_msg directly instead of ?send_disconnect to avoid filling the log + D = send_msg(#ssh_msg_disconnect{code = ?SSH_DISCONNECT_BY_APPLICATION, + description = "Terminated (shutdown) by supervisor"}, + D0), + stop_subsystem(D), + close_transport(D); + +terminate(kill, _StateName, D) -> + %% Got a kill signal + stop_subsystem(D), + close_transport(D); + +terminate(Reason, StateName, D0) -> + %% Others, e.g undef, {badmatch,_}, ... + log(error, D0, Reason), + {_ShutdownReason, D} = ?send_disconnect(?SSH_DISCONNECT_BY_APPLICATION, + "Internal error", + io_lib:format("Reason: ~p",[Reason]), + StateName, D0), + stop_subsystem(D), + close_transport(D). %%-------------------------------------------------------------------- @@ -1493,36 +1547,41 @@ terminate(Reason, StateName, State0) -> format_status(normal, [_, _StateName, D]) -> [{data, [{"State", D}]}]; format_status(terminate, [_, _StateName, D]) -> - DataPropList0 = fmt_stat_rec(record_info(fields, data), D, - [decrypted_data_buffer, - encrypted_data_buffer, - key_exchange_init_msg, - user_passwords, - opts, - inet_initial_recbuf_size]), - SshPropList = fmt_stat_rec(record_info(fields, ssh), D#data.ssh_params, - [c_keyinit, - s_keyinit, - send_mac_key, - send_mac_size, - recv_mac_key, - recv_mac_size, - encrypt_keys, - encrypt_ctx, - decrypt_keys, - decrypt_ctx, - compress_ctx, - decompress_ctx, - shared_secret, - exchanged_hash, - session_id, - keyex_key, - keyex_info, - available_host_keys]), - DataPropList = lists:keyreplace(ssh_params, 1, DataPropList0, - {ssh_params,SshPropList}), - [{data, [{"State", DataPropList}]}]. - + [{data, [{"State", state_data2proplist(D)}]}]. + + +state_data2proplist(D) -> + DataPropList0 = + fmt_stat_rec(record_info(fields, data), D, + [decrypted_data_buffer, + encrypted_data_buffer, + key_exchange_init_msg, + user_passwords, + opts, + inet_initial_recbuf_size]), + SshPropList = + fmt_stat_rec(record_info(fields, ssh), D#data.ssh_params, + [c_keyinit, + s_keyinit, + send_mac_key, + send_mac_size, + recv_mac_key, + recv_mac_size, + encrypt_keys, + encrypt_ctx, + decrypt_keys, + decrypt_ctx, + compress_ctx, + decompress_ctx, + shared_secret, + exchanged_hash, + session_id, + keyex_key, + keyex_info, + available_host_keys]), + lists:keyreplace(ssh_params, 1, DataPropList0, + {ssh_params,SshPropList}). + fmt_stat_rec(FieldNames, Rec, Exclude) -> Values = tl(tuple_to_list(Rec)), @@ -1847,11 +1906,49 @@ new_channel_id(#data{connection_state = #connection{channel_id_seed = Id} = Connection#connection{channel_id_seed = Id + 1}}}. %%%---------------------------------------------------------------- -%% %%% This server/client has decided to disconnect via the state machine: -disconnect(Msg=#ssh_msg_disconnect{description=Description}, _StateName, State0) -> - State = send_msg(Msg, State0), - disconnect_fun(Description, State), - {stop, {shutdown,Description}, State}. +%%% This server/client has decided to disconnect via the state machine: +%%% The unused arguments are for debugging. + +send_disconnect(Code, DetailedText, Module, Line, StateName, D) -> + send_disconnect(Code, default_text(Code), DetailedText, Module, Line, StateName, D). + +send_disconnect(Code, Reason, DetailedText, Module, Line, StateName, D0) -> + Msg = #ssh_msg_disconnect{code = Code, + description = Reason}, + D = send_msg(Msg, D0), + LogMsg = io_lib:format("Disconnects with code = ~p [RFC4253 11.1]: ~s",[Code,Reason]), + call_disconnectfun_and_log_cond(LogMsg, DetailedText, Module, Line, StateName, D), + {{shutdown,Reason}, D}. + +call_disconnectfun_and_log_cond(LogMsg, DetailedText, Module, Line, StateName, D) -> + case disconnect_fun(LogMsg, D) of + void -> + log(info, D, + io_lib:format("~s~n" + "State = ~p~n" + "Module = ~p, Line = ~p.~n" + "Details:~n ~s~n", + [LogMsg, StateName, Module, Line, DetailedText])); + _ -> + ok + end. + + +default_text(?SSH_DISCONNECT_HOST_NOT_ALLOWED_TO_CONNECT) -> "Host not allowed to connect"; +default_text(?SSH_DISCONNECT_PROTOCOL_ERROR) -> "Protocol error"; +default_text(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED) -> "Key exchange failed"; +default_text(?SSH_DISCONNECT_RESERVED) -> "Reserved"; +default_text(?SSH_DISCONNECT_MAC_ERROR) -> "Mac error"; +default_text(?SSH_DISCONNECT_COMPRESSION_ERROR) -> "Compression error"; +default_text(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE) -> "Service not available"; +default_text(?SSH_DISCONNECT_PROTOCOL_VERSION_NOT_SUPPORTED) -> "Protocol version not supported"; +default_text(?SSH_DISCONNECT_HOST_KEY_NOT_VERIFIABLE) -> "Host key not verifiable"; +default_text(?SSH_DISCONNECT_CONNECTION_LOST) -> "Connection lost"; +default_text(?SSH_DISCONNECT_BY_APPLICATION) -> "By application"; +default_text(?SSH_DISCONNECT_TOO_MANY_CONNECTIONS) -> "Too many connections"; +default_text(?SSH_DISCONNECT_AUTH_CANCELLED_BY_USER) -> "Auth cancelled by user"; +default_text(?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE) -> "Unable to connect using the available authentication methods"; +default_text(?SSH_DISCONNECT_ILLEGAL_USER_NAME) -> "Illegal user name". %%%---------------------------------------------------------------- counterpart_versions(NumVsn, StrVsn, #ssh{role = server} = Ssh) -> @@ -1864,8 +1961,7 @@ conn_info(client_version, #data{ssh_params=S}) -> {S#ssh.c_vsn, S#ssh.c_version} conn_info(server_version, #data{ssh_params=S}) -> {S#ssh.s_vsn, S#ssh.s_version}; conn_info(peer, #data{ssh_params=S}) -> S#ssh.peer; conn_info(user, D) -> D#data.auth_user; -conn_info(sockname, D) -> {ok, SockName} = inet:sockname(D#data.socket), - SockName; +conn_info(sockname, #data{ssh_params=S}) -> S#ssh.local; %% dbg options ( = not documented): conn_info(socket, D) -> D#data.socket; conn_info(chan_ids, D) -> @@ -1896,13 +1992,43 @@ fold_keys(Keys, Fun, Extra) -> end, [], Keys). %%%---------------------------------------------------------------- -log_error(Reason) -> - Report = io_lib:format("Erlang ssh connection handler failed with reason:~n" - " ~p~n" - "Stacktrace:~n" - " ~p~n", - [Reason, erlang:get_stacktrace()]), - error_logger:error_report(Report). +log(Tag, D, Reason) -> + case atom_to_list(Tag) of % Dialyzer-technical reasons... + "error" -> do_log(error_msg, Reason, D); + "warning" -> do_log(warning_msg, Reason, D); + "info" -> do_log(info_msg, Reason, D) + end. + +do_log(F, Reason, #data{ssh_params = #ssh{role = Role} = S + }) -> + VSN = + case application:get_key(ssh,vsn) of + {ok,Vsn} -> Vsn; + undefined -> "" + end, + PeerVersion = + case Role of + server -> S#ssh.c_version; + client -> S#ssh.s_version + end, + CryptoInfo = + try + [{_,_,CI}] = crypto:info_lib(), + <<"(",CI/binary,")">> + catch + _:_ -> "" + end, + Other = + case Role of + server -> "Client"; + client -> "Server" + end, + error_logger:F("Erlang SSH ~p ~s ~s.~n" + "~s: ~p~n" + "~s~n", + [Role, VSN, CryptoInfo, + Other, PeerVersion, + Reason]). %%%---------------------------------------------------------------- not_connected_filter({connection_reply, _Data}) -> true; @@ -1944,7 +2070,7 @@ get_repl(X, Acc) -> %%%---------------------------------------------------------------- -define(CALL_FUN(Key,D), catch (?GET_OPT(Key, (D#data.ssh_params)#ssh.opts)) ). -disconnect_fun({disconnect,Msg}, D) -> ?CALL_FUN(disconnectfun,D)(Msg); +%%disconnect_fun({disconnect,Msg}, D) -> ?CALL_FUN(disconnectfun,D)(Msg); disconnect_fun(Reason, D) -> ?CALL_FUN(disconnectfun,D)(Reason). unexpected_fun(UnexpectedMessage, #data{ssh_params = #ssh{peer = {_,Peer} }} = D) -> @@ -2099,3 +2225,137 @@ update_inet_buffers(Socket) -> catch _:_ -> ok end. + +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [terminate, disconnect, connections, connection_events]; + +dbg_trace(flags, connections, A) -> [c] ++ dbg_trace(flags, terminate, A); +dbg_trace(on, connections, A) -> dbg:tp(?MODULE, init_connection_handler, 3, x), + dbg_trace(on, terminate, A); +dbg_trace(off, connections, A) -> dbg:ctpg(?MODULE, init_connection_handler, 3), + dbg_trace(off, terminate, A); +dbg_trace(format, connections, {call, {?MODULE,init_connection_handler, [Role, Sock, Opts]}}) -> + DefaultOpts = ssh_options:handle_options(Role,[]), + ExcludedKeys = [internal_options, user_options], + NonDefaultOpts = + maps:filter(fun(K,V) -> + case lists:member(K,ExcludedKeys) of + true -> + false; + false -> + V =/= (catch maps:get(K,DefaultOpts)) + end + end, + Opts), + {ok, {IPp,Portp}} = inet:peername(Sock), + {ok, {IPs,Ports}} = inet:sockname(Sock), + [io_lib:format("Starting ~p connection:\n",[Role]), + io_lib:format("Socket = ~p, Peer = ~s:~p, Local = ~s:~p,~n" + "Non-default options:~n~p", + [Sock,inet:ntoa(IPp),Portp,inet:ntoa(IPs),Ports, + NonDefaultOpts]) + ]; +dbg_trace(format, connections, F) -> + dbg_trace(format, terminate, F); + +dbg_trace(flags, connection_events, _) -> [c]; +dbg_trace(on, connection_events, _) -> dbg:tp(?MODULE, handle_event, 4, x); +dbg_trace(off, connection_events, _) -> dbg:ctpg(?MODULE, handle_event, 4); +dbg_trace(format, connection_events, {call, {?MODULE,handle_event, [EventType, EventContent, State, _Data]}}) -> + ["Connection event\n", + io_lib:format("EventType: ~p~nEventContent: ~p~nState: ~p~n", [EventType, EventContent, State]) + ]; +dbg_trace(format, connection_events, {return_from, {?MODULE,handle_event,4}, Ret}) -> + ["Connection event result\n", + io_lib:format("~p~n", [event_handler_result(Ret)]) + ]; + +dbg_trace(flags, terminate, _) -> [c]; +dbg_trace(on, terminate, _) -> dbg:tp(?MODULE, terminate, 3, x); +dbg_trace(off, terminate, _) -> dbg:ctpg(?MODULE, terminate, 3); +dbg_trace(format, terminate, {call, {?MODULE,terminate, [Reason, StateName, D]}}) -> + ExtraInfo = + try + {conn_info(peer,D), + conn_info(user,D), + conn_info(sockname,D)} + of + {{_,{IPp,Portp}}, Usr, {IPs,Ports}} when is_tuple(IPp), is_tuple(IPs), + is_integer(Portp), is_integer(Ports) -> + io_lib:format("Peer=~s:~p, Local=~s:~p, User=~p", + [inet:ntoa(IPp),Portp,inet:ntoa(IPs),Ports,Usr]); + {Peer,Usr,Sockname} -> + io_lib:format("Peer=~p, Local=~p, User=~p",[Peer,Sockname,Usr]) + catch + _:_ -> + "" + end, + if + Reason == normal ; + Reason == shutdown ; + element(1,Reason) == shutdown + -> + ["Connection Terminating:\n", + io_lib:format("Reason: ~p, StateName: ~p~n~s", [Reason, StateName, ExtraInfo]) + ]; + + true -> + ["Connection Terminating:\n", + io_lib:format("Reason: ~p, StateName: ~p~n~s~nStateData = ~p", + [Reason, StateName, ExtraInfo, state_data2proplist(D)]) + ] + end; + +dbg_trace(flags, disconnect, _) -> [c]; +dbg_trace(on, disconnect, _) -> dbg:tpl(?MODULE, send_disconnect, 7, x); +dbg_trace(off, disconnect, _) -> dbg:ctpl(?MODULE, send_disconnect, 7); +dbg_trace(format, disconnect, {call,{?MODULE,send_disconnect, + [Code, Reason, DetailedText, Module, Line, StateName, _D]}}) -> + ["Disconnecting:\n", + io_lib:format(" Module = ~p, Line = ~p, StateName = ~p,~n" + " Code = ~p, Reason = ~p,~n" + " DetailedText =~n" + " ~p", + [Module, Line, StateName, Code, Reason, lists:flatten(DetailedText)]) + ]. + + +event_handler_result({next_state, NextState, _NewData}) -> + {next_state, NextState, "#data{}"}; +event_handler_result({next_state, NextState, _NewData, Actions}) -> + {next_state, NextState, "#data{}", Actions}; +event_handler_result(R) -> + state_callback_result(R). + +state_callback_result({keep_state, _NewData}) -> + {keep_state, "#data{}"}; +state_callback_result({keep_state, _NewData, Actions}) -> + {keep_state, "#data{}", Actions}; +state_callback_result(keep_state_and_data) -> + keep_state_and_data; +state_callback_result({keep_state_and_data, Actions}) -> + {keep_state_and_data, Actions}; +state_callback_result({repeat_state, _NewData}) -> + {repeat_state, "#data{}"}; +state_callback_result({repeat_state, _NewData, Actions}) -> + {repeat_state, "#data{}", Actions}; +state_callback_result(repeat_state_and_data) -> + repeat_state_and_data; +state_callback_result({repeat_state_and_data, Actions}) -> + {repeat_state_and_data, Actions}; +state_callback_result(stop) -> + stop; +state_callback_result({stop, Reason}) -> + {stop, Reason}; +state_callback_result({stop, Reason, _NewData}) -> + {stop, Reason, "#data{}"}; +state_callback_result({stop_and_reply, Reason, Replies}) -> + {stop_and_reply, Reason, Replies}; +state_callback_result({stop_and_reply, Reason, Replies, _NewData}) -> + {stop_and_reply, Reason, Replies, "#data{}"}; +state_callback_result(R) -> + R. diff --git a/lib/ssh/src/ssh_message.erl b/lib/ssh/src/ssh_message.erl index eb06f05a4a..a2251eab97 100644 --- a/lib/ssh/src/ssh_message.erl +++ b/lib/ssh/src/ssh_message.erl @@ -32,6 +32,8 @@ -export([encode/1, decode/1, decode_keyboard_interactive_prompts/2]). +-export([dbg_trace/3]). + -define('2bin'(X), (if is_binary(X) -> X; is_list(X) -> list_to_binary(X); X==undefined -> <<>> @@ -611,3 +613,86 @@ encode_signature({#'ECPoint'{}, {namedCurve,OID}}, _SigAlg, Signature) -> CurveName = public_key:oid2ssh_curvename(OID), <<?Ebinary(<<"ecdsa-sha2-",CurveName/binary>>), ?Ebinary(Signature)>>. +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [ssh_messages, raw_messages]; + +dbg_trace(flags, ssh_messages, _) -> [c]; +dbg_trace(on, ssh_messages, _) -> dbg:tp(?MODULE,encode,1,x), + dbg:tp(?MODULE,decode,1,x); +dbg_trace(off, ssh_messages, _) -> dbg:ctpg(?MODULE,encode,1), + dbg:ctpg(?MODULE,decode,1); + +dbg_trace(flags, raw_messages, A) -> dbg_trace(flags, ssh_messages, A); +dbg_trace(on, raw_messages, A) -> dbg_trace(on, ssh_messages, A); +dbg_trace(off, raw_messages, A) -> dbg_trace(off, ssh_messages, A); + +dbg_trace(format, ssh_messages, {call,{?MODULE,encode,[Msg]}}) -> + Name = string:to_upper(atom_to_list(element(1,Msg))), + ["Going to send ",Name,":\n", + wr_record(ssh_dbg:shrink_bin(Msg)) + ]; +dbg_trace(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)) + ]; + +dbg_trace(format, raw_messages, {call,{?MODULE,decode,[BytesPT]}}) -> + ["Received plain text bytes (shown after decryption):\n", + io_lib:format("~p",[BytesPT]) + ]; +dbg_trace(format, raw_messages, {return_from,{?MODULE,encode,1},BytesPT}) -> + ["Going to send plain text bytes (shown before encryption):\n", + io_lib:format("~p",[BytesPT]) + ]. + + +?wr_record(ssh_msg_disconnect); +?wr_record(ssh_msg_ignore); +?wr_record(ssh_msg_unimplemented); +?wr_record(ssh_msg_debug); +?wr_record(ssh_msg_service_request); +?wr_record(ssh_msg_service_accept); +?wr_record(ssh_msg_kexinit); +?wr_record(ssh_msg_kexdh_init); +?wr_record(ssh_msg_kexdh_reply); +?wr_record(ssh_msg_newkeys); +?wr_record(ssh_msg_ext_info); +?wr_record(ssh_msg_kex_dh_gex_request); +?wr_record(ssh_msg_kex_dh_gex_request_old); +?wr_record(ssh_msg_kex_dh_gex_group); +?wr_record(ssh_msg_kex_dh_gex_init); +?wr_record(ssh_msg_kex_dh_gex_reply); +?wr_record(ssh_msg_kex_ecdh_init); +?wr_record(ssh_msg_kex_ecdh_reply); + +?wr_record(ssh_msg_userauth_request); +?wr_record(ssh_msg_userauth_failure); +?wr_record(ssh_msg_userauth_success); +?wr_record(ssh_msg_userauth_banner); +?wr_record(ssh_msg_userauth_passwd_changereq); +?wr_record(ssh_msg_userauth_pk_ok); +?wr_record(ssh_msg_userauth_info_request); +?wr_record(ssh_msg_userauth_info_response); + +?wr_record(ssh_msg_global_request); +?wr_record(ssh_msg_request_success); +?wr_record(ssh_msg_request_failure); +?wr_record(ssh_msg_channel_open); +?wr_record(ssh_msg_channel_open_confirmation); +?wr_record(ssh_msg_channel_open_failure); +?wr_record(ssh_msg_channel_window_adjust); +?wr_record(ssh_msg_channel_data); +?wr_record(ssh_msg_channel_extended_data); +?wr_record(ssh_msg_channel_eof); +?wr_record(ssh_msg_channel_close); +?wr_record(ssh_msg_channel_request); +?wr_record(ssh_msg_channel_success); +?wr_record(ssh_msg_channel_failure); + +wr_record(R) -> io_lib:format('~p~n',[R]). + diff --git a/lib/ssh/src/ssh_no_io.erl b/lib/ssh/src/ssh_no_io.erl index 1da257ed99..25be0023e9 100644 --- a/lib/ssh/src/ssh_no_io.erl +++ b/lib/ssh/src/ssh_no_io.erl @@ -31,35 +31,24 @@ -spec yes_no(any(), any()) -> no_return(). yes_no(_, _) -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "User interaction is not allowed"}, - {no_io_allowed, yes_no}). + ?DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + "User interaction is not allowed"). -spec read_password(any(), any()) -> no_return(). read_password(_, _) -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "User interaction is not allowed"}, - {no_io_allowed, read_password}). - + ?DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + "User interaction is not allowed"). -spec read_line(any(), any()) -> no_return(). read_line(_, _) -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "User interaction is not allowed"}, - {no_io_allowed, read_line}). - + ?DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + "User interaction is not allowed"). -spec format(any(), any()) -> no_return(). format(_, _) -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - description = "User interaction is not allowed"}, - {no_io_allowed, format}). - + ?DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, + "User interaction is not allowed"). diff --git a/lib/ssh/src/ssh_sftp.erl b/lib/ssh/src/ssh_sftp.erl index 9e1229dc85..f00c0aed1f 100644 --- a/lib/ssh/src/ssh_sftp.erl +++ b/lib/ssh/src/ssh_sftp.erl @@ -52,6 +52,8 @@ %% TODO: Should be placed elsewhere ssh_sftpd should not call functions in ssh_sftp! -export([info_to_attr/1, attr_to_info/1]). +-export([dbg_trace/3]). + -record(state, { xf, @@ -1460,3 +1462,21 @@ format_channel_start_error({shutdown, Reason}) -> Reason; format_channel_start_error(Reason) -> Reason. + +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [terminate]; + +dbg_trace(flags, terminate, _) -> [c]; +dbg_trace(on, terminate, _) -> dbg:tp(?MODULE, terminate, 2, x); +dbg_trace(off, terminate, _) -> dbg:ctpg(?MODULE, terminate, 2); +dbg_trace(format, terminate, {call, {?MODULE,terminate, [Reason, State]}}) -> + ["Sftp Terminating:\n", + io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)]) + ]. + +?wr_record(state). + diff --git a/lib/ssh/src/ssh_sftpd.erl b/lib/ssh/src/ssh_sftpd.erl index 427edf01ab..26cf2cb665 100644 --- a/lib/ssh/src/ssh_sftpd.erl +++ b/lib/ssh/src/ssh_sftpd.erl @@ -38,6 +38,8 @@ -export([init/1, handle_ssh_msg/2, handle_msg/2, terminate/2]). +-export([dbg_trace/3]). + -record(state, { xf, % [{channel,ssh_xfer states}...] cwd, % current dir (on first connect) @@ -947,3 +949,20 @@ maybe_increase_recv_window(ConnectionManager, ChannelId, Options) -> Increment =< 0 -> do_nothing end. + +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [terminate]; + +dbg_trace(flags, terminate, _) -> [c]; +dbg_trace(on, terminate, _) -> dbg:tp(?MODULE, terminate, 2, x); +dbg_trace(off, terminate, _) -> dbg:ctpg(?MODULE, terminate, 2); +dbg_trace(format, terminate, {call, {?MODULE,terminate, [Reason, State]}}) -> + ["SftpD Terminating:\n", + io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)]) + ]. + +?wr_record(state). diff --git a/lib/ssh/src/ssh_shell.erl b/lib/ssh/src/ssh_shell.erl index 17224b6ef4..085534592d 100644 --- a/lib/ssh/src/ssh_shell.erl +++ b/lib/ssh/src/ssh_shell.erl @@ -22,6 +22,7 @@ -module(ssh_shell). +-include("ssh.hrl"). -include("ssh_connect.hrl"). %%% As this is an user interactive client it behaves like a daemon @@ -34,6 +35,8 @@ %% Spawn export -export([input_loop/2]). +-export([dbg_trace/3]). + -record(state, { io, %% Io process @@ -194,3 +197,20 @@ get_ancestors() -> A when is_list(A) -> A; _ -> [] end. + +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [terminate]; + +dbg_trace(flags, terminate, _) -> [c]; +dbg_trace(on, terminate, _) -> dbg:tp(?MODULE, terminate, 2, x); +dbg_trace(off, terminate, _) -> dbg:ctpg(?MODULE, terminate, 2); +dbg_trace(format, terminate, {call, {?MODULE,terminate, [Reason, State]}}) -> + ["Shell Terminating:\n", + io_lib:format("Reason: ~p,~nState:~n~s", [Reason, wr_record(State)]) + ]. + +?wr_record(state). diff --git a/lib/ssh/src/ssh_transport.erl b/lib/ssh/src/ssh_transport.erl index c221cf5905..f5bba9f824 100644 --- a/lib/ssh/src/ssh_transport.erl +++ b/lib/ssh/src/ssh_transport.erl @@ -53,6 +53,8 @@ valid_key_sha_alg/2, sha/1, sign/3, verify/5]). +-export([dbg_trace/3]). + %%% For test suites -export([pack/3, adjust_algs_for_peer_version/2]). -export([decompress/2, decrypt_blocks/3, is_valid_mac/3 ]). % FIXME: remove @@ -319,10 +321,11 @@ handle_kexinit_msg(#ssh_msg_kexinit{} = CounterPart, #ssh_msg_kexinit{} = Own, key_exchange_first_msg(Algos#alg.kex, Ssh#ssh{algorithms = Algos}) catch - _:_ -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Selection of key exchange algorithm failed"}) + Class:Error -> + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexinit failed in client: ~p:~p", + [Class,Error]) + ) end; handle_kexinit_msg(#ssh_msg_kexinit{} = CounterPart, #ssh_msg_kexinit{} = Own, @@ -335,10 +338,11 @@ handle_kexinit_msg(#ssh_msg_kexinit{} = CounterPart, #ssh_msg_kexinit{} = Own, Algos -> {ok, Ssh#ssh{algorithms = Algos}} catch - _:_ -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Selection of key exchange algorithm failed"}) + Class:Error -> + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexinit failed in server: ~p:~p", + [Class,Error]) + ) end. @@ -439,12 +443,10 @@ handle_kexdh_init(#ssh_msg_kexdh_init{e = E}, session_id = sid(Ssh1, H)}}; true -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, 'e' out of bounds"}, - {error,bad_e_from_peer} - ) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexdh init failed, received 'e' out of bounds~n E=~p~n P=~p", + [E,P]) + ) end. handle_kexdh_reply(#ssh_msg_kexdh_reply{public_host_key = PeerPubHostKey, @@ -464,20 +466,16 @@ handle_kexdh_reply(#ssh_msg_kexdh_reply{public_host_key = PeerPubHostKey, exchanged_hash = H, session_id = sid(Ssh, H)})}; Error -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed"}, - Error) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexdh init failed. Verify host key: ~p",[Error]) + ) end; true -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, 'f' out of bounds"}, - bad_f_from_peer - ) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexdh init failed, received 'f' out of bounds~n F=~p~n P=~p", + [F,P]) + ) end. @@ -501,11 +499,9 @@ handle_kex_dh_gex_request(#ssh_msg_kex_dh_gex_request{min = Min0, keyex_info = {Min0, Max0, NBits} }}; {error,_} -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "No possible diffie-hellman-group-exchange group found" - }) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("No possible diffie-hellman-group-exchange group found",[]) + ) end; handle_kex_dh_gex_request(#ssh_msg_kex_dh_gex_request_old{n = NBits}, @@ -535,20 +531,14 @@ handle_kex_dh_gex_request(#ssh_msg_kex_dh_gex_request_old{n = NBits}, keyex_info = {-1, -1, NBits} % flag for kex_hash calc }}; {error,_} -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "No possible diffie-hellman-group-exchange group found" - }) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("No possible diffie-hellman-group-exchange group found",[]) + ) end; handle_kex_dh_gex_request(_, _) -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, bad values in ssh_msg_kex_dh_gex_request"}, - bad_ssh_msg_kex_dh_gex_request). - + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + "Key exchange failed, bad values in ssh_msg_kex_dh_gex_request"). adjust_gex_min_max(Min0, Max0, Opts) -> {Min1, Max1} = ?GET_OPT(dh_gex_limits, Opts), @@ -558,11 +548,8 @@ adjust_gex_min_max(Min0, Max0, Opts) -> Min2 =< Max2 -> {Min2, Max2}; Max2 < Min2 -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "No possible diffie-hellman-group-exchange group possible" - }) + ?DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, + "No possible diffie-hellman-group-exchange group possible") end. @@ -600,18 +587,15 @@ handle_kex_dh_gex_init(#ssh_msg_kex_dh_gex_init{e = E}, session_id = sid(Ssh, H) }}; true -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, 'K' out of bounds"}, - bad_K) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + "Kexdh init failed, received 'k' out of bounds" + ) end; true -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, 'e' out of bounds"}, - bad_e_from_peer) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexdh gex init failed, received 'e' out of bounds~n E=~p~n P=~p", + [E,P]) + ) end. handle_kex_dh_gex_reply(#ssh_msg_kex_dh_gex_reply{public_host_key = PeerPubHostKey, @@ -634,28 +618,22 @@ handle_kex_dh_gex_reply(#ssh_msg_kex_dh_gex_reply{public_host_key = PeerPubHostK {ok, SshPacket, install_alg(snd, Ssh#ssh{shared_secret = ssh_bits:mpint(K), exchanged_hash = H, session_id = sid(Ssh, H)})}; - _Error -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed" - }) + Error -> + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexdh gex reply failed. Verify host key: ~p",[Error]) + ) end; true -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, 'K' out of bounds"}, - bad_K) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + "Kexdh gex init failed, 'K' out of bounds" + ) end; true -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed, 'f' out of bounds"}, - bad_f_from_peer - ) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Kexdh gex init failed, received 'f' out of bounds~n F=~p~n P=~p", + [F,P]) + ) end. %%%---------------------------------------------------------------- @@ -686,12 +664,11 @@ handle_kex_ecdh_init(#ssh_msg_kex_ecdh_init{q_c = PeerPublic}, exchanged_hash = H, session_id = sid(Ssh1, H)}} catch - _:_ -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Peer ECDH public key is invalid"}, - invalid_peer_public_key) + Class:Error -> + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("ECDH compute key failed in server: ~p:~p", + [Class,Error]) + ) end. handle_kex_ecdh_reply(#ssh_msg_kex_ecdh_reply{public_host_key = PeerPubHostKey, @@ -713,19 +690,16 @@ handle_kex_ecdh_reply(#ssh_msg_kex_ecdh_reply{public_host_key = PeerPubHostKey, exchanged_hash = H, session_id = sid(Ssh, H)})}; Error -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Key exchange failed"}, - Error) + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("ECDH reply failed. Verify host key: ~p",[Error]) + ) end catch - _:_ -> - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{ - code = ?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - description = "Peer ECDH public key is invalid"}, - invalid_peer_public_key) + Class:Error -> + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, + io_lib:format("Peer ECDH public key seem invalid: ~p:~p", + [Class,Error]) + ) end. @@ -735,11 +709,11 @@ handle_new_keys(#ssh_msg_newkeys{}, Ssh0) -> #ssh{} = Ssh -> {ok, Ssh} catch - _C:_Error -> %% TODO: Throw earlier .... - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = "Install alg failed" - }) + Class:Error -> %% TODO: Throw earlier ... + ?DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, + io_lib:format("Install alg failed: ~p:~p", + [Class,Error]) + ) end. @@ -1111,10 +1085,9 @@ select_all(CL, SL) when length(CL) + length(SL) < ?MAX_NUM_ALGORITHMS -> %% algorithms used by client and server (client pref) lists:map(fun(ALG) -> list_to_atom(ALG) end, (CL -- A)); select_all(CL, SL) -> - Err = lists:concat(["Received too many algorithms (",length(CL),"+",length(SL)," >= ",?MAX_NUM_ALGORITHMS,")."]), - ssh_connection_handler:disconnect( - #ssh_msg_disconnect{code = ?SSH_DISCONNECT_PROTOCOL_ERROR, - description = Err}). + Error = lists:concat(["Received too many algorithms (",length(CL),"+",length(SL)," >= ",?MAX_NUM_ALGORITHMS,")."]), + ?DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, + Error). select([], []) -> @@ -2037,3 +2010,40 @@ trim_tail(Str) -> lists:takewhile(fun(C) -> C=/=$\r andalso C=/=$\n end, Str). + +%%%################################################################ +%%%# +%%%# Tracing +%%%# + +dbg_trace(points, _, _) -> [alg, ssh_messages, raw_messages, hello]; + +dbg_trace(flags, hello, _) -> [c]; +dbg_trace(on, hello, _) -> dbg:tp(?MODULE,hello_version_msg,1,x), + dbg:tp(?MODULE,handle_hello_version,1,x); +dbg_trace(off, hello, _) -> dbg:ctpg(?MODULE,hello_version_msg,1), + dbg:ctpg(?MODULE,handle_hello_version,1); + +dbg_trace(C, raw_messages, A) -> dbg_trace(C, hello, A); +dbg_trace(C, ssh_messages, A) -> dbg_trace(C, hello, A); + +dbg_trace(flags, alg, _) -> [c]; +dbg_trace(on, alg, _) -> dbg:tpl(?MODULE,select_algorithm,4,x); +dbg_trace(off, alg, _) -> dbg:ctpl(?MODULE,select_algorithm,4); + + +dbg_trace(format, hello, {return_from,{?MODULE,hello_version_msg,1},Hello}) -> + ["Going to send hello message:\n", + Hello + ]; +dbg_trace(format, hello, {call,{?MODULE,handle_hello_version,[Hello]}}) -> + ["Received hello message:\n", + Hello + ]; + +dbg_trace(format, alg, {return_from,{?MODULE,select_algorithm,4},{ok,Alg}}) -> + ["Negotiated algorithms:\n", + wr_record(Alg) + ]. + +?wr_record(alg). diff --git a/lib/ssh/src/ssh_transport.hrl b/lib/ssh/src/ssh_transport.hrl index 87c3719514..7d5a4c153e 100644 --- a/lib/ssh/src/ssh_transport.hrl +++ b/lib/ssh/src/ssh_transport.hrl @@ -220,6 +220,9 @@ %% %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% +-define(DISCONNECT(Code, DetailedText), + ssh_connection_handler:disconnect(Code, DetailedText, ?MODULE, ?LINE)). + -define(SSH_DISCONNECT_HOST_NOT_ALLOWED_TO_CONNECT, 1). -define(SSH_DISCONNECT_PROTOCOL_ERROR, 2). -define(SSH_DISCONNECT_KEY_EXCHANGE_FAILED, 3). |