Failed to Authenticate: Got a response but Authentication timed out

[Tostosss]

Hi,

I have below configurations. I can make ldap search. After the bind_timeout period i got "http_auth_ldap: Authentication timed out" error on access log. On debug log it finds out the user with the below logs from ldap server. I searched every issue and all other things but nothing. I get tired from searching. I have cheched the ldap module. Log generated from ngx_http_auth_ldap_read_handler method on STATE_SEARCHING case but i don't know what is this state and what is the error. Please help.!

http_auth_ldap: ldap_result() -> rc=100, msgid=2, msgtype=100 http_auth_ldap: Received a search entry http_auth_ldap: Found entry with DN "CN=BOB MARTIN,OU=17764,OU=7222,OU=6710,OU=16152,OU=16085,OU=16083,OU=4573,OU=UserOU,DC=xxx,DC=yyy,DC=zzz"

NGINX VERSION: nginx version: nginx/1.8.0 built by gcc 4.4.7 20120313 (Red Hat 4.4.7-3) (GCC) built with OpenSSL 1.0.0-fips 29 Mar 2010 TLS SNI support enabled configure arguments: --prefix=/nginx/nginx-1.8.0/server --sbin-path=/nginx/nginx-1.8.0/bin/nginx --pid-path=/nginx/nginx-1.8.0/bin/pid.nginx --conf-path=/nginx/nginx-1.8.0/conf/nginx.conf --error-log-path=/nginx/nginx-1.8.0/server/logs/default/error.log --http-log-path=/nginx/nginx-1.8.0/server/logs/default/access.log --with-pcre=/nginx/nginx-1.8.0/conf/pcre-8.37 --with-zlib=/nginx/nginx-1.8.0/conf/zlib-1.2.8 --user=curio --group=curio --with-threads --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_addition_module --with-http_sub_module --with-http_dav_module --with-http_gzip_static_module --with-http_gunzip_module --add-module=/nginx/src/nginx-dav-ext-module-master --add-module=/nginx/src/nginx-auth-ldap-master --with-http_auth_request_module --with-debug

NGINX_LDAP_CONF:

LDAP Global Configs

auth_ldap_cache_enabled on;
auth_ldap_cache_expiration_time 120000;
auth_ldap_cache_size 1000;

# LDAP Server
ldap_server ldap_server {

    # Timeout Values
    connect_timeout 30s;
    bind_timeout 15s;
    request_timeout 30s;
    connections 1;

    # user search base.
    url 'ldap://domain.xx.yy.zz:389/dc=xx,dc=yy,dc=zz?sAMAccountName?sub?(objectClass=user)';

    # bind as
    binddn 'CN=service,OU=Generic Users,DC=xx,DC=yy,DC=zz';

    # bind passwd
    binddn_passwd 'service_passwd';

    # group attribute name which contains member object
    group_attribute uniquemember;

    # search for full DN in member object
    group_attribute_is_dn on;

    # matching algorithm (any / all)
    satisfy any;

    # list of allowed users
    require valid_user;

}

ERROR_LOG: http_auth_ldap: Authentication timed out

DEBUG_LOG: 2016/01/11 11:30:01 [debug] 33230#33230: ngx_http_auth_ldap_sb_read(len=8) 2016/01/11 11:30:01 [debug] 33230#33230: ngx_http_auth_ldap_sb_read(len=14) 2016/01/11 11:30:01 [debug] 33230#33230: http_auth_ldap: ldap_result() -> rc=97, msgid=1, msgtype=97 2016/01/11 11:30:01 [debug] 33230#33230: http_auth_ldap: Initial bind successful 2016/01/11 11:30:01 [debug] 33230#33230: http_auth_ldap: Marking the connection to "ldap_server" as free 2016/01/11 11:30:01 [debug] 33230#33230: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:01 [debug] 33230#33230: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:01 [debug] 33230#33230: ngx_http_auth_ldap_sb_read(len=8) 2016/01/11 11:30:01 [debug] 33230#33230: http_auth_ldap: ldap_result() -> rc=0 2016/01/11 11:30:01 [debug] 33230#33230: http_auth_ldap: Dummy write handler

2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_write(len=100) 2016/01/11 11:30:17 [debug] 33227#33227: http_auth_ldap: Read handler 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_read(len=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_read(len=130) 2016/01/11 11:30:17 [debug] 33227#33227: http_auth_ldap: ldap_result() -> rc=100, msgid=2, msgtype=100 2016/01/11 11:30:17 [debug] 33227#33227: http_auth_ldap: Received a search entry 2016/01/11 11:30:17 [debug] 33227#33227: http_auth_ldap: Found entry with DN "CN=BOB MARTIN,OU=17764,OU=7222,OU=6710,OU=16152,OU=16085,OU=16083,OU=4573,OU=UserOU,DC=xxx,DC=yyy,DC=zzz" 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_read(len=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_read(len=93) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:17 [debug] 33227#33227: ngx_http_auth_ldap_sb_read(len=8)

2016/01/11 11:30:47 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:47 [debug] 33227#33227: http_auth_ldap: ldap_result() -> rc=115, msgid=2, msgtype=115 2016/01/11 11:30:47 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:47 [debug] 33227#33227: ngx_http_auth_ldap_sb_ctrl(opt=8) 2016/01/11 11:30:47 [debug] 33227#33227: http_auth_ldap: ldap_result() -> rc=0 2016/01/11 11:30:47 [debug] 33227#33227: http_auth_ldap: Dummy write handler

[arifcse019]

Having the same issue. I have nginx 1.6.2, and trying to talk to a Active Directory server

[ibplayn]

I was having the same issue as well. I fixed it by changing the port from 389 to 3268.

[mkmoisen]

I'm also seeing this. I can authenticate using python's python-ldap module fine over port 389, but cannot do it in nginx. Any solutions?

[michelvocks]

Same issue here. The workaround from @wu-chapb works well.

[svscorp]

Well, workaround doesn't explain anything neither work in my case - 3268 isn't opened in all ADs/LDAPs.

[yeangigi]

Having the same issue and my LDAP server is not AD , I cant change the port from 389 to 3268.