aboutsummaryrefslogtreecommitdiffstats
path: root/lib/ssl/src/ssl_logger.erl
diff options
context:
space:
mode:
Diffstat (limited to 'lib/ssl/src/ssl_logger.erl')
-rw-r--r--lib/ssl/src/ssl_logger.erl349
1 files changed, 349 insertions, 0 deletions
diff --git a/lib/ssl/src/ssl_logger.erl b/lib/ssl/src/ssl_logger.erl
new file mode 100644
index 0000000000..35c8dcfd48
--- /dev/null
+++ b/lib/ssl/src/ssl_logger.erl
@@ -0,0 +1,349 @@
+%%
+%% %CopyrightBegin%
+%%
+%% Copyright Ericsson AB 1999-2018. All Rights Reserved.
+%%
+%% Licensed under the Apache License, Version 2.0 (the "License");
+%% you may not use this file except in compliance with the License.
+%% You may obtain a copy of the License at
+%%
+%% http://www.apache.org/licenses/LICENSE-2.0
+%%
+%% Unless required by applicable law or agreed to in writing, software
+%% distributed under the License is distributed on an "AS IS" BASIS,
+%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+%% See the License for the specific language governing permissions and
+%% limitations under the License.
+%%
+%% %CopyrightEnd%
+%%
+
+-module(ssl_logger).
+
+-export([debug/3,
+ format/2,
+ notice/2]).
+
+-define(DEC2HEX(X),
+ if ((X) >= 0) andalso ((X) =< 9) -> (X) + $0;
+ ((X) >= 10) andalso ((X) =< 15) -> (X) + $a - 10
+ end).
+
+-define(rec_info(T,R),lists:zip(record_info(fields,T),tl(tuple_to_list(R)))).
+
+-include("tls_record.hrl").
+-include("ssl_internal.hrl").
+-include("tls_handshake.hrl").
+-include_lib("kernel/include/logger.hrl").
+
+%%-------------------------------------------------------------------------
+%% External API
+%%-------------------------------------------------------------------------
+
+%% SSL log formatter
+format(#{level:= _Level, msg:= {report, Msg}, meta:= _Meta}, _Config0) ->
+ #{direction := Direction,
+ protocol := Protocol,
+ message := BinMsg0} = Msg,
+ case Protocol of
+ 'tls_record' ->
+ BinMsg = lists:flatten(BinMsg0),
+ format_tls_record(Direction, BinMsg);
+ 'handshake' ->
+ format_handshake(Direction, BinMsg0);
+ _Other ->
+ []
+ end.
+
+%% Stateful logging
+debug(Level, Report, Meta) ->
+ case logger:compare_levels(Level, debug) of
+ lt ->
+ ?LOG_DEBUG(Report, Meta);
+ eq ->
+ ?LOG_DEBUG(Report, Meta);
+ _ ->
+ ok
+ end.
+
+%% Stateful logging
+notice(Level, Report) ->
+ case logger:compare_levels(Level, notice) of
+ lt ->
+ ?LOG_NOTICE(Report);
+ eq ->
+ ?LOG_NOTICE(Report);
+ _ ->
+ ok
+ end.
+
+
+%%-------------------------------------------------------------------------
+%% Handshake Protocol
+%%-------------------------------------------------------------------------
+format_handshake(Direction, BinMsg) ->
+ {Header, Message} = parse_handshake(Direction, BinMsg),
+ io_lib:format("~s~n~s~n", [Header, Message]).
+
+
+parse_handshake(Direction, #client_hello{
+ client_version = Version
+ } = ClientHello) ->
+ Header = io_lib:format("~s ~s Handshake, ClientHello",
+ [header_prefix(Direction),
+ version(Version)]),
+ Message = io_lib:format("~p", [?rec_info(client_hello, ClientHello)]),
+ {Header, Message};
+parse_handshake(Direction, #server_hello{
+ server_version = Version
+ } = ServerHello) ->
+ Header = io_lib:format("~s ~s Handshake, ServerHello",
+ [header_prefix(Direction),
+ version(Version)]),
+ Message = io_lib:format("~p", [?rec_info(server_hello, ServerHello)]),
+ {Header, Message};
+parse_handshake(Direction, #certificate{} = Certificate) ->
+ Header = io_lib:format("~s Handshake, Certificate",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(certificate, Certificate)]),
+ {Header, Message};
+parse_handshake(Direction, #server_key_exchange{} = ServerKeyExchange) ->
+ Header = io_lib:format("~s Handshake, ServerKeyExchange",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(server_key_exchange, ServerKeyExchange)]),
+ {Header, Message};
+parse_handshake(Direction, #server_key_params{} = ServerKeyExchange) ->
+ Header = io_lib:format("~s Handshake, ServerKeyExchange",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(server_key_params, ServerKeyExchange)]),
+ {Header, Message};
+parse_handshake(Direction, #certificate_request{} = CertificateRequest) ->
+ Header = io_lib:format("~s Handshake, CertificateRequest",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(certificate_request, CertificateRequest)]),
+ {Header, Message};
+parse_handshake(Direction, #server_hello_done{} = ServerHelloDone) ->
+ Header = io_lib:format("~s Handshake, ServerHelloDone",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(server_hello_done, ServerHelloDone)]),
+ {Header, Message};
+parse_handshake(Direction, #client_key_exchange{} = ClientKeyExchange) ->
+ Header = io_lib:format("~s Handshake, ClientKeyExchange",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(client_key_exchange, ClientKeyExchange)]),
+ {Header, Message};
+parse_handshake(Direction, #certificate_verify{} = CertificateVerify) ->
+ Header = io_lib:format("~s Handshake, CertificateVerify",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(certificate_verify, CertificateVerify)]),
+ {Header, Message};
+parse_handshake(Direction, #finished{} = Finished) ->
+ Header = io_lib:format("~s Handshake, Finished",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(finished, Finished)]),
+ {Header, Message};
+parse_handshake(Direction, #hello_request{} = HelloRequest) ->
+ Header = io_lib:format("~s Handshake, HelloRequest",
+ [header_prefix(Direction)]),
+ Message = io_lib:format("~p", [?rec_info(hello_request, HelloRequest)]),
+ {Header, Message}.
+
+
+version({3,3}) ->
+ "TLS 1.2";
+version({3,2}) ->
+ "TLS 1.1";
+version({3,1}) ->
+ "TLS 1.0";
+version({3,0}) ->
+ "SSL 3.0";
+version({M,N}) ->
+ io_lib:format("TLS [0x0~B0~B]", [M,N]).
+
+
+header_prefix(inbound) ->
+ "<<<";
+header_prefix(outbound) ->
+ ">>>".
+
+
+%%-------------------------------------------------------------------------
+%% TLS Record Protocol
+%%-------------------------------------------------------------------------
+format_tls_record(Direction, BinMsg) ->
+ {Message, Size} = convert_to_hex('tls_record', BinMsg),
+ Header = io_lib:format("~s (~B bytes) ~s~n",
+ [header_prefix_tls_record(Direction),
+ Size,
+ tls_record_version(BinMsg)]),
+ Header ++ Message.
+
+
+header_prefix_tls_record(inbound) ->
+ "reading";
+header_prefix_tls_record(outbound) ->
+ "writing".
+
+
+tls_record_version([<<?BYTE(B),?BYTE(3),?BYTE(3),_/binary>>|_]) ->
+ io_lib:format("TLS 1.2 Record Protocol, ~s", [msg_type(B)]);
+tls_record_version([<<?BYTE(B),?BYTE(3),?BYTE(2),_/binary>>|_]) ->
+ io_lib:format("TLS 1.1 Record Protocol, ~s", [msg_type(B)]);
+tls_record_version([<<?BYTE(B),?BYTE(3),?BYTE(1),_/binary>>|_]) ->
+ io_lib:format("TLS 1.0 Record Protocol, ~s", [msg_type(B)]);
+tls_record_version([<<?BYTE(B),?BYTE(3),?BYTE(0),_/binary>>|_]) ->
+ io_lib:format("SSL 3.0 Record Protocol, ~s", [msg_type(B)]);
+tls_record_version([<<?BYTE(B),?BYTE(M),?BYTE(N),_/binary>>|_]) ->
+ io_lib:format("TLS [0x0~B0~B] Record Protocol, ~s", [M, N, msg_type(B)]).
+
+
+msg_type(20) -> "change_cipher_spec";
+msg_type(21) -> "alert";
+msg_type(22) -> "handshake";
+msg_type(23) -> "application_data";
+msg_type(_) -> unknown.
+
+
+%%-------------------------------------------------------------------------
+%% Hex encoding functions
+%%-------------------------------------------------------------------------
+convert_to_hex(Protocol, BinMsg) ->
+ convert_to_hex(Protocol, BinMsg, [], [], 0).
+%%
+convert_to_hex(P, [], Row0, Acc, C) when C rem 16 =:= 0 ->
+ Row = lists:reverse(end_row(P, Row0)),
+ {lists:reverse(Acc) ++ Row ++ io_lib:nl(), C};
+convert_to_hex(P, [], Row0, Acc, C) ->
+ Row = lists:reverse(end_row(P, Row0)),
+ Padding = calculate_padding(Row0, Acc),
+ PaddedRow = string:pad(Row, Padding, leading, $ ),
+ {lists:reverse(Acc) ++ PaddedRow ++ io_lib:nl(), C};
+convert_to_hex(P, [H|T], Row, Acc, C) when is_list(H) ->
+ convert_to_hex(P, H ++ T, Row, Acc, C);
+convert_to_hex(P, [<<>>|T], Row, Acc, C) ->
+ convert_to_hex(P, T, Row, Acc, C);
+
+%% First line
+convert_to_hex(P, [<<A:4,B:4,R/binary>>|T], Row, Acc, C) when C =:= 0 ->
+ convert_to_hex(P, [<<R/binary>>|T],
+ update_row(<<A:4,B:4>>, Row),
+ prepend_first_row(P, A, B, Acc, C),
+ C + 1);
+%% New line
+convert_to_hex(P, [<<A:4,B:4,R/binary>>|T], Row, Acc, C) when C rem 16 =:= 0 ->
+ convert_to_hex(P, [<<R/binary>>|T],
+ update_row(<<A:4,B:4>>, []),
+ prepend_row(P, A, B, Row, Acc, C),
+ C + 1);
+%% Add 8th hex with extra whitespace
+%% 0000 - 16 03 02 00 bd 01 00 00 b9 ...
+%% ^^^^
+convert_to_hex(P, [<<A:4,B:4,R/binary>>|T], Row, Acc, C) when C rem 8 =:= 7 ->
+ convert_to_hex(P, [<<R/binary>>|T],
+ update_row(<<A:4,B:4>>, Row),
+ prepend_eighths_hex(A, B, Acc),
+ C + 1);
+convert_to_hex(P, [<<A:4,B:4,R/binary>>|T], Row, Acc, C) ->
+ convert_to_hex(P, [<<R/binary>>|T],
+ update_row(<<A:4,B:4>>, Row),
+ prepend_hex(A, B, Acc),
+ C + 1);
+%% First line
+convert_to_hex(P, [H|T], Row, Acc, C) when is_integer(H), C =:= 0 ->
+ convert_to_hex(P, T,
+ update_row(H, Row),
+ prepend_first_row(P, H, Acc, C),
+ C + 1);
+%% New line
+convert_to_hex(P, [H|T], Row, Acc, C) when is_integer(H), C rem 16 =:= 0 ->
+ convert_to_hex(P, T,
+ update_row(H, []),
+ prepend_row(P, H, Row, Acc, C),
+ C + 1);
+%% Add 8th hex with extra whitespace
+%% 0000 - 16 03 02 00 bd 01 00 00 b9 ...
+%% ^^^^
+convert_to_hex(P, [H|T], Row, Acc, C) when is_integer(H), C rem 8 =:= 7 ->
+ convert_to_hex(P, T,
+ update_row(H, Row),
+ prepend_eighths_hex(H, Acc),
+ C + 1);
+convert_to_hex(P, [H|T], Row, Acc, C) when is_integer(H) ->
+ convert_to_hex(P, T,
+ update_row(H, Row),
+ prepend_hex(H, Acc),
+ C + 1).
+
+
+row_prefix(tls_record, N) ->
+ S = string:pad(string:to_lower(erlang:integer_to_list(N, 16)),4,leading,$0),
+ lists:reverse(lists:flatten(S ++ " - ")).
+
+
+end_row(tls_record, Row) ->
+ Row ++ " ".
+
+
+%% Calculate padding of the "printable character" lines in order to be
+%% visually aligned.
+calculate_padding(Row, Acc) ->
+ %% Number of new line characters
+ NNL = (length(Acc) div 75) * length(io_lib:nl()),
+ %% Length of the last printed line
+ Length = (length(Acc) - NNL) rem 75,
+ %% Adjusted length of the last printed line
+ PaddedLength = 75 - (16 - length(Row)), %% Length
+ %% Padding
+ PaddedLength - Length.
+
+
+%%-------------------------------------------------------------------------
+%% Functions operating on reversed lists
+%%-------------------------------------------------------------------------
+update_row(B, Row) when is_binary(B) ->
+ case binary_to_list(B) of
+ [C] when 32 =< C, C =< 126 ->
+ [C|Row];
+ _Else ->
+ [$.|Row]
+ end;
+update_row(C, Row) when 32 =< C, C =< 126 ->
+ [C|Row];
+update_row(_, Row) ->
+ [$.|Row].
+
+
+prepend_first_row(P, A, B, Acc, C) ->
+ prepend_hex(A, B,row_prefix(P, C) ++ Acc).
+%%
+prepend_first_row(P, N, Acc, C) ->
+ prepend_hex(N,row_prefix(P, C) ++ Acc).
+
+prepend_row(P, A, B, Row, Acc, C) ->
+ prepend_hex(A, B,row_prefix(P, C) ++ io_lib:nl() ++ end_row(P, Row) ++ Acc).
+%%
+prepend_row(P, N, Row, Acc, C) ->
+ prepend_hex(N,row_prefix(P, C) ++ io_lib:nl() ++ end_row(P, Row) ++ Acc).
+
+
+
+prepend_hex(A, B, Acc) ->
+ [$ ,?DEC2HEX(B),?DEC2HEX(A)|Acc].
+%%
+prepend_hex(N, Acc) ->
+ " " ++ number_to_hex(N) ++ Acc.
+
+
+prepend_eighths_hex(A, B, Acc) ->
+ [$ ,$ ,?DEC2HEX(B),?DEC2HEX(A)|Acc].
+%%
+prepend_eighths_hex(N, Acc) ->
+ " " ++ number_to_hex(N) ++ Acc.
+
+number_to_hex(N) ->
+ case string:to_lower(erlang:integer_to_list(N, 16)) of
+ H when length(H) < 2 ->
+ lists:append(H, "0");
+ H ->
+ lists:reverse(H)
+ end.