ssl: Enhance error logging

5 files changed, 65 insertions, 57 deletions

diff --git a/lib/ssl/src/dtls_connection.erl b/lib/ssl/src/dtls_connection.erl
index e8cfbbe2e3..b6aafc3fa4 100644
--- a/lib/ssl/src/dtls_connection.erl
+++ b/lib/ssl/src/dtls_connection.erl
@@ -48,7 +48,7 @@
 	 select_sni_extension/1]).
 
 %% Alert and close handling
--export([encode_alert/3,send_alert/2, close/5]).
+-export([encode_alert/3,send_alert/2, close/5, protocol_name/0]).
 
 %% Data handling
 
@@ -208,6 +208,9 @@ setopts(Transport, Socket, Other) ->
 getopts(Transport, Socket, Tag) ->
     dtls_socket:getopts(Transport, Socket, Tag).
 
+protocol_name() ->
+    "DTLS".
+        
 %%====================================================================
 %% tls_connection_sup API
 %%====================================================================
diff --git a/lib/ssl/src/ssl_alert.erl b/lib/ssl/src/ssl_alert.erl
index 696a55e4b9..b923785e17 100644
--- a/lib/ssl/src/ssl_alert.erl
+++ b/lib/ssl/src/ssl_alert.erl
@@ -57,16 +57,16 @@ decode(Bin) ->
 reason_code(#alert{description = ?CLOSE_NOTIFY}, _) ->
     closed;
 reason_code(#alert{description = Description}, _) ->
-    {tls_alert, description_txt(Description)}.
+    {tls_alert, string:to_lower(description_txt(Description))}.
 
 %%--------------------------------------------------------------------
 -spec alert_txt(#alert{}) -> string().
 %%
 %% Description: Returns the error string for given alert.
 %%--------------------------------------------------------------------
-alert_txt(#alert{level = Level, description = Description, where = {Mod,Line}, reason = undefined}) ->
-    Mod ++ ":" ++ integer_to_list(Line) ++ ":" ++ 
-        level_txt(Level) ++" "++ description_txt(Description);
+alert_txt(#alert{level = Level, description = Description, where = {Mod,Line}, reason = undefined, role = Role}) ->
+    "at " ++ Mod ++ ":" ++ integer_to_list(Line) ++ " " ++ string:to_upper(atom_to_list(Role)) ++ " ALERT: " ++
+        level_txt(Level) ++ description_txt(Description);
 alert_txt(#alert{reason = Reason} = Alert) ->
     BaseTxt = alert_txt(Alert#alert{reason = undefined}),
     FormatDepth = 9, % Some limit on printed representation of an error
@@ -93,73 +93,73 @@ decode(<<>>, Acc, _) ->
     lists:reverse(Acc, []).
 
 level_txt(?WARNING) ->
-    "Warning:";
+    "Warning - ";
 level_txt(?FATAL) ->
-    "Fatal error:".
+    "Fatal - ".
 
 description_txt(?CLOSE_NOTIFY) ->
-    "close notify";
+    "Close Notify";
 description_txt(?UNEXPECTED_MESSAGE) ->
-    "unexpected message";
+    "Unexpected Message";
 description_txt(?BAD_RECORD_MAC) ->
-    "bad record mac";
+    "Bad Record MAC";
 description_txt(?DECRYPTION_FAILED) ->
-    "decryption failed";
+    "Decryption Failed";
 description_txt(?RECORD_OVERFLOW) ->
-    "record overflow";
+    "Record Overflow";
 description_txt(?DECOMPRESSION_FAILURE) ->
-    "decompression failure";
+    "Decompression Failure";
 description_txt(?HANDSHAKE_FAILURE) ->
-    "handshake failure";
+    "Handshake Failure";
 description_txt(?NO_CERTIFICATE_RESERVED) ->
-    "No certificate reserved";
+    "No Certificate Reserved";
 description_txt(?BAD_CERTIFICATE) ->
-    "bad certificate";
+    "Bad Certificate";
 description_txt(?UNSUPPORTED_CERTIFICATE) ->
-    "unsupported certificate";
+    "Unsupported Certificate";
 description_txt(?CERTIFICATE_REVOKED) ->
-    "certificate revoked";
+    "Certificate Revoked";
 description_txt(?CERTIFICATE_EXPIRED) ->
-    "certificate expired";
+    "Certificate Expired";
 description_txt(?CERTIFICATE_UNKNOWN) ->
-    "certificate unknown";
+    "Certificate Unknown";
 description_txt(?ILLEGAL_PARAMETER) ->
-    "illegal parameter";
+    "Illegal Parameter";
 description_txt(?UNKNOWN_CA) ->
-    "unknown ca";
+    "Unknown CA";
 description_txt(?ACCESS_DENIED) ->
-    "access denied";
+    "Access Denied";
 description_txt(?DECODE_ERROR) ->
-    "decode error";
+    "Decode Error";
 description_txt(?DECRYPT_ERROR) ->
-    "decrypt error";
+    "Decrypt Error";
 description_txt(?EXPORT_RESTRICTION) ->
-    "export restriction";
+    "Export Restriction";
 description_txt(?PROTOCOL_VERSION) ->
-    "protocol version";
+    "Protocol Version";
 description_txt(?INSUFFICIENT_SECURITY) ->
-    "insufficient security";
+    "Insufficient Security";
 description_txt(?INTERNAL_ERROR) ->
-    "internal error";
+    "Internal Error";
 description_txt(?USER_CANCELED) ->
-    "user canceled";
+    "User Canceled";
 description_txt(?NO_RENEGOTIATION) ->
-    "no renegotiation";
+    "No Renegotiation";
 description_txt(?UNSUPPORTED_EXTENSION) ->
-    "unsupported extension";
+    "Unsupported Extension";
 description_txt(?CERTIFICATE_UNOBTAINABLE) ->
-    "certificate unobtainable";
+    "Certificate Unobtainable";
 description_txt(?UNRECOGNISED_NAME) ->
-    "unrecognised name";
+    "Unrecognised Name";
 description_txt(?BAD_CERTIFICATE_STATUS_RESPONSE) ->
-    "bad certificate status response";
+    "Bad Certificate Status Response";
 description_txt(?BAD_CERTIFICATE_HASH_VALUE) ->
-    "bad certificate hash value";
+    "Bad Certificate Hash Value";
 description_txt(?UNKNOWN_PSK_IDENTITY) ->
-    "unknown psk identity";
+    "Unknown Psk Identity";
 description_txt(?INAPPROPRIATE_FALLBACK) ->
-    "inappropriate fallback";
+    "Inappropriate Fallback";
 description_txt(?NO_APPLICATION_PROTOCOL) ->
-    "no application protocol";
+    "No application protocol";
 description_txt(Enum) ->
     lists:flatten(io_lib:format("unsupported/unknown alert: ~p", [Enum])).
diff --git a/lib/ssl/src/ssl_alert.hrl b/lib/ssl/src/ssl_alert.hrl
index f3743ba0f0..1aabb6c55a 100644
--- a/lib/ssl/src/ssl_alert.hrl
+++ b/lib/ssl/src/ssl_alert.hrl
@@ -118,6 +118,7 @@
 	  level,
 	  description,
           where = {?FILE, ?LINE},
+          role,
           reason
 	 }).
 -endif. % -ifdef(ssl_alert).
diff --git a/lib/ssl/src/ssl_connection.erl b/lib/ssl/src/ssl_connection.erl
index fb87662c7b..0163d08f2a 100644
--- a/lib/ssl/src/ssl_connection.erl
+++ b/lib/ssl/src/ssl_connection.erl
@@ -1143,7 +1143,7 @@ handle_alert(#alert{level = ?FATAL} = Alert, StateName,
 		    port = Port, session = Session, user_application = {_Mon, Pid},
 		    role = Role, socket_options = Opts, tracker = Tracker}) ->
     invalidate_session(Role, Host, Port, Session),
-    log_alert(SslOpts#ssl_options.log_alert, StateName, Alert),
+    log_alert(SslOpts#ssl_options.log_alert,  Connection:protocol_name(), StateName, Alert#alert{role = opposite_role(Role)}),
     alert_user(Transport, Tracker, Socket, StateName, Opts, Pid, From, Alert, Role, Connection),
     {stop, normal};
 
@@ -1153,15 +1153,16 @@ handle_alert(#alert{level = ?WARNING, description = ?CLOSE_NOTIFY} = Alert,
     {stop, {shutdown, peer_close}};
 
 handle_alert(#alert{level = ?WARNING, description = ?NO_RENEGOTIATION} = Alert, StateName, 
-	     #state{ssl_options = SslOpts, renegotiation = {true, internal}} = State) ->
-    log_alert(SslOpts#ssl_options.log_alert, StateName, Alert),
+	     #state{role = Role, ssl_options = SslOpts, protocol_cb = Connection, renegotiation = {true, internal}} = State) ->
+    log_alert(SslOpts#ssl_options.log_alert, Connection:protocol_name(), StateName, Alert#alert{role = opposite_role(Role)}),
     handle_normal_shutdown(Alert, StateName, State),
     {stop, {shutdown, peer_close}};
 
 handle_alert(#alert{level = ?WARNING, description = ?NO_RENEGOTIATION} = Alert, StateName, 
-	     #state{ssl_options = SslOpts, renegotiation = {true, From},
+	     #state{role = Role,
+                    ssl_options = SslOpts, renegotiation = {true, From},
 		    protocol_cb = Connection} = State0) ->
-    log_alert(SslOpts#ssl_options.log_alert, StateName, Alert),
+    log_alert(SslOpts#ssl_options.log_alert,  Connection:protocol_name(), StateName, Alert#alert{role = opposite_role(Role)}),
     gen_statem:reply(From, {error, renegotiation_rejected}),
     {Record, State} = Connection:next_record(State0),
     %% Go back to connection!
@@ -1169,8 +1170,8 @@ handle_alert(#alert{level = ?WARNING, description = ?NO_RENEGOTIATION} = Alert,
 
 %% Gracefully log and ignore all other warning alerts
 handle_alert(#alert{level = ?WARNING} = Alert, StateName,
-	     #state{ssl_options = SslOpts, protocol_cb = Connection} = State0) ->
-    log_alert(SslOpts#ssl_options.log_alert, StateName, Alert),
+	     #state{ssl_options = SslOpts, protocol_cb = Connection, role = Role} = State0) ->
+    log_alert(SslOpts#ssl_options.log_alert,  Connection:protocol_name(), StateName, Alert#alert{role = opposite_role(Role)}),
     {Record, State} = Connection:next_record(State0),
     Connection:next_event(StateName, Record, State).
 
@@ -2370,18 +2371,19 @@ alert_user(Transport, Tracker, Socket, Active, Pid, From, Alert, Role, Connectio
 							Transport, Socket, Connection, Tracker), ReasonCode})
     end.
 
-log_alert(true, Info, Alert) ->
+log_alert(true, ProtocolName, StateName, Alert) ->
     Txt = ssl_alert:alert_txt(Alert),
-    error_logger:format("SSL: ~p: ~s\n", [Info, Txt]);
-log_alert(false, _, _) ->
+    error_logger:format("~s: In state ~p ~s\n", [ProtocolName, StateName, Txt]);
+log_alert(false, _, _, _) ->
     ok.
 
 handle_own_alert(Alert, Version, StateName, 
-		 #state{transport_cb = Transport,
-			socket = Socket,
-			protocol_cb = Connection,
-			connection_states = ConnectionStates,
-			ssl_options = SslOpts} = State) ->
+		 #state{role = Role,
+                        transport_cb = Transport,
+                        socket = Socket,
+                        protocol_cb = Connection,
+                        connection_states = ConnectionStates,
+                        ssl_options = SslOpts} = State) ->
     try %% Try to tell the other side
 	{BinMsg, _} =
 	Connection:encode_alert(Alert, Version, ConnectionStates),
@@ -2390,7 +2392,7 @@ handle_own_alert(Alert, Version, StateName,
 	    ignore
     end,
     try %% Try to tell the local user
-	log_alert(SslOpts#ssl_options.log_alert, StateName, Alert),
+	log_alert(SslOpts#ssl_options.log_alert, Connection:protocol_name(), StateName, Alert#alert{role = Role}),
 	handle_normal_shutdown(Alert,StateName, State)
     catch _:_ ->
 	    ok
diff --git a/lib/ssl/src/tls_connection.erl b/lib/ssl/src/tls_connection.erl
index 352874c77d..e3ffbea3d3 100644
--- a/lib/ssl/src/tls_connection.erl
+++ b/lib/ssl/src/tls_connection.erl
@@ -56,7 +56,7 @@
 	 reinit_handshake_data/1,  select_sni_extension/1]).
 
 %% Alert and close handling
--export([send_alert/2, close/5]).
+-export([send_alert/2, close/5, protocol_name/0]).
 
 %% Data handling
 -export([passive_receive/2, next_record_if_active/1, handle_common_event/4, send/3,
@@ -164,6 +164,8 @@ encode_data(Data, Version, ConnectionStates0)->
 encode_alert(#alert{} = Alert, Version, ConnectionStates) ->
     tls_record:encode_alert_record(Alert, Version, ConnectionStates).
 
+protocol_name() ->
+    "TLS".
 %%====================================================================
 %% tls_connection_sup API
 %%====================================================================
@@ -719,7 +721,7 @@ close(downgrade, _,_,_,_) ->
 %% Other
 close(_, Socket, Transport, _,_) -> 
     Transport:close(Socket).
-	       
+
 convert_state(#state{ssl_options = Options} = State, up, "5.3.5", "5.3.6") ->
     State#state{ssl_options = convert_options_partial_chain(Options, up)};
 convert_state(#state{ssl_options = Options} = State, down, "5.3.6", "5.3.5") ->