search

kvspb / nginx-auth-ldap

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

auth-ldap can't operate with fancyindex #200

Open Joungkyun opened 6 years ago

Joungkyun commented 6 years ago

Environment

Configuration

ldap_server ldap.domain.com {
    url ldaps://ldap.domain.com/OU=People,DC=domain,DC=com?uid?sub?(objectClass=posixAccount);
    binddn "uid=ssomanager,ou=admin,dc=domain,dc=com";
    binddn_passwd acblfebadiced@T;
    group_attribute uniquemember;
    group_attribute_is_dn on;
    require valid_user;

    ssl_check_cert off;
    satisfy any;
}

server {
   listen        80 default_server backlog=1024;
   server_name   _;

    auth_ldap "Forbidden";
    auth_ldap_servers ldap.domain.com;

    ..blah..blah

    location / {
        if ( $http_user_agent ~* "bot" ) {
            access_log off;
        }

        if ( $request_filename ~* "\.(js|css|png|jpg|jpeg|gif|ico)$" ) {
            access_log off;
        }

        fancyindex on;
        fancyindex_localtime on;
        fancyindex_exact_size off;
        fancyindex_header "/fancyindex/header.html";
        fancyindex_footer "/fancyindex/footer.html";
    }

}

Expected:

print file list

Actually:

Connection timeout on browser.

Try packet dump: If you disconnect from the client by pressing escape in your browser, the server prints the results.

The problem only occurs if fancyindex_header or fancyindex_footer is set. If fancyindex_header and fancyindex_footer are not set, the output is normal. Perhaps it is related to subrequest.

_Here is a good log. (do not set fancyindex_header and fancyindexfooter):

