From f126ae85c8eedc3975b6ef02ddd85d0c891e1696 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Dimitrov?= Date: Tue, 29 Jan 2019 14:13:52 +0100 Subject: ssl: Improve ssl_logger Improve API and delay creation of map arguments for ?LOG_DEBUG macro. Change-Id: I6956112fe64e599d33d83dfdd710cad53b8449e1 --- lib/ssl/src/ssl_logger.erl | 16 ++++++++++++---- lib/ssl/src/tls_connection.erl | 31 +++++++------------------------ lib/ssl/src/tls_handshake.erl | 5 +---- lib/ssl/src/tls_record.erl | 10 ++-------- lib/ssl/src/tls_sender.erl | 15 +++------------ 5 files changed, 25 insertions(+), 52 deletions(-) diff --git a/lib/ssl/src/ssl_logger.erl b/lib/ssl/src/ssl_logger.erl index ce8225bf72..51db8e6bdf 100644 --- a/lib/ssl/src/ssl_logger.erl +++ b/lib/ssl/src/ssl_logger.erl @@ -20,7 +20,7 @@ -module(ssl_logger). --export([debug/3, +-export([debug/4, format/2, notice/2]). @@ -57,12 +57,20 @@ format(#{level:= _Level, msg:= {report, Msg}, meta:= _Meta}, _Config0) -> end. %% Stateful logging -debug(Level, Report, Meta) -> +debug(Level, Direction, Protocol, Message) + when (Direction =:= inbound orelse Direction =:= outbound) andalso + (Protocol =:= 'tls_record' orelse Protocol =:= 'handshake') -> case logger:compare_levels(Level, debug) of lt -> - ?LOG_DEBUG(Report, Meta); + ?LOG_DEBUG(#{direction => Direction, + protocol => Protocol, + message => Message}, + #{domain => [otp,ssl,Protocol]}); eq -> - ?LOG_DEBUG(Report, Meta); + ?LOG_DEBUG(#{direction => Direction, + protocol => Protocol, + message => Message}, + #{domain => [otp,ssl,Protocol]}); _ -> ok end. diff --git a/lib/ssl/src/tls_connection.erl b/lib/ssl/src/tls_connection.erl index 26f9fc99d3..211c289f12 100644 --- a/lib/ssl/src/tls_connection.erl +++ b/lib/ssl/src/tls_connection.erl @@ -339,14 +339,8 @@ queue_handshake(Handshake, #state{negotiated_version = Version, ssl_options = SslOpts} = State0) -> {BinHandshake, ConnectionStates, Hist} = encode_handshake(Handshake, Version, ConnectionStates0, Hist0), - Report = #{direction => outbound, - protocol => 'tls_record', - message => BinHandshake}, - HandshakeMsg = #{direction => outbound, - protocol => 'handshake', - message => Handshake}, - ssl_logger:debug(SslOpts#ssl_options.log_level, HandshakeMsg, #{domain => [otp,ssl,handshake]}), - ssl_logger:debug(SslOpts#ssl_options.log_level, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(SslOpts#ssl_options.log_level, outbound, 'handshake', Handshake), + ssl_logger:debug(SslOpts#ssl_options.log_level, outbound, 'tls_record', BinHandshake), State0#state{connection_states = ConnectionStates, handshake_env = HsEnv#handshake_env{tls_handshake_history = Hist}, @@ -364,10 +358,7 @@ queue_change_cipher(Msg, #state{negotiated_version = Version, ssl_options = SslOpts} = State0) -> {BinChangeCipher, ConnectionStates} = encode_change_cipher(Msg, Version, ConnectionStates0), - Report = #{direction => outbound, - protocol => 'tls_record', - message => BinChangeCipher}, - ssl_logger:debug(SslOpts#ssl_options.log_level, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(SslOpts#ssl_options.log_level, outbound, 'tls_record', BinChangeCipher), State0#state{connection_states = ConnectionStates, flight_buffer = Flight0 ++ [BinChangeCipher]}. @@ -416,10 +407,7 @@ send_alert(Alert, #state{negotiated_version = Version, {BinMsg, ConnectionStates} = encode_alert(Alert, Version, ConnectionStates0), send(Transport, Socket, BinMsg), - Report = #{direction => outbound, - protocol => 'tls_record', - message => BinMsg}, - ssl_logger:debug(SslOpts#ssl_options.log_level, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(SslOpts#ssl_options.log_level, outbound, 'tls_record', BinMsg), StateData0#state{connection_states = ConnectionStates}. %% If an ALERT sent in the connection state, should cause the TLS @@ -520,14 +508,9 @@ init({call, From}, {start, Timeout}, {BinMsg, ConnectionStates, Handshake} = encode_handshake(Hello, HelloVersion, ConnectionStates0, Handshake0), send(Transport, Socket, BinMsg), - Report = #{direction => outbound, - protocol => 'tls_record', - message => BinMsg}, - HelloMsg = #{direction => outbound, - protocol => 'handshake', - message => Hello}, - ssl_logger:debug(SslOpts#ssl_options.log_level, HelloMsg, #{domain => [otp,ssl,handshake]}), - ssl_logger:debug(SslOpts#ssl_options.log_level, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(SslOpts#ssl_options.log_level, outbound, 'handshake', Hello), + ssl_logger:debug(SslOpts#ssl_options.log_level, outbound, 'tls_record', BinMsg), + State = State0#state{connection_states = ConnectionStates, negotiated_version = HelloVersion, %% Requested version session = diff --git a/lib/ssl/src/tls_handshake.erl b/lib/ssl/src/tls_handshake.erl index f0bbd0f94f..eee2437bfd 100644 --- a/lib/ssl/src/tls_handshake.erl +++ b/lib/ssl/src/tls_handshake.erl @@ -388,10 +388,7 @@ get_tls_handshake_aux(Version, <>, try decode_handshake(Version, Type, Body) of Handshake -> - Report = #{direction => inbound, - protocol => 'handshake', - message => Handshake}, - ssl_logger:debug(Opts#ssl_options.log_level, Report, #{domain => [otp,ssl,handshake]}), + ssl_logger:debug(Opts#ssl_options.log_level, inbound, 'handshake', Handshake), get_tls_handshake_aux(Version, Rest, Opts, [{Handshake,Raw} | Acc]) catch _:_ -> diff --git a/lib/ssl/src/tls_record.erl b/lib/ssl/src/tls_record.erl index b8bf4603dd..ad2bfb7a5c 100644 --- a/lib/ssl/src/tls_record.erl +++ b/lib/ssl/src/tls_record.erl @@ -404,10 +404,7 @@ get_tls_records_aux({MajVer, MinVer} = Version, < - Report = #{direction => inbound, - protocol => 'tls_record', - message => [RawTLSRecord]}, - ssl_logger:debug(SslOpts#ssl_options.log_level, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(SslOpts#ssl_options.log_level, inbound, 'tls_record', [RawTLSRecord]), get_tls_records_aux(Version, Rest, [#ssl_tls{type = Type, version = Version, fragment = Data} | Acc], SslOpts); @@ -423,10 +420,7 @@ get_tls_records_aux(Versions, < case is_acceptable_version({MajVer, MinVer}, Versions) of true -> - Report = #{direction => inbound, - protocol => 'tls_record', - message => [RawTLSRecord]}, - ssl_logger:debug(SslOpts#ssl_options.log_level, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(SslOpts#ssl_options.log_level, inbound, 'tls_record', [RawTLSRecord]), get_tls_records_aux(Versions, Rest, [#ssl_tls{type = Type, version = {MajVer, MinVer}, fragment = Data} | Acc], SslOpts); diff --git a/lib/ssl/src/tls_sender.erl b/lib/ssl/src/tls_sender.erl index 1559fcbb37..1f34f9a420 100644 --- a/lib/ssl/src/tls_sender.erl +++ b/lib/ssl/src/tls_sender.erl @@ -386,10 +386,7 @@ send_tls_alert(Alert, #data{negotiated_version = Version, {BinMsg, ConnectionStates} = Connection:encode_alert(Alert, Version, ConnectionStates0), Connection:send(Transport, Socket, BinMsg), - Report = #{direction => outbound, - protocol => 'tls_record', - message => BinMsg}, - ssl_logger:debug(LogLevel, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(LogLevel, outbound, 'tls_record', BinMsg), StateData0#data{connection_states = ConnectionStates}. send_application_data(Data, From, StateName, @@ -414,18 +411,12 @@ send_application_data(Data, From, StateName, StateData = StateData0#data{connection_states = ConnectionStates}, case Connection:send(Transport, Socket, Msgs) of ok when DistHandle =/= undefined -> - Report = #{direction => outbound, - protocol => 'tls_record', - message => Msgs}, - ssl_logger:debug(LogLevel, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(LogLevel, outbound, 'tls_record', Msgs), {next_state, StateName, StateData, []}; Reason when DistHandle =/= undefined -> {next_state, death_row, StateData, [{state_timeout, 5000, Reason}]}; ok -> - Report = #{direction => outbound, - protocol => 'tls_record', - message => Msgs}, - ssl_logger:debug(LogLevel, Report, #{domain => [otp,ssl,tls_record]}), + ssl_logger:debug(LogLevel, outbound, 'tls_record', Msgs), {next_state, StateName, StateData, [{reply, From, ok}]}; Result -> {next_state, StateName, StateData, [{reply, From, Result}]} -- cgit v1.2.3