%% %% %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([<>|_]) -> io_lib:format("TLS 1.2 Record Protocol, ~s", [msg_type(B)]); tls_record_version([<>|_]) -> io_lib:format("TLS 1.1 Record Protocol, ~s", [msg_type(B)]); tls_record_version([<>|_]) -> io_lib:format("TLS 1.0 Record Protocol, ~s", [msg_type(B)]); tls_record_version([<>|_]) -> io_lib:format("SSL 3.0 Record Protocol, ~s", [msg_type(B)]); tls_record_version([<>|_]) -> 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, [<>|T], Row, Acc, C) when C =:= 0 -> convert_to_hex(P, [<>|T], update_row(<>, Row), prepend_first_row(P, A, B, Acc, C), C + 1); %% New line convert_to_hex(P, [<>|T], Row, Acc, C) when C rem 16 =:= 0 -> convert_to_hex(P, [<>|T], update_row(<>, []), 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, [<>|T], Row, Acc, C) when C rem 8 =:= 7 -> convert_to_hex(P, [<>|T], update_row(<>, Row), prepend_eighths_hex(A, B, Acc), C + 1); convert_to_hex(P, [<>|T], Row, Acc, C) -> convert_to_hex(P, [<>|T], update_row(<>, 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.