Apache2 ignores "authorization result of <RequireAny>: denied (no authenticated user yet)" and let random user to login

Question

I am trying to figure out why Apache2 ignores "authorization result of : denied (no authenticated user yet)" and let random user to login.

Apache vhost config is :

<VirtualHost *:443>
  ServerName vmntopng01.mgmt.local

  ## Vhost docroot
  DocumentRoot "/var/www"

  ## Directories, there should at least be a declaration for /var/www

  <Directory "/var/www">
    ## Options FollowSymlinks
    AllowOverride None
    Require all denied
    Require valid-user granted
    Require ldap-group CN=ACS-ntopng-admin,OU=Groups,OU=Company,DC=berlin-hq,DC=local granted
    AuthType Basic
    AuthName "ntopng"
    AuthBasicProvider ldap
    AuthLDAPURL "ldaps://ldap.coast.local/DC=berlin-hq,DC=local?sAMAccountName?sub?(objectClass=*)"
    AuthLDAPBindDN "CN=authldap.ntopng,OU=System-User,OU=Company,DC=berlin-hq,DC=local"
    AuthLDAPBindPassword "xxxxxxxxxxxxx"
  </Directory>

  ## Logging
  LogLevel debug
  ErrorLog "/var/log/apache2/ntopng_error_ssl.log"
  ServerSignature Off
  CustomLog "/var/log/apache2/ntopng_access_ssl.log" combined

  ## Server aliases
  ServerAlias ntopng.mgmt.local
  ServerAlias ntopng.coast.local

  ## SSL directives
  SSLEngine on
  SSLCertificateFile      "/etc/apache2/certs/vmntopng01.mgmt.local.pem"
  SSLCertificateKeyFile   "/etc/apache2/certs/vmntopng01.mgmt.local.key"
  SSLCertificateChainFile "/etc/apache2/certs/ca.pem"
</VirtualHost>

In the apache2 logs I see such events:

==> /var/log/apache2/ntopng_ssl_redirect_access.log.1 <==
10.128.130.151 - - [15/Aug/2019:11:35:34 +0200] "GET / HTTP/1.1" 301 242 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0"

==> /var/log/apache2/ntopng_error_ssl.log <==
[Thu Aug 15 11:35:34.794789 2019] [ssl:info] [pid 14190:tid 140114248333056] [client 10.128.130.151:51305] AH01964: Connection to child 65 established (server vmntopng01.mgmt.local:443)
[Thu Aug 15 11:35:34.795183 2019] [socache_shmcb:debug] [pid 14190:tid 140114248333056] mod_socache_shmcb.c(532): AH00835: socache_shmcb_retrieve (0x7a -> subcache 26)
[Thu Aug 15 11:35:34.795215 2019] [socache_shmcb:debug] [pid 14190:tid 140114248333056] mod_socache_shmcb.c(917): AH00851: shmcb_subcache_retrieve found no match
[Thu Aug 15 11:35:34.795221 2019] [socache_shmcb:debug] [pid 14190:tid 140114248333056] mod_socache_shmcb.c(542): AH00836: leaving socache_shmcb_retrieve successfully
[Thu Aug 15 11:35:34.795247 2019] [ssl:debug] [pid 14190:tid 140114248333056] ssl_engine_kernel.c(2115): [client 10.128.130.151:51305] AH02043: SSL virtual host for servername vmntopng01.mgmt.local found
[Thu Aug 15 11:35:34.795321 2019] [ssl:debug] [pid 14190:tid 140114248333056] ssl_engine_kernel.c(2115): [client 10.128.130.151:51305] AH02043: SSL virtual host for servername vmntopng01.mgmt.local found
[Thu Aug 15 11:35:34.795339 2019] [core:debug] [pid 14190:tid 140114248333056] protocol.c(2219): [client 10.128.130.151:51305] AH03155: select protocol from , choices=h2,http/1.1 for server vmntopng01.mgmt.local
[Thu Aug 15 11:35:34.804699 2019] [ssl:debug] [pid 14190:tid 140114248333056] ssl_engine_kernel.c(2042): [client 10.128.130.151:51305] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Thu Aug 15 11:35:34.805943 2019] [ssl:debug] [pid 14190:tid 140114248333056] ssl_engine_kernel.c(366): [client 10.128.130.151:51305] AH02034: Initial (No.1) HTTPS request received for child 65 (server vmntopng01.mgmt.local:443)
[Thu Aug 15 11:35:34.805993 2019] [authz_core:debug] [pid 14190:tid 140114248333056] mod_authz_core.c(809): [client 10.128.130.151:51305] AH01626: authorization result of Require all denied: denied
[Thu Aug 15 11:35:34.806008 2019] [authz_core:debug] [pid 14190:tid 140114248333056] mod_authz_core.c(809): [client 10.128.130.151:51305] AH01626: authorization result of Require valid-user granted: denied (no authenticated user yet)
[Thu Aug 15 11:35:34.806015 2019] [authz_core:debug] [pid 14190:tid 140114248333056] mod_authz_core.c(809): [client 10.128.130.151:51305] AH01626: authorization result of Require ldap-group CN=ACS-ntopng-admin,OU=Groups,OU=Company,DC=berlin-hq,DC=local granted: denied (no authenticated user yet)
[Thu Aug 15 11:35:34.806020 2019] [authz_core:debug] [pid 14190:tid 140114248333056] mod_authz_core.c(809): [client 10.128.130.151:51305] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)

==> /var/log/apache2/ntopng_access_ssl.log <==
10.128.130.151 - - [15/Aug/2019:11:35:34 +0200] "GET / HTTP/1.1" 401 381 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0"

==> /var/log/apache2/ntopng_error_ssl.log <==
[Thu Aug 15 11:35:34.806174 2019] [ssl:debug] [pid 14190:tid 140114248333056] ssl_engine_io.c(1044): [client 10.128.130.151:51305] AH02001: Connection closed to child 65 with standard shutdown (server vmntopng01.mgmt.local:443)








==> /var/log/apache2/ntopng_access_ssl.log.1 <==
10.128.130.151 - - [15/Aug/2019:11:35:46 +0200] "GET / HTTP/1.1" 200 626 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0"
10.128.130.151 - - [15/Aug/2019:11:35:46 +0200] "GET /favicon.ico HTTP/1.1" 200 2937 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0"

So you could see successful "GET / HTTP/1.1" 200" follows the ": denied (no authenticated user yet)".

Any advises are appreciated.

Answer 1

It's a hard to explain, but after whole host restart everything started working as intended. I see the only explanation, that before the restart something in the system has cached incorrect LDAP information, so access control was not working properly.