diff --git a/lib/ssh/src/ssh.hrl b/lib/ssh/src/ssh.hrl index 4353b8e68d02..d55626ab1132 100644 --- a/lib/ssh/src/ssh.hrl +++ b/lib/ssh/src/ssh.hrl @@ -1313,7 +1313,6 @@ Experimental options that should not to be used in products. -type mod_args() :: {Module::atom(), Args::list()} . -type mod_fun_args() :: {Module::atom(), Function::atom(), Args::list()} . - %% Records -record(address, {address, port, @@ -1469,6 +1468,6 @@ Experimental options that should not to be used in products. (fun() -> #{level := __Level} = logger:get_primary_config(), __Fun(__Level) - end)()). + end)()). -endif. % SSH_HRL defined diff --git a/lib/ssh/src/ssh_connection_handler.erl b/lib/ssh/src/ssh_connection_handler.erl index 304fa358d10f..eab241d27424 100644 --- a/lib/ssh/src/ssh_connection_handler.erl +++ b/lib/ssh/src/ssh_connection_handler.erl @@ -63,16 +63,16 @@ send_bytes/2, send_msg/2, send_eof/2, - send_disconnect/6, - send_disconnect/7, + send_disconnect/2, + send_disconnect/3, store/3, retrieve/2, info/1, info/2, connection_info/2, channel_info/3, - adjust_window/3, close/2, - disconnect/4, - get_print_info/1, + adjust_window/3, close/2, + disconnect/1, + get_print_info/1, set_sock_opts/2, get_sock_opts/2, prohibited_sock_option/1 ]). @@ -93,8 +93,13 @@ ssh_dbg_format/2, ssh_dbg_format/3]). --define(call_disconnectfun_and_log_cond(LogMsg, DetailedText, StateName, D), - call_disconnectfun_and_log_cond(LogMsg, DetailedText, ?MODULE, ?LINE, StateName, D)). +-define(CALL_DISCONNECTFUN_LOG_COND(LogMsg, Details, StateName, D), + call_disconnectfun_log_cond(#{log_msg => LogMsg, + details => Details, + module => ?MODULE, + line => ?LINE, + code => undefined, + state_name => StateName}, D)). %%==================================================================== %% Start / stop @@ -160,16 +165,11 @@ stop(ConnectionHandler)-> %%-------------------------------------------------------------------- %%% Some other module has decided to disconnect. - --spec disconnect(Code::integer(), Details::iodata(), - Module::atom(), Line::integer()) -> no_return(). -%% . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . - -% Preferable called with the macro ?DISCONNECT - -disconnect(Code, DetailedText, Module, Line) -> +% Preferably called with the macro ?DISCONNECT +-spec disconnect(DisconnectContext::map()) -> no_return(). +disconnect(DisconnectContext) -> throw({keep_state_and_data, - [{next_event, internal, {send_disconnect, Code, DetailedText, Module, Line}}]}). + [{next_event, internal, {send_disconnect, DisconnectContext}}]}). %%-------------------------------------------------------------------- %%% Open a channel in the connection to the peer, that is, do the ssh @@ -630,9 +630,9 @@ handle_event(internal, socket_ready, {hello,_}=StateName, #data{ssh_params = Ssh {keep_state, D#data{inet_initial_buffer_size=Size}, [{state_timeout,Time,no_hello_received}] }; Other -> - ?call_disconnectfun_and_log_cond("Option return", - io_lib:format("Unexpected getopts return:~n ~p",[Other]), - StateName, D), + LogMsg = "Option return", + Details = io_lib:format("Unexpected getopts return:~n ~p", [Other]), + ?CALL_DISCONNECTFUN_LOG_COND(LogMsg, Details, StateName, D), {stop, {shutdown,{unexpected_getopts_return, Other}}} end; @@ -646,12 +646,13 @@ handle_event(internal, {info_line,Line}, {hello,server}=StateName, D) -> %% But the client may NOT send them to the server. Openssh answers with cleartext, %% and so do we send_bytes("Protocol mismatch.", D), - Msg = io_lib:format("Protocol mismatch in version exchange. Client sent info lines.~n~s", - [ssh_dbg:hex_dump(Line, 64)]), - ?call_disconnectfun_and_log_cond("Protocol mismatch.", Msg, StateName, D), + LogMsg = "Protocol mismatch.", + Details = io_lib:format("Protocol mismatch in version exchange. Client sent info lines.~n~s", + [ssh_dbg:hex_dump(Line, 64)]), + ?CALL_DISCONNECTFUN_LOG_COND(LogMsg, Details, StateName, D), {stop, {shutdown,"Protocol mismatch in version exchange. Client sent info lines."}}; -handle_event(internal, {version_exchange,Version}, {hello,Role}, D0) -> +handle_event(internal, {version_exchange,Version}, {hello,Role}=StateName, D0) -> {NumVsn, StrVsn} = ssh_transport:handle_hello_version(Version), case handle_version(NumVsn, StrVsn, D0#data.ssh_params) of {ok, Ssh1} -> @@ -669,11 +670,10 @@ handle_event(internal, {version_exchange,Version}, {hello,Role}, D0) -> {next_state, {kexinit,Role,init}, D, {change_callback_module, ssh_fsm_kexinit}}; not_supported -> + Details = io_lib:format("Offending version is ~p",[string:chomp(Version)]), {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_VERSION_NOT_SUPPORTED, - io_lib:format("Offending version is ~p",[string:chomp(Version)]), - {hello,Role}, - D0), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_VERSION_NOT_SUPPORTED, Details, + StateName, D0), {stop, Shutdown, D} end; @@ -686,8 +686,8 @@ handle_event(state_timeout, no_hello_received, {hello,_Role}=StateName, D0 = #da (_) -> ["No HELLO received within hello_timeout"] end, - {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, ?SELECT_MSG(MsgFun), StateName, D0), + Details = ?SELECT_MSG(MsgFun), + {Shutdown, D} = ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D0), {stop, Shutdown, D}; @@ -703,12 +703,10 @@ handle_event(internal, Msg = #ssh_msg_service_request{name=ServiceName}, StateNa {ok, {Reply, Ssh}} = ssh_auth:handle_userauth_request(Msg, SessionId, Ssh0), D = send_msg(Reply, D0#data{ssh_params = Ssh}), {next_state, {userauth,server}, D, {change_callback_module,ssh_fsm_userauth_server}}; - _ -> + Details = io_lib:format("Unknown service: ~p",[ServiceName]), {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - io_lib:format("Unknown service: ~p",[ServiceName]), - StateName, D0), + ?SEND_DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, Details, StateName, D0), {stop, Shutdown, D} end; @@ -740,7 +738,9 @@ handle_event(internal, #ssh_msg_disconnect{description=Desc} = Msg, StateName, D {disconnect, _, RepliesCon} = ssh_connection:handle_msg(Msg, D0#data.connection_state, ?role(StateName), D0#data.ssh_params), {Actions,D} = send_replies(RepliesCon, D0), - disconnect_fun("Received disconnect: "++Desc, D), + DisconnectType = disconnect_received, + Details = "Received disconnect: " ++ Desc, + disconnect_fun(DisconnectType, Details, D), {stop_and_reply, {shutdown,Desc}, Actions, D}; handle_event(internal, #ssh_msg_ignore{}, _StateName, _) -> @@ -795,9 +795,9 @@ handle_event(internal, {conn_msg, Msg}, StateName, #data{connection_state = Conn catch Class:Error -> {Repls, D1} = send_replies(ssh_connection:handle_stop(Connection0), D0), - {Shutdown, D} = ?send_disconnect(?SSH_DISCONNECT_BY_APPLICATION, - io_lib:format("Internal error: ~p:~p",[Class,Error]), - StateName, D1), + Details = io_lib:format("Internal error: ~p:~p",[Class,Error]), + {Shutdown, D} = + ?SEND_DISCONNECT(?SSH_DISCONNECT_BY_APPLICATION, Details, StateName, D1), {stop_and_reply, Shutdown, Repls, D} end; @@ -849,7 +849,7 @@ handle_event({timeout, alive}, _, StateName, D = #data{ssh_params=Ssh}) -> handle_event({timeout, renegotiation_alive}, _, StateName, D) -> Details = "Renegotiation alive timeout reached.", - {Shutdown, D1} = ?send_disconnect(?SSH_DISCONNECT_CONNECTION_LOST, Details, StateName, D), + {Shutdown, D1} = ?SEND_DISCONNECT(?SSH_DISCONNECT_CONNECTION_LOST, Details, StateName, D), {stop, Shutdown, D1}; @@ -900,7 +900,7 @@ handle_event(cast, {reply_request,Resp,ChannelId}, StateName, D) when ?CONNECTED #channel{} -> Details = io_lib:format("Unhandled reply in state ~p:~n~p", [StateName,Resp]), {_Shutdown, D1} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D), {keep_state, D1}; undefined -> @@ -1182,19 +1182,16 @@ handle_event(info, {Proto, Sock, NewData}, StateName, encrypted_data_buffer = EncryptedDataRest}, try ssh_message:decode(set_kex_overload_prefix(DecryptedBytes,D2)) - of - #ssh_msg_kexinit{} = Msg -> - {keep_state, D2, [{next_event, internal, prepare_next_packet}, - {next_event, internal, {Msg,DecryptedBytes}} - ]}; - + of + #ssh_msg_kexinit{} = Msg -> + {keep_state, D2, [{next_event, internal, prepare_next_packet}, + {next_event, internal, {Msg,DecryptedBytes}}]}; #ssh_msg_global_request{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_request_success{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_request_failure{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_channel_open{} = Msg -> {keep_state, D2, [{{timeout, max_initial_idle_time}, cancel} | - ?CONNECTION_MSG(Msg) - ]}; + ?CONNECTION_MSG(Msg)]}; #ssh_msg_channel_open_confirmation{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_channel_open_failure{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_channel_window_adjust{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; @@ -1205,11 +1202,10 @@ handle_event(info, {Proto, Sock, NewData}, StateName, #ssh_msg_channel_request{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_channel_failure{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; #ssh_msg_channel_success{} = Msg -> {keep_state, D2, ?CONNECTION_MSG(Msg)}; - Msg -> {keep_state, D2, [{next_event, internal, prepare_next_packet}, {next_event, internal, Msg} - ]} + ]} catch Class:Reason0:Stacktrace -> Reason = ssh_lib:trim_reason(Reason0), @@ -1223,10 +1219,9 @@ handle_event(info, {Proto, Sock, NewData}, StateName, [Class, Reason], [{chars_limit, ssh_lib:max_log_len(SshParams)}]) end, + Details = ?SELECT_MSG(MsgFun), {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, - ?SELECT_MSG(MsgFun), - StateName, D2), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D2), {stop, Shutdown, D} end; @@ -1241,25 +1236,23 @@ handle_event(info, {Proto, Sock, NewData}, StateName, ssh_params = Ssh1}}; {bad_mac, Ssh1} -> + Details = "Bad packet: bad mac", {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, - "Bad packet: bad mac", + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D1#data{ssh_params=Ssh1}), {stop, Shutdown, D}; {error, {exceeds_max_size,PacketLen}} -> + Details = io_lib:format("Bad packet: Size (~p bytes) 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, D1), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D1), {stop, Shutdown, D}; {error, exceeds_max_decompressed_size} -> + Details = "Bad packet: Size after decompression exceeds max size", {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, - "Bad packet: Size after decompression exceeds max size", - StateName, D1), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D1), {stop, Shutdown, D} catch Class:Reason0:Stacktrace -> @@ -1274,9 +1267,9 @@ handle_event(info, {Proto, Sock, NewData}, StateName, [Class,Reason], [{chars_limit, ssh_lib:max_log_len(SshParams)}]) end, + Details = ?SELECT_MSG(MsgFun), {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, ?SELECT_MSG(MsgFun), - StateName, D1), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D1), {stop, Shutdown, D} end; @@ -1298,7 +1291,9 @@ handle_event(info, {CloseTag,Socket}, _StateName, transport_close_tag = CloseTag, connection_state = C0}) -> {Repls, D} = send_replies(ssh_connection:handle_stop(C0), D0), - disconnect_fun("Received a transport close", D), + DisconnectType = transport_close_received, + Details = "Received a transport close", + disconnect_fun(DisconnectType, Details, D), {stop_and_reply, {shutdown,"Connection closed"}, Repls, D}; handle_event(info, {timeout, {_, From} = Request}, _, @@ -1452,12 +1447,11 @@ handle_event(info, UnexpectedMessage, StateName, D = #data{ssh_params = Ssh}) -> keep_state_and_data end; -handle_event(internal, {send_disconnect,Code,DetailedText,Module,Line}, StateName, D0) -> - {Shutdown, D} = - send_disconnect(Code, DetailedText, Module, Line, StateName, D0), +handle_event(internal, {send_disconnect,DisconnectContext0}, StateName, D0) -> + DisconnectContext = maps:merge(DisconnectContext0, #{state_name => StateName}), + {Shutdown, D} = send_disconnect(DisconnectContext, D0), {stop, Shutdown, D}; - handle_event(enter, _OldState, State, D) -> %% Just skip {next_state, State, D}; @@ -1475,7 +1469,7 @@ handle_event(Type, Ev, StateName, D0) -> io_lib:format("Unhandled event in state ~p and type ~p:~n~p", [StateName,Type,Ev]) end, {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D0), + ?SEND_DISCONNECT(?SSH_DISCONNECT_PROTOCOL_ERROR, Details, StateName, D0), {stop, Shutdown, D}. @@ -1495,12 +1489,12 @@ terminate(normal, _StateName, D) -> close_transport(D); terminate({shutdown,_R}, _StateName, D) -> - %% Internal termination, usually already reported via ?send_disconnect resulting in a log entry + %% Internal termination, usually already reported via ?SEND_DISCONNECT resulting in a log entry close_transport(D); terminate(shutdown, _StateName, D0) -> %% Terminated by supervisor - %% Use send_msg directly instead of ?send_disconnect to avoid filling the log + %% 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), @@ -1509,10 +1503,10 @@ terminate(shutdown, _StateName, D0) -> 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), + DisconnectReason = "Internal error", + Details = io_lib:format("Reason: ~p",[Reason]), + {_ShutdownReason, D} = + ?SEND_DISCONNECT(?SSH_DISCONNECT_BY_APPLICATION, DisconnectReason, Details, StateName, D0), close_transport(D). %%-------------------------------------------------------------------- @@ -1876,27 +1870,33 @@ check_data_rekeying_dbg(SentSinceRekey, MaxSent) -> %%%---------------------------------------------------------------- %%% This server/client has decided to disconnect via the state machine: %%% The unused arguments are for debugging. +send_disconnect(#{code := Code} = DisconnectContext, D) -> + send_disconnect(default_text(Code), DisconnectContext, D). -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}, +send_disconnect(Reason, #{code := Code} = DisconnectContext, 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), + LogMsg = io_lib:format("Disconnects with code = ~p [RFC4253 11.1]: ~s", [Code, Reason]), + MoreContext = #{log_msg => LogMsg}, + call_disconnectfun_log_cond(maps:merge(DisconnectContext, MoreContext), D), {{shutdown,Reason}, D}. -call_disconnectfun_and_log_cond(LogMsg, DetailedText, Module, Line, StateName, D) -> - case disconnect_fun(LogMsg, D) of +call_disconnectfun_log_cond(#{code := Code} = DisconnectContext0, D) -> + DisconnectType = case Code of + undefined -> internal_disconnect; + Code when is_integer(Code) -> disconnect_sent + end, + DisconnectContext = maps:merge(DisconnectContext0, #{type => DisconnectType}), + case disconnect_fun(DisconnectContext, D) of void -> + #{log_msg := LogMsg, state_name := StateName, module := Module, line := Line, + details := Details} = DisconnectContext, log(info, D, "~s~n" "State = ~p~n" "Module = ~p, Line = ~p.~n" "Details:~n ~s~n", - [LogMsg, StateName, Module, Line, DetailedText]); + [LogMsg, StateName, Module, Line, Details]); _ -> ok end. @@ -1926,15 +1926,10 @@ counterpart_versions(NumVsn, StrVsn, #ssh{role = client} = Ssh) -> %%%---------------------------------------------------------------- conn_info_keys() -> - [client_version, - server_version, - peer, - user, - sockname, - options, - algorithms, - channels - ]. + conn_info_keys_base() ++ [channels]. + +conn_info_keys_base() -> + [client_version, server_version, peer, user, sockname, options, algorithms]. 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}; @@ -1954,8 +1949,8 @@ conn_info(channels, D) -> try conn_info_chans(ets:tab2list(cache(D))) conn_info(socket, D) -> D#data.socket; conn_info(chan_ids, D) -> ssh_client_channel:cache_foldl(fun(#channel{local_id=Id}, Acc) -> - [Id | Acc] - end, [], cache(D)). + [Id | Acc] + end, [], cache(D)). conn_info_chans(Chs) -> Fs = record_info(fields, channel), @@ -2120,8 +2115,12 @@ get_repl(X, Acc) -> exit({get_repl,X,Acc}). %%%---------------------------------------------------------------- -%%disconnect_fun({disconnect,Msg}, D) -> ?CALL_FUN(disconnectfun,D)(Msg); -disconnect_fun(Reason, D) -> ?CALL_FUN(disconnectfun,D)(Reason). +disconnect_fun(DisconnectType, Details, D) -> + disconnect_fun(#{type => DisconnectType, details => Details, code => undefined}, D). + +disconnect_fun(#{details := Details} = _DisconnectContext, D) -> + Fun = ?GET_OPT(disconnectfun, (D#data.ssh_params)#ssh.opts), + Fun(Details). unexpected_fun(UnexpectedMessage, #data{ssh_params = #ssh{peer = {_,Peer} }} = D) -> ?CALL_FUN(unexpectedfun,D)(UnexpectedMessage, Peer). @@ -2222,7 +2221,7 @@ triggered_alive(StateName, D0 = #data{}, %% Max probes count reached (equal to `alive_count`), we disconnect Details = "Alive timeout triggered", {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_CONNECTION_LOST, Details, StateName, D0), + ?SEND_DISCONNECT(?SSH_DISCONNECT_CONNECTION_LOST, Details, StateName, D0), {stop, Shutdown, D}; _ -> D = send_msg({ssh_msg_global_request,"keepalive@erlang.org", true, <<>>}, @@ -2295,7 +2294,8 @@ ssh_dbg_on(tcp) -> dbg:tp(?MODULE, handle_event, 4, dbg:tp(?MODULE, send_bytes, 2, x), dbg:tpl(?MODULE, close_transport, 1, x); -ssh_dbg_on(disconnect) -> dbg:tpl(?MODULE, send_disconnect, 7, x). +ssh_dbg_on(disconnect) -> dbg:tpl(?MODULE, send_disconnect, 2, x), + dbg:tpl(?MODULE, send_disconnect, 3, x). ssh_dbg_off(alive) -> @@ -2304,7 +2304,8 @@ ssh_dbg_off(alive) -> dbg:ctpl(?MODULE, reset_alive, 1), dbg:ctpl(?MODULE, init_ssh_record, 4), dbg:ctpl(?MODULE, triggered_alive, 4); -ssh_dbg_off(disconnect) -> dbg:ctpl(?MODULE, send_disconnect, 7); +ssh_dbg_off(disconnect) -> dbg:ctpl(?MODULE, send_disconnect, 2), + dbg:ctpl(?MODULE, send_disconnect, 3); ssh_dbg_off(terminate) -> dbg:ctpg(?MODULE, terminate, 3); ssh_dbg_off(tcp) -> dbg:ctpg(?MODULE, handle_event, 4), % How to avoid cancelling 'connection_events' ? dbg:ctpl(?MODULE, send_bytes, 2), @@ -2514,15 +2515,30 @@ 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]}}) -> + [#{code := Code, details := Details, + module := Module, line := Line, + state_name := StateName}, _D]}}) -> + ["Disconnecting:\n", + io_lib:format(" Module = ~p, Line = ~p, StateName = ~p,~n" + " Code = ~p,~n" + " Details =~n" + " ~p", + [Module, Line, StateName, Code, lists:flatten(Details)]) + ]; +ssh_dbg_format(disconnect, {call,{?MODULE,send_disconnect, + [Reason, #{code := Code, details := Details, + module := Module, line := Line, + state_name := StateName}, _D]}}) -> ["Disconnecting:\n", io_lib:format(" Module = ~p, Line = ~p, StateName = ~p,~n" " Code = ~p, Reason = ~p,~n" - " DetailedText =~n" + " Details =~n" " ~p", - [Module, Line, StateName, Code, Reason, lists:flatten(DetailedText)]) + [Module, Line, StateName, Code, Reason, lists:flatten(Details)]) ]; -ssh_dbg_format(renegotiation, {return_from, {?MODULE,send_disconnect,7}, _Ret}) -> +ssh_dbg_format(renegotiation, {return_from, {?MODULE,send_disconnect,2}, _Ret}) -> + skip; +ssh_dbg_format(renegotiation, {return_from, {?MODULE,send_disconnect,3}, _Ret}) -> skip. diff --git a/lib/ssh/src/ssh_fsm.hrl b/lib/ssh/src/ssh_fsm.hrl index ac37cbf37396..656917ff943c 100644 --- a/lib/ssh/src/ssh_fsm.hrl +++ b/lib/ssh/src/ssh_fsm.hrl @@ -67,12 +67,16 @@ %%==================================================================== %% Macros %%==================================================================== --define(send_disconnect(Code, DetailedText, StateName, State), - ssh_connection_handler:send_disconnect(Code, DetailedText, ?MODULE, ?LINE, StateName, State)). - --define(send_disconnect(Code, Reason, DetailedText, StateName, State), - ssh_connection_handler:send_disconnect(Code, Reason, DetailedText, ?MODULE, ?LINE, StateName, State)). +-define(SEND_DISCONNECT(Code, Details, StateName, State), + ssh_connection_handler:send_disconnect(#{code => Code, state_name => StateName, + details => Details, module => ?MODULE, line => ?LINE}, + State)). +-define(SEND_DISCONNECT(Code, Reason, Details, StateName, State), + ssh_connection_handler:send_disconnect(Reason, + #{code => Code, state_name => StateName, + details => Details, module => ?MODULE, line => ?LINE}, + State)). -define(CALL_FUN(Key,D), catch (?GET_OPT(Key, (D#data.ssh_params)#ssh.opts)) ). diff --git a/lib/ssh/src/ssh_fsm_kexinit.erl b/lib/ssh/src/ssh_fsm_kexinit.erl index c738e1c765f8..66c3974ab14c 100644 --- a/lib/ssh/src/ssh_fsm_kexinit.erl +++ b/lib/ssh/src/ssh_fsm_kexinit.erl @@ -60,11 +60,9 @@ callback_mode() -> state_enter]. %%-------------------------------------------------------------------- - - handle_event(Type, Event = prepare_next_packet, StateName, D) -> ssh_connection_handler:handle_event(Type, Event, StateName, D); -handle_event(Type, Event = {send_disconnect, _, _, _, _}, StateName, D) -> +handle_event(Type, Event = {send_disconnect, _}, StateName, D) -> ssh_connection_handler:handle_event(Type, Event, StateName, D); %%% ######## {kexinit, client|server, init|renegotiate} #### @@ -172,9 +170,10 @@ handle_event(internal, _Event, {key_exchange,_Role,init}, #data{ssh_params = #ssh{algorithms = #alg{kex_strict_negotiated = true}, send_sequence = SendSeq, recv_sequence = RecvSeq}}) -> - ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - io_lib:format("KEX strict violation: send_sequence = ~p recv_sequence = ~p", - [SendSeq, RecvSeq])); + Details = + io_lib:format("KEX strict violation: send_sequence = ~p recv_sequence = ~p", + [SendSeq, RecvSeq]), + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, Details); %%% ######## {key_exchange_dh_gex_init, server, init|renegotiate} #### handle_event(internal, #ssh_msg_kex_dh_gex_init{} = Msg, {key_exchange_dh_gex_init,server,ReNeg}, D) -> diff --git a/lib/ssh/src/ssh_fsm_userauth_client.erl b/lib/ssh/src/ssh_fsm_userauth_client.erl index 4a02caf121ff..4ecc35e63967 100644 --- a/lib/ssh/src/ssh_fsm_userauth_client.erl +++ b/lib/ssh/src/ssh_fsm_userauth_client.erl @@ -79,10 +79,9 @@ handle_event(internal, #ssh_msg_userauth_success{}, {userauth,client}, D0=#data{ %%---- userauth failure response to clientfrom the server handle_event(internal, #ssh_msg_userauth_failure{}, {userauth,client}=StateName, #data{ssh_params = #ssh{userauth_methods = []}} = D0) -> + Details = io_lib:format("User auth failed for: ~p",[D0#data.auth_user]), {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), + ?SEND_DISCONNECT(?SSH_DISCONNECT_NO_MORE_AUTH_METHODS_AVAILABLE, Details, StateName, D0), {stop, Shutdown, D}; handle_event(internal, #ssh_msg_userauth_failure{authentications = Methods}, StateName={userauth,client}, @@ -92,16 +91,15 @@ handle_event(internal, #ssh_msg_userauth_failure{authentications = Methods}, Sta none -> %% Server tells us which authentication methods that are allowed Ssh0#ssh{userauth_methods = string:tokens(Methods, ",")}; - _ -> - %% We already know... - Ssh0 - end, + _ -> + %% We already know... + Ssh0 + end, case ssh_auth:userauth_request_msg(Ssh1) of {send_disconnect, Code, Ssh} -> + Details = io_lib:format("User auth failed for: ~p",[D0#data.auth_user]), {Shutdown, D} = - ?send_disconnect(Code, - io_lib:format("User auth failed for: ~p",[D0#data.auth_user]), - StateName, D0#data{ssh_params = Ssh}), + ?SEND_DISCONNECT(Code, Details, StateName, D0#data{ssh_params = Ssh}), {stop, Shutdown, D}; {"keyboard-interactive", {Msg, Ssh}} -> D = ssh_connection_handler:send_msg(Msg, D0#data{ssh_params = Ssh}), diff --git a/lib/ssh/src/ssh_fsm_userauth_server.erl b/lib/ssh/src/ssh_fsm_userauth_server.erl index b1656cef75ab..7254b10c65b6 100644 --- a/lib/ssh/src/ssh_fsm_userauth_server.erl +++ b/lib/ssh/src/ssh_fsm_userauth_server.erl @@ -115,10 +115,9 @@ handle_event(internal, %% {ServiceName, Expected, Method} when Expected =/= ServiceName -> Do what? {ServiceName, _, _} when ServiceName =/= "ssh-connection" -> - {Shutdown, D} = - ?send_disconnect(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, - io_lib:format("Unknown service: ~p",[ServiceName]), - StateName, D1), + Details = io_lib:format("Unknown service: ~p",[ServiceName]), + {Shutdown, D} = + ?SEND_DISCONNECT(?SSH_DISCONNECT_SERVICE_NOT_AVAILABLE, Details, StateName, D1), {stop, Shutdown, D} end; diff --git a/lib/ssh/src/ssh_transport.erl b/lib/ssh/src/ssh_transport.erl index 047b898b5ef9..9b9fe49114da 100644 --- a/lib/ssh/src/ssh_transport.erl +++ b/lib/ssh/src/ssh_transport.erl @@ -419,16 +419,17 @@ handle_kexinit_msg(#ssh_msg_kexinit{} = CounterPart, #ssh_msg_kexinit{} = Own, true = verify_kexinit_is_first_msg(Algorithms, Ssh, ReNeg), Algorithms of - Algos -> - key_exchange_first_msg(Algos#alg.kex, - Ssh#ssh{algorithms = Algos}) + Algos -> + key_exchange_first_msg(Algos#alg.kex, + Ssh#ssh{algorithms = Algos}) catch Class:Reason0 -> Reason = ssh_lib:trim_reason(Reason0), - Msg = kexinit_error(Class, Reason, client, Own, CounterPart, Ssh), - ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, Msg) + DisconnectContext = kexinit_error(Class, Reason, client, Own, CounterPart, Ssh), + ?DISCONNECT_CONTEXT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, DisconnectContext) end; + handle_kexinit_msg(#ssh_msg_kexinit{first_kex_packet_follows = CounterGuess} = CounterPart, #ssh_msg_kexinit{} = Own, #ssh{role = server} = Ssh, ReNeg) -> @@ -445,10 +446,11 @@ handle_kexinit_msg(#ssh_msg_kexinit{first_kex_packet_follows = CounterGuess} = C catch Class:Reason0 -> Reason = ssh_lib:trim_reason(Reason0), - Msg = kexinit_error(Class, Reason, server, Own, CounterPart, Ssh), - ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, Msg) + DisconnectContext = kexinit_error(Class, Reason, server, Own, CounterPart, Ssh), + ?DISCONNECT_CONTEXT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, DisconnectContext) end. + %% RFC 4253 section 7 check if guess is wrong is_guess_wrong(false, _, _) -> false; @@ -461,9 +463,9 @@ is_guess_wrong(true, is_guess_wrong(true, _, _) -> true. -kexinit_error(Class, Error, Role, Own, CounterPart, Ssh) -> +kexinit_error(Class, Reason, Role, Own, CounterPart, Ssh) -> {Fmt,Args} = - case {Class,Error} of + case {Class,Reason} of {error, {badmatch,{false,Alg}}} -> {Txt,W,C} = alg_info(Role, Alg), MsgFun = @@ -479,15 +481,19 @@ kexinit_error(Class, Error, Role, Own, CounterPart, Ssh) -> end, ?SELECT_MSG(MsgFun); _ -> - {"Kexinit failed in ~p: ~p:~p", [Role,Class,Error]} + {"Kexinit failed in ~p: ~p:~p", [Role,Class,Reason]} end, - try io_lib:format(Fmt, Args, [{chars_limit, ssh_lib:max_log_len(Ssh)}]) of - R -> R - catch - _:_ -> - io_lib:format("Kexinit failed in ~p: ~p:~p", [Role, Class, Error], - [{chars_limit, ssh_lib:max_log_len(Ssh)}]) - end. + Details = + try io_lib:format(Fmt, Args, [{chars_limit, ssh_lib:max_log_len(Ssh)}]) of + R -> R + catch + _:_ -> + io_lib:format("Kexinit failed in ~p: ~p:~p", [Role, Class, Reason], + [{chars_limit, ssh_lib:max_log_len(Ssh)}]) + end, + #{own_proposal => Own, + peer_proposal => CounterPart, + details => Details}. alg_info(client, Alg) -> alg_info(Alg); @@ -713,10 +719,10 @@ handle_kex_dh_gex_request(#ssh_msg_kex_dh_gex_request{min = Min0, keyex_info = {Min0, Max0, NBits} }}; {error,_} -> - ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, - io_lib:format("No possible diffie-hellman-group-exchange group found",[], - [{chars_limit, ssh_lib:max_log_len(Opts)}]) - ) + Details = + io_lib:format("No possible diffie-hellman-group-exchange group found",[], + [{chars_limit, ssh_lib:max_log_len(Opts)}]), + ?DISCONNECT(?SSH_DISCONNECT_KEY_EXCHANGE_FAILED, Details) end; handle_kex_dh_gex_request(#ssh_msg_kex_dh_gex_request_old{n = NBits}, diff --git a/lib/ssh/src/ssh_transport.hrl b/lib/ssh/src/ssh_transport.hrl index a67ded4754f1..1641eb3e7c3e 100644 --- a/lib/ssh/src/ssh_transport.hrl +++ b/lib/ssh/src/ssh_transport.hrl @@ -244,8 +244,15 @@ %% %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% --define(DISCONNECT(Code, DetailedText), - ssh_connection_handler:disconnect(Code, DetailedText, ?MODULE, ?LINE)). +-define(DISCONNECT_CONTEXT(__Code, __DisconnectContext0), + begin + __DisconnectContext = + maps:merge(__DisconnectContext0, #{code => __Code, module => ?MODULE, line => ?LINE}), + ssh_connection_handler:disconnect(__DisconnectContext) + end). + +-define(DISCONNECT(__Code, __Msg), + ?DISCONNECT_CONTEXT(__Code, #{details => __Msg})). -define(SSH_DISCONNECT_HOST_NOT_ALLOWED_TO_CONNECT, 1). -define(SSH_DISCONNECT_PROTOCOL_ERROR, 2). diff --git a/lib/ssh/test/ssh_test_lib.erl b/lib/ssh/test/ssh_test_lib.erl index fe6efccd4b97..7fe132f5ba7c 100644 --- a/lib/ssh/test/ssh_test_lib.erl +++ b/lib/ssh/test/ssh_test_lib.erl @@ -187,7 +187,7 @@ connect(Host, Port, Options0) -> do_connect(Host, Port, Options) -> R = ssh:connect(Host, Port, Options), - ct:log("~p:~p ssh:connect(~p, ~p, ~p)~n -> ~p",[?MODULE,?LINE,Host, Port, Options, R]), + ?CT_LOG("ssh:connect(~p, ~p, ~p)~n -> ~p",[Host, Port, Options, R]), {ok, ConnectionRef} = R, ConnectionRef. @@ -212,17 +212,17 @@ daemon(Host, Options) -> daemon(Host, Port, Options) -> - ct:log("~p:~p Calling ssh:daemon(~p, ~p, ~p)",[?MODULE,?LINE,Host,Port,Options]), + ?CT_LOG("Calling ssh:daemon(~p, ~p, ~p)",[Host,Port,Options]), case ssh:daemon(Host, Port, Options) of {ok, Pid} -> R = ssh:daemon_info(Pid), - ct:log("~p:~p ssh:daemon_info(~p) ->~n ~p",[?MODULE,?LINE,Pid,R]), + ?CT_LOG("ssh:daemon_info(~p) ->~n ~p",[Pid,R]), {ok,L} = R, ListenPort = proplists:get_value(port, L), ListenIP = proplists:get_value(ip, L), {Pid, ListenIP, ListenPort}; Error -> - ct:log("ssh:daemon error ~p",[Error]), + ?CT_LOG("ssh:daemon error ~p",[Error]), Error end. @@ -240,10 +240,10 @@ gen_tcp_connect(Port, Options) -> gen_tcp_connect(Host0, Port, Options) -> Host = ssh_test_lib:ntoa(ssh_test_lib:mangle_connect_address(Host0)), - ct:log("~p:~p gen_tcp:connect(~p, ~p, ~p)~nHost0 = ~p", - [?MODULE,?LINE, Host, Port, Options, Host0]), + ?CT_LOG("gen_tcp:connect(~p, ~p, ~p)~nHost0 = ~p", + [Host, Port, Options, Host0]), Result = gen_tcp:connect(Host, Port, Options), - ct:log("~p:~p Result = ~p", [?MODULE,?LINE, Result]), + ?CT_LOG("Result = ~p", [Result]), Result. %%%---------------------------------------------------------------- @@ -253,7 +253,7 @@ open_sshc(Host0, Port, OptStr) -> open_sshc(Host0, Port, OptStr, ExecStr) -> Cmd = open_sshc_cmd(Host0, Port, OptStr, ExecStr), Result = os:cmd(Cmd), - ct:log("~p:~p Result = ~p", [?MODULE,?LINE, Result]), + ?CT_LOG("Result = ~p", [Result]), Result. @@ -266,7 +266,7 @@ open_sshc_cmd(Host0, Port, OptStr, ExecStr) -> " ", OptStr, " ", Host, " ", ExecStr]), - ct:log("~p:~p OpenSSH Cmd = ~p", [?MODULE,?LINE, Cmd]), + ?CT_LOG("OpenSSH Cmd = ~p", [Cmd]), Cmd. %%%---------------------------------------------------------------- @@ -315,13 +315,13 @@ std_simple_exec(Host, Port, Config) -> std_simple_exec(Host, Port, Config, []). std_simple_exec(Host, Port, Config, Opts) -> - ct:log("~p:~p std_simple_exec",[?MODULE,?LINE]), + ?CT_LOG("std_simple_exec",[]), ConnectionRef = ssh_test_lib:std_connect(Config, Host, Port, Opts), - ct:log("~p:~p connected! ~p",[?MODULE,?LINE,ConnectionRef]), + ?CT_LOG("connected! ~p",[ConnectionRef]), {ok, ChannelId} = ssh_connection:session_channel(ConnectionRef, infinity), - ct:log("~p:~p session_channel ok ~p",[?MODULE,?LINE,ChannelId]), + ?CT_LOG("session_channel ok ~p",[ChannelId]), ExecResult = ssh_connection:exec(ConnectionRef, ChannelId, "23+21-2.", infinity), - ct:log("~p:~p exec ~p",[?MODULE,?LINE,ExecResult]), + ?CT_LOG("exec ~p",[ExecResult]), case ExecResult of success -> Expected = {ssh_cm, ConnectionRef, {data,ChannelId,0,<<"42">>}}, @@ -344,8 +344,8 @@ start_shell(Port, IOServer) -> start_shell(Port, IOServer, ExtraOptions) -> spawn_link( fun() -> - ct:log("~p:~p:~p ssh_test_lib:start_shell(~p, ~p, ~p)", - [?MODULE,?LINE,self(), Port, IOServer, ExtraOptions]), + ?CT_LOG("ssh_test_lib:start_shell(~p, ~p, ~p)", + [Port, IOServer, ExtraOptions]), Options = [{user_interaction, false}, {silently_accept_hosts,true}, {save_accepted_host,false}, @@ -356,33 +356,33 @@ start_shell(Port, IOServer, ExtraOptions) -> case Port of 22 -> Host = hostname(), - ct:log("Port==22 Call ssh:shell(~p, ~p)", + ?CT_LOG("Port==22 Call ssh:shell(~p, ~p)", [Host, Options]), ssh:shell(Host, Options); _ when is_integer(Port) -> Host = hostname(), - ct:log("is_integer(Port) Call ssh:shell(~p, ~p, ~p)", + ?CT_LOG("is_integer(Port) Call ssh:shell(~p, ~p, ~p)", [Host, Port, Options]), ssh:shell(Host, Port, Options); ConnRef when is_pid(ConnRef) -> - ct:log("is_pid(ConnRef) Call ssh:shell(~p)", + ?CT_LOG("is_pid(ConnRef) Call ssh:shell(~p)", [ConnRef]), ssh:shell(ConnRef); % Options were given in ssh:connect Socket -> receive start -> ok end, - ct:log("Socket Call ssh:shell(~p, ~p)", + ?CT_LOG("Socket Call ssh:shell(~p, ~p)", [Socket, Options]), ssh:shell(Socket, Options) end of R -> - ct:log("~p:~p ssh_test_lib:start_shell(~p, ~p, ~p) -> ~p", - [?MODULE,?LINE,Port, IOServer, ExtraOptions, R]) + ?CT_LOG("ssh_test_lib:start_shell(~p, ~p, ~p) -> ~p", + [Port, IOServer, ExtraOptions, R]) catch C:E:S -> - ct:log("Exception ~p:~p~n~p", [C,E,S]), + ?CT_LOG("Exception ~p:~p~n~p", [C,E,S]), ct:fail("Exception",[]) end end). @@ -409,7 +409,7 @@ loop_io_server(TestCase, Buff0) -> io_reply(From, ReplyAs, Reply), loop_io_server(TestCase, Buff); {'EXIT',_, _} = _Exit -> - ct:log("ssh_test_lib:loop_io_server/2 got ~p",[_Exit]), + ?CT_LOG("ssh_test_lib:loop_io_server/2 got ~p",[_Exit]), ok after 30000 -> ct:fail("timeout ~p:~p",[?MODULE,?LINE]) @@ -464,7 +464,9 @@ rcv_expected(Expect, SshPort, Timeout) -> case Expect(Recvd) of true -> ?CT_LOG("Got expected ~p from ~p",[Recvd,SshPort]), - catch port_close(SshPort), + try port_close(SshPort) + catch C:E:S -> ?CT_LOG("port_close exception ~p:~p~n~p",[C,E,S]) + end, rcv_lingering(50); false -> ?CT_LOG("Got UNEXPECTED ~p~n",[Recvd]), @@ -472,25 +474,29 @@ rcv_expected(Expect, SshPort, Timeout) -> end; {SshPort, Expect} -> ?CT_LOG("Got expected ~p from ~p",[Expect,SshPort]), - catch port_close(SshPort), + try port_close(SshPort) + catch C:E:S -> ?CT_LOG("port_close exception ~p:~p~n~p",[C,E,S]) + end, rcv_lingering(50); Other -> ?CT_LOG("Got UNEXPECTED ~p~nExpect ~p",[Other, {SshPort,Expect}]), rcv_expected(Expect, SshPort, Timeout) after Timeout -> - catch port_close(SshPort), + try port_close(SshPort) + catch C:E:S -> ?CT_LOG("port_close exception ~p:~p~n~p",[C,E,S]) + end, ct:fail("Did not receive answer") end. rcv_lingering(Timeout) -> receive Msg -> - ct:log("Got LINGERING ~p",[Msg]), + ?CT_LOG("Got LINGERING ~p",[Msg]), rcv_lingering(Timeout) after Timeout -> - ct:log("No more lingering messages",[]), + ?CT_LOG("No more lingering messages",[]), ok end. @@ -498,22 +504,22 @@ rcv_lingering(Timeout) -> receive_exec_result([]) -> expected; receive_exec_result(Msgs) when is_list(Msgs) -> - ct:log("~p:~p Expect data! ~p", [?MODULE,?FUNCTION_NAME,Msgs]), + ?CT_LOG("Expect data! ~p", [Msgs]), receive Msg -> case lists:member(Msg, Msgs) orelse lists:member({optional,Msg}, Msgs) of true -> - ct:log("~p:~p Collected data ~p", [?MODULE,?FUNCTION_NAME,Msg]), + ?CT_LOG("Collected data ~p", [Msg]), receive_exec_result(Msgs--[Msg,{optional,Msg}]); false -> case Msg of {ssh_cm,_,{data,_,1, Data}} -> - ct:log("~p:~p unexpected StdErr: ~p~n~p~n", [?MODULE,?FUNCTION_NAME,Data,Msg]), + ?CT_LOG("unexpected StdErr: ~p~n~p~n", [Data,Msg]), receive_exec_result(Msgs); Other -> - ct:log("~p:~p unexpected Other ~p", [?MODULE,?FUNCTION_NAME,Other]), + ?CT_LOG("unexpected Other ~p", [Other]), receive_exec_result(Msgs) end end @@ -526,7 +532,7 @@ receive_exec_result(Msgs) when is_list(Msgs) -> false -> ct:fail("timeout ~p:~p",[?MODULE,?FUNCTION_NAME]); true -> - ct:log("~p:~p Only optional messages expected!~n ~p", [?MODULE,?FUNCTION_NAME,Msgs]), + ?CT_LOG("Only optional messages expected!~n ~p", [Msgs]), expected end end; @@ -606,8 +612,8 @@ openssh_sanity_check(Config) -> [{sanity_check_result, ok} | Config]; Err -> Str = lists:append(io_lib:format("~p", [Err])), - ct:log("Error = ~p", [Err]), - ct:log(?SANITY_CHECK_NOTE), + ?CT_LOG("Error = ~p", [Err]), + ?CT_LOG(?SANITY_CHECK_NOTE), ssh:stop(), [{sanity_check_result, Str} | Config] end. @@ -618,8 +624,8 @@ verify_sanity_check(Config) -> ok -> Config; Err -> - ct:log("Error = ~p", [Err]), - ct:log(?SANITY_CHECK_NOTE), + ?CT_LOG("Error = ~p", [Err]), + ?CT_LOG(?SANITY_CHECK_NOTE), {fail, passwordless_connection_failed} end. @@ -640,7 +646,7 @@ default_algorithms(sshd, Host, Port) -> {user_interaction, false}]}])) catch _C:_E -> - ct:log("***~p:~p: ~p:~p",[?MODULE,?LINE,_C,_E]), + ?CT_LOG("*** ~p:~p",[_C,_E]), [] end. @@ -660,7 +666,7 @@ default_algorithms(sshc, DaemonOptions) -> InitialState)) catch _C:_E -> - ct:log("***~p:~p: ~p:~p",[?MODULE,?LINE,_C,_E]), + ?CT_LOG("*** ~p:~p",[_C,_E]), [] end} end), @@ -780,11 +786,11 @@ ssh_type() -> demonitor(MonitorRef), Result; {'DOWN', MonitorRef, process, Pid, _Info} -> - ct:log("~p:~p Process DOWN",[?MODULE,?LINE]), + ?CT_LOG("Process DOWN",[]), not_found after 10000 -> - ct:log("~p:~p Timeout",[?MODULE,?LINE]), + ?CT_LOG("Timeout",[]), demonitor(MonitorRef), not_found end. @@ -792,25 +798,25 @@ ssh_type() -> ssh_type1() -> try - ct:log("~p:~p os:find_executable(\"ssh\")",[?MODULE,?LINE]), + ?CT_LOG("os:find_executable(\"ssh\")",[]), case os:find_executable("ssh") of false -> - ct:log("~p:~p Executable \"ssh\" not found",[?MODULE,?LINE]), + ?CT_LOG("Executable \"ssh\" not found",[]), not_found; Path -> - ct:log("~p:~p Found \"ssh\" at ~p",[?MODULE,?LINE,Path]), + ?CT_LOG("Found \"ssh\" at ~p",[Path]), case installed_ssh_version(timeout) of Version = "OpenSSH" ++ _ -> - ct:log("~p:~p Found OpenSSH ~p",[?MODULE,?LINE,Version]), + ?CT_LOG("Found OpenSSH ~p",[Version]), openSSH; Other -> - ct:log("ssh client ~p is unknown",[Other]), + ?CT_LOG("ssh client ~p is unknown",[Other]), unknown end end catch Class:Exception -> - ct:log("~p:~p Exception ~p:~p",[?MODULE,?LINE,Class,Exception]), + ?CT_LOG("Exception ~p:~p",[Class,Exception]), not_found end. @@ -953,12 +959,12 @@ get_kex_init(Conn, Ref, TRef) -> false -> receive {reneg_timeout,Ref} -> - ct:log("~p:~p Not in 'connected' state: ~p but reneg_timeout received. Fail.", - [?MODULE,?LINE,State]), - ct:log("S = ~p", [S]), + ?CT_LOG("Not in 'connected' state: ~p but reneg_timeout received. Fail.", + [State]), + ?CT_LOG("S = ~p", [S]), ct:fail(reneg_timeout) after 0 -> - ct:log("~p:~p Not in 'connected' state: ~p, Will try again after 100ms",[?MODULE,?LINE,State]), + ?CT_LOG("Not in 'connected' state: ~p, Will try again after 100ms",[State]), timer:sleep(100), % If renegotiation is complete we do not % want to exit on the reneg_timeout get_kex_init(Conn, Ref, TRef) @@ -990,7 +996,7 @@ create_random_dir(Config) -> %%%---------------------------------------------------------------- match_ip(A, B) -> R = match_ip0(A,B) orelse match_ip0(B,A), - ct:log("match_ip(~p, ~p) -> ~p",[A, B, R]), + ?CT_LOG("match_ip(~p, ~p) -> ~p",[A, B, R]), R. match_ip0(A, A) -> @@ -1038,7 +1044,11 @@ mangle_connect_address1({0,0,0,0}, _) -> loopback(false); mangle_connect_address1({0,0,0,0,0,0,0,0}, _) -> loopback(true); mangle_connect_address1( IP, _) when is_tuple(IP) -> IP; mangle_connect_address1(A, _) -> - case catch inet:parse_address(A) of + case (try inet:parse_address(A) + catch C:E:S -> + ?CT_LOG("inet:parse_address exception ~p:~p~n~p",[C,E,S]), + error + end) of {ok, {0,0,0,0}} -> loopback(false); {ok, {0,0,0,0,0,0,0,0}} -> loopback(true); _ -> A @@ -1090,11 +1100,11 @@ is_cryptolib_fips_capable() -> report(Comment, Line) -> ct:comment(Comment), - ct:log("~p:~p try_enable_fips_mode~n" + ?CT_LOG("try_enable_fips_mode (caller line ~p)~n" "crypto:info_lib() = ~p~n" "crypto:info_fips() = ~p~n" - "crypto:supports() =~n~p~n", - [?MODULE, Line, + "crypto:supports() =~n~p~n", + [Line, crypto:info_lib(), crypto:info_fips(), crypto:supports()]). @@ -1105,7 +1115,7 @@ lc_name_in(Names) -> {ok,Name} -> lists:member(string:to_lower(Name), Names); Other -> - ct:log("~p:~p inet:gethostname() returned ~p", [?MODULE,?LINE,Other]), + ?CT_LOG("inet:gethostname() returned ~p", [Other]), false end. @@ -1186,8 +1196,8 @@ setup_all_user_host_keys(DataDir, UserDir, SysDir) -> error:{badmatch, {error,enoent}} -> OkAlgs; C:E:S -> - ct:log("Exception in ~p:~p for alg ~p: ~p:~p~n~p", - [?MODULE,?FUNCTION_NAME,Alg,C,E,S]), + ?CT_LOG("Exception for alg ~p: ~p:~p~n~p", + [Alg,C,E,S]), OkAlgs end end, [], ssh_transport:supported_algorithms(public_key)). @@ -1208,8 +1218,8 @@ setup_all_host_keys(DataDir, SysDir) -> error:{badmatch, {error,enoent}} -> OkAlgs; C:E:S -> - ct:log("Exception in ~p:~p for alg ~p: ~p:~p~n~p", - [?MODULE,?FUNCTION_NAME,Alg,C,E,S]), + ?CT_LOG("Exception for alg ~p: ~p:~p~n~p", + [Alg,C,E,S]), OkAlgs end end, [], ssh_transport:supported_algorithms(public_key)). @@ -1225,8 +1235,8 @@ setup_all_user_keys(DataDir, UserDir) -> error:{badmatch, {error,enoent}} -> OkAlgs; C:E:S -> - ct:log("Exception in ~p:~p for alg ~p: ~p:~p~n~p", - [?MODULE,?FUNCTION_NAME,Alg,C,E,S]), + ?CT_LOG("Exception for alg ~p: ~p:~p~n~p", + [Alg,C,E,S]), OkAlgs end end, [], ssh_transport:supported_algorithms(public_key)). @@ -1248,7 +1258,7 @@ setup_user_key(SshAlg, DataDir, UserDir) -> setup_host_key_create_dir(SshAlg, DataDir, BaseDir) -> SysDir = filename:join(BaseDir,"system"), - ct:log("~p:~p SshAlg=~p~nDataDir = ~p~nBaseDir = ~p~nSysDir = ~p",[?MODULE,?LINE,SshAlg, DataDir, BaseDir,SysDir]), + ?CT_LOG("SshAlg=~p~nDataDir = ~p~nBaseDir = ~p~nSysDir = ~p",[SshAlg, DataDir, BaseDir,SysDir]), file:make_dir(SysDir), setup_host_key(SshAlg, DataDir, SysDir), SysDir. @@ -1398,7 +1408,7 @@ analyze_events(Events, EventNumber) when EventNumber >= 0 -> [length(Events)]) end, AllEventsSummary = lists:flatten([process_event(E) || E <- Events]), - ct:log("~nTotal logger events: ~p~nAll events:~n~s", [EventNumber, AllEventsSummary]), + ?CT_LOG("~nTotal logger events: ~p~nAll events:~n~s", [EventNumber, AllEventsSummary]), {ok, Cnt}. process_event(#{msg := {report, @@ -1506,7 +1516,7 @@ get_mfa_value(Properties) -> get_value(Key, List) -> case lists:keyfind(Key, 1, List) of R = false -> - ct:log("Key ~p not found in~n~p", [Key, List]), + ?CT_LOG("Key ~p not found in~n~p", [Key, List]), R; R -> R end. @@ -1515,7 +1525,7 @@ print_interesting_events([], Cnt) -> {ok, Cnt}; print_interesting_events([#{level := Level} = Event | Tail], Cnt) when Level /= info, Level /= notice, Level /= debug -> - ct:log("------------~nInteresting event found:~n~p~n==========~n", [Event]), + ?CT_LOG("------------~nInteresting event found:~n~p~n==========~n", [Event]), print_interesting_events(Tail, Cnt + 1); print_interesting_events([_|Tail], Cnt) -> print_interesting_events(Tail, Cnt).