2018/03/12 05:01:46 [debug] 5720#0: accept on 0.0.0.0:80, ready: 0
2018/03/12 05:01:46 [debug] 5720#0: posix_memalign: 0000000001310720:512 @16
2018/03/12 05:01:46 [debug] 5720#0: *3 accept: 172.16.254.2:13742 fd:3
2018/03/12 05:01:46 [debug] 5720#0: *3 event timer add: 3: 60000:1520798566228
2018/03/12 05:01:46 [debug] 5720#0: *3 reusable connection: 1
2018/03/12 05:01:46 [debug] 5720#0: *3 epoll add event: fd:3 op:1 ev:80002001
2018/03/12 05:01:46 [debug] 5720#0: *3 http wait request handler
2018/03/12 05:01:46 [debug] 5720#0: *3 malloc: 00000000012D3F00:1024
2018/03/12 05:01:46 [debug] 5720#0: *3 recv: eof:0, avail:1
2018/03/12 05:01:46 [debug] 5720#0: *3 recv: fd:3 488 of 1024
2018/03/12 05:01:46 [debug] 5720#0: *3 reusable connection: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 posix_memalign: 000000000126CF30:4096 @16
2018/03/12 05:01:46 [debug] 5720#0: *3 http process request line
2018/03/12 05:01:46 [debug] 5720#0: *3 http request line: "GET / HTTP/1.1"
2018/03/12 05:01:46 [debug] 5720#0: *3 http uri: "/"
2018/03/12 05:01:46 [debug] 5720#0: *3 http args: ""
2018/03/12 05:01:46 [debug] 5720#0: *3 http exten: ""
2018/03/12 05:01:46 [debug] 5720#0: *3 http process request header line
2018/03/12 05:01:46 [debug] 5720#0: *3 posix_memalign: 000000000130B4C0:4096 @16
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Host: www.domain.com"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Connection: keep-alive"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Cache-Control: max-age=0"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Authorization: Basic b29wczpza3NhanR3b2RkbDotKA=="
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Upgrade-Insecure-Requests: 1"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "DNT: 1"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Accept-Encoding: gzip, deflate"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header: "Accept-Language: ko-KR,ko;q=0.9,en-US;q=0.8,en;q=0.7"
2018/03/12 05:01:46 [debug] 5720#0: *3 http header done
2018/03/12 05:01:46 [debug] 5720#0: *3 event timer del: 3: 1520798566228
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 1
2018/03/12 05:01:46 [debug] 5720#0: *3 rewrite phase: 2
2018/03/12 05:01:46 [debug] 5720#0: *3 test location: "/"
2018/03/12 05:01:46 [debug] 5720#0: *3 test location: ~ "^/(robots\.txt|favicon\.ico)($|/)"
2018/03/12 05:01:46 [debug] 5720#0: *3 test location: ~ "/nginx-error/error.html"
2018/03/12 05:01:46 [debug] 5720#0: *3 test location: ~ "\.(dat|cfg|orig|org|bak|rpmsave|save|,v|tpl|la?ng|modules?|engines?|install|inc|ini|ph)$"
2018/03/12 05:01:46 [debug] 5720#0: *3 test location: ~ "\.(htaccess|htgroup|htpasswd)"
2018/03/12 05:01:46 [debug] 5720#0: *3 test location: ~ "/(temp|sessions?|class(es)?)/"
2018/03/12 05:01:46 [debug] 5720#0: *3 using configuration "/"
2018/03/12 05:01:46 [debug] 5720#0: *3 http cl:-1 max:1048576
2018/03/12 05:01:46 [debug] 5720#0: *3 rewrite phase: 4
2018/03/12 05:01:46 [debug] 5720#0: *3 http script var
2018/03/12 05:01:46 [debug] 5720#0: *3 http script var: "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"
2018/03/12 05:01:46 [debug] 5720#0: *3 http script regex: "bot"
2018/03/12 05:01:46 [notice] 5720#0: *3 "bot" does not match "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36", client: 172.16.254.2, server: _, request: "GET / HTTP/1.1", host: "www.domain.com"
2018/03/12 05:01:46 [debug] 5720#0: *3 http script if
2018/03/12 05:01:46 [debug] 5720#0: *3 http script if: false
2018/03/12 05:01:46 [debug] 5720#0: *3 http script var
2018/03/12 05:01:46 [debug] 5720#0: *3 http script var: "/home/www/"
2018/03/12 05:01:46 [debug] 5720#0: *3 http script regex: "\.(js|css|png|jpg|jpeg|gif|ico)$"
2018/03/12 05:01:46 [notice] 5720#0: *3 "\.(js|css|png|jpg|jpeg|gif|ico)$" does not match "/home/www/", client: 172.16.254.2, server: _, request: "GET / HTTP/1.1", host: "www.domain.com"
2018/03/12 05:01:46 [debug] 5720#0: *3 http script if
2018/03/12 05:01:46 [debug] 5720#0: *3 http script if: false
2018/03/12 05:01:46 [debug] 5720#0: *3 post rewrite phase: 5
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 6
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 7
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 8
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 9
2018/03/12 05:01:46 [debug] 5720#0: *3 generic phase: 10
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 11
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Username is "sam"
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=0, iteration=0)
2018/03/12 05:01:46 [debug] 5720#0: *3 event timer add: 3: 10000:1520798516238
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: request_timeout=10000
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=1, iteration=0)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Wants a free connection to "ldap.domain.com"
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Search filter is "(&(objectClass=posixAccount)(uid=sam))"
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: ldap_search_ext() -> msgid=11
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Waking authentication request "GET / HTTP/1.1"
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 11
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=1, iteration=1)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=2, iteration=1)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: User DN is "uid=sam,ou=People,dc=domain,dc=com"
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=4, iteration=0)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: ldap_sasl_bind() -> msgid=12
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Waking authentication request "GET / HTTP/1.1"
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 11
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=4, iteration=1)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: User bind successful
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=5, iteration=0)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Rebinding to binddn
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: ldap_sasl_bind() -> msgid=13
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Waking authentication request "GET / HTTP/1.1"
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 11
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=5, iteration=1)
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: binddn bind successful
2018/03/12 05:01:46 [debug] 5720#0: *3 http_auth_ldap: Authentication loop (phase=6, iteration=1)
2018/03/12 05:01:46 [debug] 5720#0: *3 event timer del: 3: 1520798516238
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 12
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 13
2018/03/12 05:01:46 [debug] 5720#0: *3 access phase: 14
2018/03/12 05:01:46 [debug] 5720#0: *3 post access phase: 15
2018/03/12 05:01:46 [debug] 5720#0: *3 content phase: 16
2018/03/12 05:01:46 [debug] 5720#0: *3 content phase: 17
2018/03/12 05:01:46 [debug] 5720#0: *3 open index "/home/www/index.html"
2018/03/12 05:01:46 [debug] 5720#0: *3 stat() "/home/www/index.html" failed (2: No such file or directory)
2018/03/12 05:01:46 [debug] 5720#0: *3 http index check dir: "/home/www"
2018/03/12 05:01:46 [debug] 5720#0: *3 content phase: 18
2018/03/12 05:01:46 [debug] 5720#0: *3 content phase: 19
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex: "/home/www"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file: "."
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file: ".."
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file: "firmware"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex fullpath: "/home/www/firmware"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file owner: "sam1"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex gruop owner: "ldaps"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file: "application"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex fullpath: "/home/www/application"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file owner: "sam1"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex gruop owner: "ldapsers"
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex file: "OS"
2018/03/12 05:01:46 [debug] 5720#0: *3 posix_memalign: 000000000130C4D0:4096 @16
2018/03/12 05:01:46 [debug] 5720#0: *3 headers more header filter, uri "/"
2018/03/12 05:01:46 [debug] 5720#0: *3 HTTP/1.1 200 OK
Date: Sun, 11 Mar 2018 20:01:46 GMT
Content-Type: text/html
Transfer-Encoding: chunked
Connection: keep-alive
Server: nginx

