Hi All
I have two operation problems:
1) I configured ejabberd 2.1.6 to use LDAP for authentication. This works fine most of the time. But suddenly, the authentication fails for a few minutes and then it works again. I observed this for various users at random times. The typical error message is:
=INFO REPORT==== 2011-03-17 19:42:16 ===
I(<0.6378.0>:ejabberd_c2s:649) : ({socket_state,tls,{tlssock,#Port<0.6704>,#Port<0.6706>},<0.6377.0>}) Failed authentication for USER
interestingly, there is another log message close by the failures (before and after):
=INFO REPORT==== 2011-03-17 19:40:29 ===
I(<0.257.0>:eldap:967) : LDAP connection on LDAP-SERVER:636
=ERROR REPORT==== 2011-03-17 19:44:16 ===
E(<0.6383.0>:eldap_pool:81) : LDAP request failed: timed out
2) When I start the ejabberd server for the first time, some users log in and are successfully authenticated against the LDAP. Then they add each other as contacts. The contacts appear in the clients as long as I do not restart ejabberd. However, when I restart ejabbed, all contact lists are erased. My expectation was that the contact lists should survive a server restart?
Regards,
Marc
The contact list problem is
The contact list problem is solved. Sorry. I mistakenly deleted mod_roster from the config.
But the LDAP problem is still there. 90% of the time, it works, but then it fails for about 10 minutes (but only for the user which first experienced the problem).
LDAP authentication still there
I found out the following:
The first user authentication in the morning times out. While the first has to wait a few dozen minutes, the second and all other users can quickly authenticate. Is there a problem with the LDAP connection which is established over a long time?
My LDAP config:
{auth_method, ldap}.
{ldap_servers, ["SERVER"]}.
{ldap_encrypt, tls}.
{ldap_port, 1636}.
{ldap_rootdn, "ROOTDN"}.
{ldap_password, "PASSWORD"}.
{ldap_base, "BASE"}.
{ldap_uids, [{"uid", "%u@%d"}]}.
The c2s config:
{5222, ejabberd_c2s, [
{certfile, "CERTFILE"}, starttls_required,
{access, c2s},
{shaper, c2s_shaper},
{max_stanza_size, 65536}
]},
The ejabberd.log emits:
=INFO REPORT==== 2011-03-23 07:28:10 ===
I(<0.377.0>:ejabberd_listener:281) : (#Port<0.4063>) Accepted connection {{IP,49160} -> {{IP},5222}
=INFO REPORT==== 2011-03-23 07:29:50 ===
I(<0.935.0>:ejabberd_c2s:649) : ({socket_state,tls,{tlssock,#Port<0.4063>,#Port<0.4065>},<0.934.0>}) Failed authentication for FIRSTUSER
=WARNING REPORT==== 2011-03-23 07:33:52 ===
W(<0.220.0>:eldap:589) : LDAP server closed the connection: SERVER:1636
In State: active
=INFO REPORT==== 2011-03-23 07:33:53 ===
I(<0.220.0>:eldap:967) : LDAP connection on SERVER:1636
=INFO REPORT==== 2011-03-23 07:35:33 ===
I(<0.946.0>:ejabberd_c2s:649) : ({socket_state,tls,{tlssock,#Port<0.4075>,#Port<0.4077>},<0.945.0>}) Failed authentication for FIRSTUSER
=WARNING REPORT==== 2011-03-23 07:39:34 ===
W(<0.229.0>:eldap:589) : LDAP server closed the connection: SERVER:1636
In State: active_bind
=INFO REPORT==== 2011-03-23 07:39:35 ===
I(<0.229.0>:eldap:967) : LDAP connection on SERVER:1636
=INFO REPORT==== 2011-03-23 07:44:57 ===
I(<0.377.0>:ejabberd_listener:281) : (#Port<0.4083>) Accepted connection {{IP},52500} -> {{IP},5222}
=INFO REPORT==== 2011-03-23 07:44:58 ===
I(<0.968.0>:ejabberd_c2s:631) : ({socket_state,tls,{tlssock,#Port<0.4083>,#Port<0.4085>},<0.967.0>}) Accepted authentication for SECONDUSER by ejabberd_auth_ldap
=INFO REPORT==== 2011-03-23 07:44:58 ===
I(<0.968.0>:ejabberd_c2s:890) : ({socket_state,tls,{tlssock,#Port<0.4083>,#Port<0.4085>},<0.967.0>}) Opened session for SECONDUSER
=INFO REPORT==== 2011-03-23 08:22:07 ===
I(<0.377.0>:ejabberd_listener:281) : (#Port<0.4106>) Accepted connection {{IP},50436} -> {{IP},5222}
=INFO REPORT==== 2011-03-23 08:22:07 ===
I(<0.1029.0>:ejabberd_c2s:631) : ({socket_state,tls,{tlssock,#Port<0.4106>,#Port<0.4108>},<0.1028.0>}) Accepted authentication for FIRSTUSER by ejabberd_auth_ldap
=INFO REPORT==== 2011-03-23 08:22:07 ===
I(<0.1029.0>:ejabberd_c2s:890) : ({socket_state,tls,{tlssock,#Port<0.4106>,#Port<0.4108>},<0.1028.0>}) Opened session for FIRSTUSER
What can I do to work around this tedious initial timeout?
Problem Solved! The problem
Problem Solved!
The problem was/is that ejabberd establishes a long-lived TCP connection to the LDAP server. However, the firewall was configured with a TCP idle timeout of 1 hour. This repeatedly leaded to the situaton that a user tried to authenticate through ejabberd with LDAP over an already-dropped TCP connection.
The LDAP server was/is configured for TCP keep-alives. But the default for TCP keep-alive (on most operating systems) is 2 hours.
The workaround now either is to disable TCP SYN checking on the firewall (not preferred) or to set the TCP timeout on the firewall to more than 2 hours (this is what I did).