* src/eldap.erl: Improved logging. We now use ejabberd logging framework (EJAB-582).

* src/eldap.erl: Faster LDAP reconnection (Thanks to Christophe Romain) (EJAB-581)

SVN Revision: 1236
This commit is contained in:
Mickaël Rémond 2008-03-20 16:28:36 +00:00
parent 320c266276
commit 4cef493b91
2 changed files with 71 additions and 85 deletions

View File

@ -1,3 +1,11 @@
2008-03-20 Mickael Remond <mremond@process-one.net>
* src/eldap.erl: Improved logging. We now use ejabberd logging
framework (EJAB-582).
* src/eldap.erl: Faster LDAP reconnection (Thanks to Christophe
Romain) (EJAB-581)
2008-03-17 Mickael Remond <mremond@process-one.net>
* src/ejabberd_s2s.erl: Only trigger s2s_connect_hook on

View File

@ -35,6 +35,14 @@
%%% Modified by Evgeniy Khramtsov <xram@jabber.ru>
%%% Implemented queue for bind() requests to prevent pending binds.
%%% Modified by Christophe Romain <christophe.romain@process-one.net>
%%% Improve error case handling
%%% Modified by Mickael Remond <mremond@process-one.net>
%%% Now use ejabberd log mechanism
%%% --------------------------------------------------------------------
-vc('$Id$ ').
@ -48,20 +56,19 @@
%%% active_bind - sent bind() request and waiting for response
%%%----------------------------------------------------------------------
%%-compile(export_all).
%%-export([Function/Arity, ...]).
-behaviour(gen_fsm).
-include("ejabberd.hrl").
%% External exports
-export([start_link/1, start_link/5, start_link/6]).
-export([start_link/1, start_link/5]).
-export([baseObject/0,singleLevel/0,wholeSubtree/0,close/1,
equalityMatch/2,greaterOrEqual/2,lessOrEqual/2,
approxMatch/2,search/2,substrings/2,present/1,
'and'/1,'or'/1,'not'/1,modify/3, mod_add/2, mod_delete/2,
mod_replace/2, add/3, delete/2, modify_dn/5, bind/3]).
-export([debug_level/2, get_status/1]).
-export([get_status/1]).
%% gen_fsm callbacks
-export([init/1, connecting/2,
@ -75,26 +82,24 @@
-include("eldap.hrl").
-define(LDAP_VERSION, 3).
-define(RETRY_TIMEOUT, 5000).
-define(RETRY_TIMEOUT, 500).
-define(BIND_TIMEOUT, 10000).
-define(CMD_TIMEOUT, 100000).
-define(MAX_TRANSACTION_ID, 65535).
-define(MIN_TRANSACTION_ID, 0).
-record(eldap, {version = ?LDAP_VERSION,
hosts, % Possible hosts running LDAP servers
hosts, % Possible hosts running LDAP servers
host = null, % Connected Host LDAP server
port = 389 , % The LDAP server port
port = 389, % The LDAP server port
fd = null, % Socket filedescriptor.
rootdn = "", % Name of the entry to bind as
passwd, % Password for (above) entry
id = 0, % LDAP Request ID
log, % User provided log function
bind_timer, % Ref to bind timeout
dict, % dict holding operation params and results
bind_q, % Queue for bind() requests
debug_level % Integer debug/logging level
}).
bind_q % Queue for bind() requests
}).
%%%----------------------------------------------------------------------
%%% API
@ -104,20 +109,8 @@ start_link(Name) ->
gen_fsm:start_link({local, Reg_name}, ?MODULE, [], []).
start_link(Name, Hosts, Port, Rootdn, Passwd) ->
Log = fun(_N, Fmt, Args) -> io:format("---- " ++ Fmt, [Args]) end,
Reg_name = list_to_atom("eldap_" ++ Name),
gen_fsm:start_link({local, Reg_name}, ?MODULE, {Hosts, Port, Rootdn, Passwd, Log}, []).
start_link(Name, Hosts, Port, Rootdn, Passwd, Log) ->
Reg_name = list_to_atom("eldap_" ++ Name),
gen_fsm:start_link({local, Reg_name}, ?MODULE, {Hosts, Port, Rootdn, Passwd, Log}, []).
%%% --------------------------------------------------------------------
%%% Set Debug Level. 0 - none, 1 - errors, 2 - ldap events
%%% --------------------------------------------------------------------
debug_level(Handle, N) when integer(N) ->
Handle1 = get_handle(Handle),
gen_fsm:sync_send_all_state_event(Handle1, {debug_level,N}).
gen_fsm:start_link({local, Reg_name}, ?MODULE, {Hosts, Port, Rootdn, Passwd}, []).
%%% --------------------------------------------------------------------
%%% Get status of connection.
@ -377,21 +370,19 @@ get_handle(Name) when list(Name) -> list_to_atom("eldap_" ++ Name).
%%----------------------------------------------------------------------
init([]) ->
case get_config() of
{ok, Hosts, Rootdn, Passwd, Log} ->
init({Hosts, Rootdn, Passwd, Log});
{ok, Hosts, Rootdn, Passwd} ->
init({Hosts, Rootdn, Passwd});
{error, Reason} ->
{stop, Reason}
end;
init({Hosts, Port, Rootdn, Passwd, Log}) ->
init({Hosts, Port, Rootdn, Passwd}) ->
{ok, connecting, #eldap{hosts = Hosts,
port = Port,
rootdn = Rootdn,
passwd = Passwd,
id = 0,
log = Log,
dict = dict:new(),
bind_q = queue:new(),
debug_level = 0}, 0}.
bind_q = queue:new()}, 0}.
%%----------------------------------------------------------------------
%% Func: StateName/2
@ -484,9 +475,6 @@ handle_event(_Event, StateName, S) ->
%% {stop, Reason, NewStateData} |
%% {stop, Reason, Reply, NewStateData}
%%----------------------------------------------------------------------
handle_sync_event({debug_level, N}, _From, StateName, S) ->
{reply, ok, StateName, S#eldap{debug_level = N}};
handle_sync_event(_Event, _From, StateName, S) ->
{reply, {StateName, S}, StateName, S}.
@ -501,7 +489,7 @@ handle_sync_event(_Event, _From, StateName, S) ->
%% Packets arriving in various states
%%
handle_info({tcp, _Socket, Data}, connecting, S) ->
log1("eldap. tcp packet received when disconnected!~n~p~n", [Data], S),
?DEBUG("eldap. tcp packet received when disconnected!~n~p", [Data]),
{next_state, connecting, S};
handle_info({tcp, _Socket, Data}, wait_bind_response, S) ->
@ -526,19 +514,26 @@ handle_info({tcp, _Socket, Data}, StateName, S)
{error, _Reason} -> {next_state, StateName, S}
end;
handle_info({tcp_closed, _Socket}, _All_fsm_states, S) ->
handle_info({tcp_closed, _Socket}, Fsm_state, S) ->
?WARNING_MSG("LDAP server closed the connection: ~s:~p~nIn State: ~p",
[S#eldap.host, S#eldap.port ,Fsm_state]),
F = fun(_Id, [{Timer, From, _Name}|_]) ->
gen_fsm:reply(From, {error, tcp_closed}),
cancel_timer(Timer)
end,
dict:map(F, S#eldap.dict),
retry_connect(),
{next_state, connecting, S#eldap{fd = null,
dict = dict:new(), bind_q=queue:new()}};
{ok, NextState, NewS} = connect_bind(S#eldap{fd = null,
dict = dict:new(),
bind_q=queue:new()}),
{next_state, NextState, NewS};
handle_info({tcp_error, _Socket, Reason}, Fsm_state, S) ->
log1("eldap received tcp_error: ~p~nIn State: ~p~n", [Reason, Fsm_state], S),
?DEBUG("eldap received tcp_error: ~p~nIn State: ~p", [Reason, Fsm_state]),
%% XXX wouldn't it be safer to try reconnect ?
%% if we were waiting a result, we may mait forever
%% cause request is probably lost....
{next_state, Fsm_state, S};
%%
%% Timers
%%
@ -561,8 +556,8 @@ handle_info({timeout, _Timer, bind_timeout}, wait_bind_response, S) ->
%% Make sure we don't fill the message queue with rubbish
%%
handle_info(Info, StateName, S) ->
log1("eldap. Unexpected Info: ~p~nIn state: ~p~n when StateData is: ~p~n",
[Info, StateName, S], S),
?DEBUG("eldap. Unexpected Info: ~p~nIn state: ~p~n when StateData is: ~p",
[Info, StateName, S]),
{next_state, StateName, S}.
%%----------------------------------------------------------------------
@ -589,13 +584,16 @@ send_command(Command, From, S) ->
{Name, Request} = gen_req(Command),
Message = #'LDAPMessage'{messageID = Id,
protocolOp = {Name, Request}},
log2("~p~n",[{Name, Request}], S),
?DEBUG("~p~n",[{Name, Request}]),
{ok, Bytes} = asn1rt:encode('ELDAPv3', 'LDAPMessage', Message),
ok = gen_tcp:send(S#eldap.fd, Bytes),
Timer = erlang:start_timer(?CMD_TIMEOUT, self(), {cmd_timeout, Id}),
New_dict = dict:store(Id, [{Timer, From, Name}], S#eldap.dict),
{ok, S#eldap{id = Id,
dict = New_dict}}.
case gen_tcp:send(S#eldap.fd, Bytes) of
ok ->
Timer = erlang:start_timer(?CMD_TIMEOUT, self(), {cmd_timeout, Id}),
New_dict = dict:store(Id, [{Timer, From, Name}], S#eldap.dict),
{ok, S#eldap{id = Id, dict = New_dict}};
Error ->
Error
end.
gen_req({search, A}) ->
{searchRequest,
@ -647,7 +645,7 @@ recvd_packet(Pkt, S) ->
case asn1rt:decode('ELDAPv3', 'LDAPMessage', Pkt) of
{ok,Msg} ->
Op = Msg#'LDAPMessage'.protocolOp,
log2("~p~n",[Op], S),
?DEBUG("~p",[Op]),
Dict = S#eldap.dict,
Id = Msg#'LDAPMessage'.messageID,
{Timer, From, Name, Result_so_far} = get_op_rec(Id, Dict),
@ -744,7 +742,7 @@ recvd_wait_bind_response(Pkt, S) ->
check_tag(Pkt),
case asn1rt:decode('ELDAPv3', 'LDAPMessage', Pkt) of
{ok,Msg} ->
log2("~p", [Msg], S),
?DEBUG("~p", [Msg]),
check_id(S#eldap.id, Msg#'LDAPMessage'.messageID),
case Msg#'LDAPMessage'.protocolOp of
{bindResponse, Result} ->
@ -844,6 +842,7 @@ polish([], Res, Ref) ->
connect_bind(S) ->
Host = next_host(S#eldap.host, S#eldap.hosts),
TcpOpts = [{packet, asn1}, {active, true}, {keepalive, true}, binary],
?INFO_MSG("LDAP connection on ~s:~p", [Host, S#eldap.port]),
case gen_tcp:connect(Host, S#eldap.port, TcpOpts) of
{ok, Socket} ->
case bind_request(Socket, S) of
@ -853,15 +852,15 @@ connect_bind(S) ->
{ok, wait_bind_response, NewS#eldap{fd = Socket,
host = Host,
bind_timer = Timer}};
{error, _Reason} ->
{error, Reason} ->
?ERROR_MSG("LDAP bind failed on ~s:~p~nReason: ~p", [Host, S#eldap.port, Reason]),
gen_tcp:close(Socket),
erlang:send_after(?RETRY_TIMEOUT, self(),
{timeout, retry_connect}),
retry_connect(),
{ok, connecting, S#eldap{host = Host}}
end;
{error, _Reason} ->
erlang:send_after(?RETRY_TIMEOUT, self(),
{timeout, retry_connect}),
{error, Reason} ->
?ERROR_MSG("LDAP connection failed on ~s:~p~nReason: ~p", [Host, S#eldap.port, Reason]),
retry_connect(),
{ok, connecting, S#eldap{host = Host}}
end.
@ -872,10 +871,12 @@ bind_request(Socket, S) ->
authentication = {simple, S#eldap.passwd}},
Message = #'LDAPMessage'{messageID = Id,
protocolOp = {bindRequest, Req}},
log2("Message:~p~n",[Message], S),
?DEBUG("Bind Request Message:~p~n",[Message]),
{ok, Bytes} = asn1rt:encode('ELDAPv3', 'LDAPMessage', Message),
ok = gen_tcp:send(Socket, Bytes),
{ok, S#eldap{id = Id}}.
case gen_tcp:send(Socket, Bytes) of
ok -> {ok, S#eldap{id = Id}};
Error -> Error
end.
%% Given last tried Server, find next one to try
next_host(null, [H|_]) -> H; % First time, take first
@ -946,8 +947,8 @@ get_config() ->
case file:consult(File) of
{ok, Entries} ->
case catch parse(Entries) of
{ok, Hosts, Port, Rootdn, Passwd, Log} ->
{ok, Hosts, Port, Rootdn, Passwd, Log};
{ok, Hosts, Port, Rootdn, Passwd} ->
{ok, Hosts, Port, Rootdn, Passwd};
{error, Reason} ->
{error, Reason};
{'EXIT', Reason} ->
@ -962,8 +963,7 @@ parse(Entries) ->
get_hosts(host, Entries),
get_integer(port, Entries),
get_list(rootdn, Entries),
get_list(passwd, Entries),
get_log(log, Entries)}.
get_list(passwd, Entries)}.
get_integer(Key, List) ->
case lists:keysearch(Key, 1, List) of
@ -985,16 +985,6 @@ get_list(Key, List) ->
throw({error, "No Entry in Config for " ++ atom_to_list(Key)})
end.
get_log(Key, List) ->
case lists:keysearch(Key, 1, List) of
{value, {Key, Value}} when function(Value) ->
Value;
{value, {Key, _Else}} ->
false;
false ->
fun(_Level, Format, Args) -> io:format("--- " ++ Format, Args) end
end.
get_hosts(Key, List) ->
lists:map(fun({Key1, {A,B,C,D}}) when integer(A),
integer(B),
@ -1016,15 +1006,3 @@ bump_id(#eldap{id = Id}) when Id > ?MAX_TRANSACTION_ID ->
?MIN_TRANSACTION_ID;
bump_id(#eldap{id = Id}) ->
Id + 1.
%%% --------------------------------------------------------------------
%%% Log routines. Call a user provided log routine Fun.
%%% --------------------------------------------------------------------
log1(Str, Args, #eldap{log = Fun, debug_level = N}) -> log(Fun, Str, Args, 1, N).
log2(Str, Args, #eldap{log = Fun, debug_level = N}) -> log(Fun, Str, Args, 2, N).
log(Fun, Str, Args, This_level, Status) when function(Fun), This_level =< Status ->
catch Fun(This_level, Str, Args);
log(_, _, _, _, _) ->
ok.