2018/03/12 05:01:46 [debug] 5720#0: *3 write new buf t:1 f:0 000000000130C1B8, pos 000000000130C1B8, size: 158 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 http write filter: l:0 f:0 s:158
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex: adding built-in header
2018/03/12 05:01:46 [debug] 5720#0: *3 http fancyindex: adding built-in footer at 2
2018/03/12 05:01:46 [debug] 5720#0: *3 http output filter "/?"
2018/03/12 05:01:46 [debug] 5720#0: *3 http copy filter: "/?"
2018/03/12 05:01:46 [debug] 5720#0: *3 http postpone filter "/?" 000000000130C388
2018/03/12 05:01:46 [debug] 5720#0: *3 http chunk: 592
2018/03/12 05:01:46 [debug] 5720#0: *3 http chunk: 797
2018/03/12 05:01:46 [debug] 5720#0: *3 http chunk: 14
2018/03/12 05:01:46 [debug] 5720#0: *3 write old buf t:1 f:0 000000000130C1B8, pos 000000000130C1B8, size: 158 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 write new buf t:1 f:0 000000000130C448, pos 000000000130C448, size: 5 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 write new buf t:1 f:0 000000000130C998, pos 000000000130C998, size: 592 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 write new buf t:1 f:0 000000000130C4F0, pos 000000000130C4F0, size: 797 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 write new buf t:1 f:0 000000000130C308, pos 000000000130C308, size: 14 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 write new buf t:0 f:0 0000000000000000, pos 00000000004C42E1, size: 7 file: 0, size: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 http write filter: l:1 f:0 s:1573
2018/03/12 05:01:46 [debug] 5720#0: *3 http write filter limit 0
2018/03/12 05:01:46 [debug] 5720#0: *3 writev: 1573 of 1573
2018/03/12 05:01:46 [debug] 5720#0: *3 http write filter 0000000000000000
2018/03/12 05:01:46 [debug] 5720#0: *3 http copy filter: 0 "/?"
2018/03/12 05:01:46 [debug] 5720#0: *3 http finalize request: 0, "/?" a:1, c:1
2018/03/12 05:01:46 [debug] 5720#0: *3 set http keepalive handler
2018/03/12 05:01:46 [debug] 5720#0: *3 http close request
2018/03/12 05:01:46 [debug] 5720#0: *3 http log handler
2018/03/12 05:01:46 [debug] 5720#0: *3 free: 000000000126CF30, unused: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 free: 000000000130B4C0, unused: 0
2018/03/12 05:01:46 [debug] 5720#0: *3 free: 000000000130C4D0, unused: 1927
2018/03/12 05:01:46 [debug] 5720#0: *3 free: 00000000012D3F00
2018/03/12 05:01:46 [debug] 5720#0: *3 hc free: 0000000000000000
2018/03/12 05:01:46 [debug] 5720#0: *3 hc busy: 0000000000000000 0
2018/03/12 05:01:46 [debug] 5720#0: *3 tcp_nodelay
2018/03/12 05:01:46 [debug] 5720#0: *3 reusable connection: 1
2018/03/12 05:01:46 [debug] 5720#0: *3 event timer add: 3: 60000:1520798566257

_Problem log (set fancyindex_header and fancyindexfooter)

