kvspb / nginx-auth-ldap

LDAP authentication module for nginx
BSD 2-Clause "Simplified" License
739 stars 253 forks source link

Set replied=0 before search of group dn #214

Closed Kartinkin closed 5 years ago

Kartinkin commented 6 years ago

Some times, we come here when we are waiting for a group check. The problem is that replied == 1 after previous user check and we fall to the phase loop instead of wait for the answer from LDAP server. Obviously, we have no answer from LDAP yet, and group check fails.

2018/11/08 05:50:21 [debug] 7538#7538: *445 access phase: 8
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Authentication loop (phase=1, iteration=1)
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Authentication loop (phase=2, iteration=1)
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: User DN is "CN=43994982,*****"
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Moving to group check
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Authentication loop (phase=3, iteration=0)
2018/11/08 05:50:21 [debug] 7538#7538: *445 Checking group
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Search user in group "*****"
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Search group filter is "(&(CN=*****)(member=CN=43994982,*****)())"
2018/11/08 05:50:21 [debug] 7538#7538: ngx_http_auth_ldap_sb_write(len=193)
2018/11/08 05:50:21 [debug] 7538#7538: SSL to write: 193
2018/11/08 05:50:21 [debug] 7538#7538: SSL_write: 193
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: ldap_search_ext() -> msgid=1135
2018/11/08 05:50:21 [debug] 7538#7538: ngx_http_auth_ldap_sb_ctrl(opt=8)
2018/11/08 05:50:21 [debug] 7538#7538: ngx_http_auth_ldap_sb_ctrl(opt=8)
2018/11/08 05:50:21 [debug] 7538#7538: ngx_http_auth_ldap_sb_read(len=8)
2018/11/08 05:50:21 [debug] 7538#7538: SSL_read: -1
2018/11/08 05:50:21 [debug] 7538#7538: SSL_get_error: 2
2018/11/08 05:50:21 [debug] 7538#7538: http_auth_ldap: ldap_result() -> rc=0
2018/11/08 05:50:21 [debug] 7538#7538: http_auth_ldap: Dummy write handler
2018/11/08 05:50:21 [debug] 7538#7538: timer delta: 0
2018/11/08 05:50:21 [debug] 7538#7538: worker cycle
2018/11/08 05:50:21 [debug] 7538#7538: epoll timer: 3741
2018/11/08 05:50:21 [debug] 7538#7538: epoll: fd:29 ev:0005 d:00007F28B1BF23C1
2018/11/08 05:50:21 [debug] 7538#7538: *445 http run request: "/socket.io/?EIO=3&transport=polling&t=MRnsywT&sid=882accf8-6b7d-4ff8-8a86-f9400aa046d2"
2018/11/08 05:50:21 [debug] 7538#7538: *445 http reading blocked
2018/11/08 05:50:21 [debug] 7538#7538: *445 http run request: "/socket.io/?EIO=3&transport=polling&t=MRnsywT&sid=882accf8-6b7d-4ff8-8a86-f9400aa046d2"
2018/11/08 05:50:21 [debug] 7538#7538: *445 access phase: 8

Nginx is calling ngx_http_auth_ldap_authenticate and we have to answer "The LDAP operation did not finish yet" and NGX_AGAIN, but falling down to the loop

2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Authentication loop (phase=3, iteration=1)
2018/11/08 05:50:21 [debug] 7538#7538: *445 Checking group

Check fails because there is no search result (ctx->dn.data == NULL)

2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Authentication loop (phase=4, iteration=0)
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: no requirement satisfied
2018/11/08 05:50:21 [debug] 7538#7538: *445 http_auth_ldap: Authentication loop (phase=6, iteration=0)
2018/11/08 05:50:21 [debug] 7538#7538: *445 event timer del: 29: 10957657910

We'll recieve the answer, but it will be too late:

2018/11/08 05:50:21 [debug] 7538#7538: http_auth_ldap: ldap_result() -> rc=100, msgid=1135, msgtype=100
2018/11/08 05:50:21 [debug] 7538#7538: http_auth_ldap: Message with unknown ID received, ignoring.