Improve logging of Redis errors

src/ejabberd_redis.erl

@@ -31,7 +31,7 @@
 -compile({no_auto_import, [get/1, put/2]}).
 
 %% API
--export([start_link/1, get_proc/1, q/1, qp/1]).
+-export([start_link/1, get_proc/1, q/1, qp/1, format_error/1]).
 %% Commands
 -export([multi/1, get/1, set/2, del/1,
 	 sadd/2, srem/2, smembers/1, sismember/2, scard/1,
@@ -55,7 +55,7 @@
 		num :: pos_integer(),
 		pending_q :: p1_queue:queue()}).
 
--type redis_error() :: {error, binary() | timeout | disconnected}.
+-type redis_error() :: {error, binary() | timeout | disconnected | overloaded}.
 -type redis_reply() :: binary() | [binary()].
 -type redis_command() :: [binary()].
 -type redis_pipeline() :: [redis_command()].
@@ -107,6 +107,15 @@ multi(F) ->
 	    erlang:error(nested_transaction)
     end.
 
+-spec format_error(atom() | binary()) -> binary().
+format_error(Reason) when is_atom(Reason) ->
+    format_error(aux:atom_to_binary(Reason));
+format_error(Reason) ->
+    Reason.
+
+%%%===================================================================
+%%% Redis commands API
+%%%===================================================================
 -spec get(iodata()) -> {ok, undefined | binary()} | redis_error().
 get(Key) ->
     case erlang:get(?TR_STACK) of
@@ -408,13 +417,28 @@ call({Conn, Parent}, {F, Cmd}, Retries) ->
 	    try ?GEN_SERVER:call(Parent, connect, ?CALL_TIMEOUT) of
 		ok -> call({Conn, Parent}, {F, Cmd}, Retries-1);
 		{error, _} = Err -> Err
-	    catch exit:{timeout, _} -> {error, timeout};
+	    catch exit:{Why, {?GEN_SERVER, call, _}} ->
-		  exit:{_, {?GEN_SERVER, call, _}} -> {error, disconnected}
+		    Reason1 = case Why of
+				 timeout -> timeout;
+				 _ -> disconnected
+			     end,
+		    log_error(Cmd, Reason1),
+		    {error, Reason1}
 	    end;
+	{error, Reason1} ->
+	    log_error(Cmd, Reason1),
+	    Res;
 	_ ->
 	    Res
     end.
 
+-spec log_error(redis_command() | redis_pipeline(), atom() | binary()) -> ok.
+log_error(Cmd, Reason) ->
+    ?ERROR_MSG("Redis request has failed:~n"
+	       "** request = ~p~n"
+	       "** response = ~s",
+	       [Cmd, format_error(Reason)]).
+
 -spec get_worker() -> {atom(), atom()}.
 get_worker() ->
     Time = p1_time_compat:system_time(),
@@ -501,7 +525,7 @@ clean_queue(Q, CurrTime) ->
 	    ?ERROR_MSG("Redis request queue is overloaded", []),
 	    p1_queue:dropwhile(
 	      fun({From, _Time}) ->
-		      ?GEN_SERVER:reply(From, {error, disconnected}),
+		      ?GEN_SERVER:reply(From, {error, overloaded}),
 		      true
 	      end, Q1);
        true ->

src/ejabberd_router_redis.erl

@@ -51,9 +51,8 @@ register_route(Domain, ServerHost, LocalHint, _, Pid) ->
 	   end) of
 	{ok, _} ->
 	    ok;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to register route in redis: ~p", [Err]),
+	    {error, db_failure}
-	    Err
     end.
 
 unregister_route(Domain, _, Pid) ->
@@ -76,9 +75,8 @@ unregister_route(Domain, _, Pid) ->
 	   true ->
 		ok
 	end
-    catch _:{badmatch, Err} ->
+    catch _:{badmatch, {error, _}} ->
-	    ?ERROR_MSG("failed to unregister route in redis: ~p", [Err]),
+	    {error, db_failure}
-	    Err
     end.
 
 find_routes(Domain) ->
@@ -86,8 +84,7 @@ find_routes(Domain) ->
     case ejabberd_redis:hgetall(DomKey) of
 	{ok, Vals} ->
 	    decode_routes(Domain, Vals);
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to find routes in redis: ~p", [Err]),
 	    []
     end.
 
@@ -97,10 +94,7 @@ host_of_route(Domain) ->
 	{ok, [{_Pid, Data}|_]} ->
 	    {ServerHost, _} = binary_to_term(Data),
 	    {ok, ServerHost};
-	{ok, []} ->
+	_ ->
-	    error;
-	Err ->
-	    ?ERROR_MSG("failed to get host of route in redis: ~p", [Err]),
 	    error
     end.
 