2018/03/12 05:03:33 [debug] 5907#0: accept on 0.0.0.0:80, ready: 0
2018/03/12 05:03:33 [debug] 5907#0: posix_memalign: 00000000016F3F00:512 @16
2018/03/12 05:03:33 [debug] 5907#0: *2 accept: 172.16.254.2:13749 fd:3
2018/03/12 05:03:33 [debug] 5907#0: *2 event timer add: 3: 60000:1520798673036
2018/03/12 05:03:33 [debug] 5907#0: *2 reusable connection: 1
2018/03/12 05:03:33 [debug] 5907#0: *2 epoll add event: fd:3 op:1 ev:80002001
2018/03/12 05:03:33 [debug] 5907#0: *2 http wait request handler
2018/03/12 05:03:33 [debug] 5907#0: *2 malloc: 00000000016F4110:1024
2018/03/12 05:03:33 [debug] 5907#0: *2 recv: eof:0, avail:1
2018/03/12 05:03:33 [debug] 5907#0: *2 recv: fd:3 488 of 1024
2018/03/12 05:03:33 [debug] 5907#0: *2 reusable connection: 0
2018/03/12 05:03:33 [debug] 5907#0: *2 posix_memalign: 000000000168CF30:4096 @16
2018/03/12 05:03:33 [debug] 5907#0: *2 http process request line
2018/03/12 05:03:33 [debug] 5907#0: *2 http request line: "GET / HTTP/1.1"
2018/03/12 05:03:33 [debug] 5907#0: *2 http uri: "/"
2018/03/12 05:03:33 [debug] 5907#0: *2 http args: ""
2018/03/12 05:03:33 [debug] 5907#0: *2 http exten: ""
2018/03/12 05:03:33 [debug] 5907#0: *2 http process request header line
2018/03/12 05:03:33 [debug] 5907#0: *2 posix_memalign: 000000000172B4C0:4096 @16
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Host: www.domain.com"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Connection: keep-alive"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Cache-Control: max-age=0"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Authorization: Basic b29wczpza3NhanR3b2RkbDotKA=="
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Upgrade-Insecure-Requests: 1"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "DNT: 1"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Accept-Encoding: gzip, deflate"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header: "Accept-Language: ko-KR,ko;q=0.9,en-US;q=0.8,en;q=0.7"
2018/03/12 05:03:33 [debug] 5907#0: *2 http header done
2018/03/12 05:03:33 [debug] 5907#0: *2 event timer del: 3: 1520798673036
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 0
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 1
2018/03/12 05:03:33 [debug] 5907#0: *2 rewrite phase: 2
2018/03/12 05:03:33 [debug] 5907#0: *2 test location: "/"
2018/03/12 05:03:33 [debug] 5907#0: *2 test location: ~ "^/(robots\.txt|favicon\.ico)($|/)"
2018/03/12 05:03:33 [debug] 5907#0: *2 test location: ~ "/nginx-error/error.html"
2018/03/12 05:03:33 [debug] 5907#0: *2 test location: ~ "\.(dat|cfg|orig|org|bak|rpmsave|save|,v|tpl|la?ng|modules?|engines?|install|inc|ini|ph)$"
2018/03/12 05:03:33 [debug] 5907#0: *2 test location: ~ "\.(htaccess|htgroup|htpasswd)"
2018/03/12 05:03:33 [debug] 5907#0: *2 test location: ~ "/(temp|sessions?|class(es)?)/"
2018/03/12 05:03:33 [debug] 5907#0: *2 using configuration "/"
2018/03/12 05:03:33 [debug] 5907#0: *2 http cl:-1 max:1048576
2018/03/12 05:03:33 [debug] 5907#0: *2 rewrite phase: 4
2018/03/12 05:03:33 [debug] 5907#0: *2 http script var
2018/03/12 05:03:33 [debug] 5907#0: *2 http script var: "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"
2018/03/12 05:03:33 [debug] 5907#0: *2 http script regex: "bot"
2018/03/12 05:03:33 [notice] 5907#0: *2 "bot" does not match "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36", client: 172.16.254.2, server: _, request: "GET / HTTP/1.1", host: "www.domain.com"
2018/03/12 05:03:33 [debug] 5907#0: *2 http script if
2018/03/12 05:03:33 [debug] 5907#0: *2 http script if: false
2018/03/12 05:03:33 [debug] 5907#0: *2 http script var
2018/03/12 05:03:33 [debug] 5907#0: *2 http script var: "/home/www/"
2018/03/12 05:03:33 [debug] 5907#0: *2 http script regex: "\.(js|css|png|jpg|jpeg|gif|ico)$"
2018/03/12 05:03:33 [notice] 5907#0: *2 "\.(js|css|png|jpg|jpeg|gif|ico)$" does not match "/home/www/", client: 172.16.254.2, server: _, request: "GET / HTTP/1.1", host: "www.domain.com"
2018/03/12 05:03:33 [debug] 5907#0: *2 http script if
2018/03/12 05:03:33 [debug] 5907#0: *2 http script if: false
2018/03/12 05:03:33 [debug] 5907#0: *2 post rewrite phase: 5
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 6
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 7
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 8
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 9
2018/03/12 05:03:33 [debug] 5907#0: *2 generic phase: 10
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 11
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Username is "sam"
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=0, iteration=0)
2018/03/12 05:03:33 [debug] 5907#0: *2 event timer add: 3: 10000:1520798623044
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: request_timeout=10000
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=1, iteration=0)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Wants a free connection to "ldap.domain.com"
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Search filter is "(&(objectClass=posixAccount)(uid=sam))"
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: ldap_search_ext() -> msgid=2
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Waking authentication request "GET / HTTP/1.1"
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 11
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=1, iteration=1)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=2, iteration=1)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: User DN is "uid=sam,ou=People,dc=domain,dc=com"
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=4, iteration=0)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: ldap_sasl_bind() -> msgid=3
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Waking authentication request "GET / HTTP/1.1"
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 11
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=4, iteration=1)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: User bind successful
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=5, iteration=0)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Rebinding to binddn
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: ldap_sasl_bind() -> msgid=4
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Waking authentication request "GET / HTTP/1.1"
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 11
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=5, iteration=1)
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: binddn bind successful
2018/03/12 05:03:33 [debug] 5907#0: *2 http_auth_ldap: Authentication loop (phase=6, iteration=1)
2018/03/12 05:03:33 [debug] 5907#0: *2 event timer del: 3: 1520798623044
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 12
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 13
2018/03/12 05:03:33 [debug] 5907#0: *2 access phase: 14
2018/03/12 05:03:33 [debug] 5907#0: *2 post access phase: 15
2018/03/12 05:03:33 [debug] 5907#0: *2 content phase: 16
2018/03/12 05:03:33 [debug] 5907#0: *2 content phase: 17
2018/03/12 05:03:33 [debug] 5907#0: *2 open index "/home/www/index.html"
2018/03/12 05:03:33 [debug] 5907#0: *2 stat() "/home/www/index.html" failed (2: No such file or directory)
2018/03/12 05:03:33 [debug] 5907#0: *2 http index check dir: "/home/www"
2018/03/12 05:03:33 [debug] 5907#0: *2 content phase: 18
2018/03/12 05:03:33 [debug] 5907#0: *2 content phase: 19
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex: "/home/www"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file: "."
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file: ".."
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file: "firmware"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex fullpath: "/home/www/firmware"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file owner: "sam1"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex gruop owner: "ldaps"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file: "application"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex fullpath: "/home/www/application"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file owner: "sam1"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex gruop owner: "ldaps"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex file: "OS"
2018/03/12 05:03:33 [debug] 5907#0: *2 posix_memalign: 000000000172C4D0:4096 @16
2018/03/12 05:03:33 [debug] 5907#0: *2 headers more header filter, uri "/"
2018/03/12 05:03:33 [debug] 5907#0: *2 HTTP/1.1 200 OK
Date: Sun, 11 Mar 2018 20:03:33 GMT
Content-Type: text/html
Transfer-Encoding: chunked
Connection: keep-alive
Server: nginx