@@ -108,8 +102,7 @@ is_my_route(Domain) ->
     case ejabberd_redis:sismember(?ROUTES_KEY, Domain) of
 	{ok, Bool} ->
 	    Bool;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to check route in redis: ~p", [Err]),
 	    false
     end.
 
@@ -120,8 +113,7 @@ get_all_routes() ->
     case ejabberd_redis:smembers(?ROUTES_KEY) of
 	{ok, Routes} ->
 	    Routes;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to fetch routes from redis: ~p", [Err]),
 	    []
     end.
 

src/ejabberd_sm_redis.erl

@@ -50,16 +50,12 @@ set_session(Session) ->
     SIDKey = sid_to_key(Session#session.sid),
     ServKey = server_to_key(element(2, Session#session.us)),
     USSIDKey = us_sid_to_key(Session#session.us, Session#session.sid),
-    case ejabberd_redis:multi(
+    ejabberd_redis:multi(
       fun() ->
 	      ejabberd_redis:hset(USKey, SIDKey, T),
 	      ejabberd_redis:hset(ServKey, USSIDKey, T)
-	   end) of
+      end),
-	{ok, _} ->
+    ok.
-	    ok;
-	Err ->
-	    ?ERROR_MSG("failed to set session for redis: ~p", [Err])
-    end.
 
 -spec delete_session(binary(), binary(), binary(), sid()) ->
 			    {ok, #session{}} | {error, notfound}.
@@ -75,20 +71,14 @@ delete_session(LUser, LServer, _LResource, SID) ->
 		    SIDKey = sid_to_key(SID),
 		    ServKey = server_to_key(element(2, Session#session.us)),
 		    USSIDKey = us_sid_to_key(Session#session.us, SID),
-		    case ejabberd_redis:multi(
+		    ejabberd_redis:multi(
 		      fun() ->
 			      ejabberd_redis:hdel(USKey, [SIDKey]),
 			      ejabberd_redis:hdel(ServKey, [USSIDKey])
-			   end) of
+		      end),
-			{ok, _} ->
-			    ok;
-			Err ->
-			    ?ERROR_MSG("failed to delete session from redis: ~p", [Err])
-		    end,
 		    {ok, Session}
 	    end;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to delete session from redis: ~p", [Err]),
 	    {error, notfound}
     end.
 
@@ -105,8 +95,7 @@ get_sessions(LServer) ->
     case ejabberd_redis:hgetall(ServKey) of
 	{ok, Vals} ->
 	    decode_session_list(Vals);
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to get sessions from redis: ~p", [Err]),
 	    []
     end.
 
@@ -116,8 +105,7 @@ get_sessions(LUser, LServer) ->
     case ejabberd_redis:hgetall(USKey) of
 	{ok, Vals} ->
 	    decode_session_list(Vals);
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to get sessions from redis: ~p", [Err]),
 	    []
     end.
 
@@ -129,8 +117,7 @@ get_sessions(LUser, LServer, LResource) ->
 	{ok, Vals} ->
 	    [S || S <- decode_session_list(Vals),
 		  element(3, S#session.usr) == LResource];
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to get sessions from redis: ~p", [Err]),
 	    []
     end.
 
@@ -179,8 +166,8 @@ clean_table() ->
 				  end, Vals)
 			end)
 	  end, ejabberd_sm:get_vh_by_backend(?MODULE))
-    catch _:{badmatch, {error, _} = Err} ->
+    catch _:{badmatch, {error, _}} ->
-	    ?ERROR_MSG("failed to clean redis c2s sessions: ~p", [Err])
+	    ?ERROR_MSG("failed to clean redis c2s sessions", [])
     end.
 
 opt_type(redis_connect_timeout) ->

src/mod_bosh_redis.erl

@@ -28,18 +28,13 @@ open_session(SID, Pid) ->
     case ejabberd_redis:hset(?BOSH_KEY, SID, PidBin) of
 	{ok, _} ->
 	    ok;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to register bosh session in redis: ~p", [Err]),
+	    {error, db_failure}
-	    Err
     end.
 
 close_session(SID) ->
-    case ejabberd_redis:hdel(?BOSH_KEY, [SID]) of
+    ejabberd_redis:hdel(?BOSH_KEY, [SID]),
-	{ok, _} ->
+    ok.
-	    ok;
-	Err ->
-	    ?ERROR_MSG("failed to delete bosh session in redis: ~p", [Err])
-    end.
 
 find_session(SID) ->
     case ejabberd_redis:hget(?BOSH_KEY, SID) of
@@ -51,10 +46,7 @@ find_session(SID) ->
 			       [SID, Pid]),
 		    error
 	    end;
-	{ok, _} ->
+	_ ->
-	    error;
-	Err ->
-	    ?ERROR_MSG("failed to lookup bosh session in redis: ~p", [Err]),
 	    error
     end.
 
@@ -65,7 +57,7 @@ clean_table() ->
     ?INFO_MSG("Cleaning Redis BOSH sessions...", []),
     case ejabberd_redis:hgetall(?BOSH_KEY) of
 	{ok, Vals} ->
-	    case ejabberd_redis:multi(
+	    ejabberd_redis:multi(
 	      fun() ->
 		      lists:foreach(
 			fun({SID, Pid}) when node(Pid) == node() ->
@@ -73,12 +65,8 @@ clean_table() ->
 			   (_) ->
 				ok
 			end, Vals)
-		   end) of
+	      end),
-		{ok, _} ->
 	    ok;
-		Err ->
+	{error, _} ->
-		    ?ERROR_MSG("failed to clean bosh sessions in redis: ~p", [Err])
+	    ?ERROR_MSG("failed to clean bosh sessions in redis", [])
-	    end;
-	Err ->
-	    ?ERROR_MSG("failed to clean bosh sessions in redis: ~p", [Err])
     end.

src/mod_carboncopy_redis.erl

@@ -46,9 +46,8 @@ enable(LUser, LServer, LResource, NS) ->
 	   end) of
 	{ok, _} ->
 	    ok;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to write in redis: ~p", [Err]),
+	    {error, db_failure}
-	    Err
     end.
 
 disable(LUser, LServer, LResource) ->
@@ -62,9 +61,8 @@ disable(LUser, LServer, LResource) ->
 	   end) of
 	{ok, _} ->
 	    ok;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to delete from redis: ~p", [Err]),
+	    {error, db_failure}
-	    Err
     end.
 
 list(LUser, LServer) ->
@@ -72,8 +70,7 @@ list(LUser, LServer) ->
     case ejabberd_redis:hgetall(USKey) of
 	{ok, Vals} ->
 	    Vals;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("failed to read from redis: ~p", [Err]),
 	    []
     end.
 
@@ -85,7 +82,7 @@ clean_table() ->
     NodeKey = node_key(),
     case ejabberd_redis:smembers(NodeKey) of
 	{ok, JIDs} ->
-	    case ejabberd_redis:multi(
+	    ejabberd_redis:multi(
 	      fun() ->
 		      lists:foreach(
 			fun(JID) ->
@@ -93,19 +90,12 @@ clean_table() ->
 				USKey = us_key(U, S),
 				ejabberd_redis:hdel(USKey, [R])
 			end, JIDs)
-		   end) of
+	      end);
-		{ok, _} ->
+	{error, _} ->
-		    ok;
+	    ok
-		Err ->
-		    ?ERROR_MSG("failed to delete from redis: ~p", [Err])
-	    end;
-	Err ->
-	    ?ERROR_MSG("failed to read from redis: ~p", [Err])
     end,
-    case ejabberd_redis:del([NodeKey]) of
+    ejabberd_redis:del([NodeKey]),
-	{ok, _} -> ok;
+    ok.
-	Error -> ?ERROR_MSG("failed to delete from redis: ~p", [Error])
-    end.
 
 us_key(LUser, LServer) ->
     <<"ejabberd:carboncopy:users:", LUser/binary, $@, LServer/binary>>.

src/mod_proxy65_redis.erl

@@ -73,8 +73,7 @@ init() ->
 		      ejabberd_redis:del([NodeKey])
 	      end),
 	    ok;
-	Err ->
+	{error, _} ->
-	    ?ERROR_MSG("redis request failed: ~p", [Err]),
 	    {error, db_failure}
     end.
 
@@ -101,8 +100,7 @@ register_stream(SID, Pid) ->
 			   [SIDKey, Val]),
 		{error, db_failure}
 	end
-    catch _:{badmatch, Err} ->
+    catch _:{badmatch, {error, _}} ->
-	    ?ERROR_MSG("redis request failed: ~p", [Err]),
 	    {error, db_failure}
     end.
 
@@ -135,8 +133,7 @@ unregister_stream(SID) ->
 			   [SIDKey, Val]),
 		{error, db_failure}
 	end
-    catch _:{badmatch, Err} ->
+    catch _:{badmatch, {error, _}} ->
-	    ?ERROR_MSG("redis request failed: ~p", [Err]),
 	    {error, db_failure}
     end.
 
@@ -171,8 +168,7 @@ activate_stream(SID, IJID, MaxConnections, _Node) ->
 			   [SIDKey, Val]),
 		{error, db_failure}
 	end
-    catch _:{badmatch, Err} ->
+    catch _:{badmatch, {error, _}} ->
-	    ?ERROR_MSG("redis request failed: ~p", [Err]),
 	    {error, db_failure}
     end.