2018/03/12 05:03:33 [debug] 5907#0: *2 write new buf t:1 f:0 000000000172C1B8, pos 000000000172C1B8, size: 158 file: 0, size: 0
2018/03/12 05:03:33 [debug] 5907#0: *2 http write filter: l:0 f:0 s:158
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex: header subrequest "/fancyindex/header.html"
2018/03/12 05:03:33 [debug] 5907#0: *2 http subrequest "/fancyindex/header.html?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex: header subrequest status = 0
2018/03/12 05:03:33 [debug] 5907#0: *2 http output filter "/?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http copy filter: "/?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http postpone filter "/?" 00007FFCB090F250
2018/03/12 05:03:33 [debug] 5907#0: *2 http copy filter: 0 "/?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex: footer subrequest "/fancyindex/footer.html"
2018/03/12 05:03:33 [debug] 5907#0: *2 posix_memalign: 000000000172D4E0:4096 @16
2018/03/12 05:03:33 [debug] 5907#0: *2 http subrequest "/fancyindex/footer.html?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http fancyindex: header subrequest status = 0
2018/03/12 05:03:33 [debug] 5907#0: *2 http output filter "/?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http copy filter: "/?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http postpone filter "/?" 00007FFCB090F1F0
2018/03/12 05:03:33 [debug] 5907#0: *2 http copy filter: 0 "/?"
2018/03/12 05:03:33 [debug] 5907#0: *2 http finalize request: 0, "/?" a:0, c:3
2018/03/12 05:03:33 [debug] 5907#0: *2 event timer add: 3: 60000:1520798673064
Joungkyun commented 6 years ago

I did not have much time, so I was not sure whether this was a problem with nginx-auth-ldap or ngx-fancyindex.

However, I fixed the problem by modifying ngx-fancyindex. See also https://github.com/aperezdc/ngx-fancyindex/pull/83