Active Directory Authentication showing "Internal Server Error"

[jmgascoriego]

Hi Marc,

After the issue #2, I'm unable to login with an AD user account. Every time that I try the logon, the application is giving an "Internal Server Error" and it seems the website is not fully loaded:

https://imgur.com/ImVuE3V

These are my settings for the LDAP server:

Server: 192.168.126.23
Enabled: True
Type: MS Active Directory
Protocol: LDAPS
Port: 636
Bind DN: <service_account>@<domain_name>
Base DN: OU=<OU_Name>,DC=<domain_name>,DC=<root_domain>
Username Attribute: sAMAccountName
LDAP filter: objectClass=*

In my case, I am using LDAP Groups:

Enabled: True
DN: CN=<AD_Security_Group_name>,<OU_Name>,DC=<domain_name>,DC=<root_domain>
LDAP Server: <LDAP_Server_Name>
User Group: GestioIP Admin

I have tested the service account and it can read correctly objects in Active Directory, so I doubt it's a permissions issue.
I also have tried to check error logs in the container during the login process, but I can't find anything.

Checking the domain controller security events, it's like GestioIP is not even sending the authentication request to the AD as no failure or success event is identified. Both, AD and Docker host where GestioIP is running are using the same subnet, so there is no FW in between.

Not sure what else should I check.

Thank you,
Kind regards.

[muebel]

Hi jmgascoriego
I'm not able to reproduce this issue. In my deployment LDAP group authentication against an AD is working.
In theory there should appear some related messages in the apache error log. Please try again to fetch some logs: execute "docker logs -f gip", then try to login with an AD user. Do there appear any new log messages?
Thank you!

[jmgascoriego]

Hi Marc,

I've tried to follow the container logs while authenticating, but nothing is showing up. Inside the container, tailing the file /var/log/other_vhosts_access.log, I can see the requests:

172.18.0.2:80 192.168.126.126 - - [17/Feb/2021:19:19:29 +0000] "POST / HTTP/1.1" 500 9449 "http://192.168.126.180:3080/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.182 Safari/537.36"
172.18.0.2:80 192.168.126.126 - - [17/Feb/2021:19:19:29 +0000] "GET /gestioip/errors/stylesheet.css HTTP/1.1" 200 4921 "http://192.168.126.180:3080/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.182 Safari/537.36"
172.18.0.2:80 192.168.126.126 - - [17/Feb/2021:19:19:29 +0000] "GET /imagenes/style/bg_topbox.jpg HTTP/1.1" 401 3745 "http://192.168.126.180:3080/gestioip/errors/stylesheet.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.182 Safari/537.36"
172.18.0.2:80 192.168.126.126 - - [17/Feb/2021:19:19:29 +0000] "GET /imagenes/style/search_field_bg.jpg HTTP/1.1" 401 3746 "http://192.168.126.180:3080/gestioip/errors/stylesheet.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.182 Safari/537.36"
172.18.0.2:80 192.168.126.126 - - [17/Feb/2021:19:19:29 +0000] "GET /imagenes/lupe.png HTTP/1.1" 401 3745 "http://192.168.126.180:3080/gestioip/errors/stylesheet.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.182 Safari/537.36"
172.18.0.2:80 192.168.126.126 - - [17/Feb/2021:19:19:29 +0000] "GET /gestioip/favicon.ico HTTP/1.1" 401 3745 "http://192.168.126.180:3080/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.182 Safari/537.36"

That's all what I can get about logs.
I have user management enabled in the global configuration, is it your case as well?

Thanks!

[jmgascoriego]

Hi Marc,

I have deployed a brand new gip/gip-mysql instance on a brand new docker host:

# docker ps -a
CONTAINER ID        IMAGE                     COMMAND                  CREATED             STATUS              PORTS                                      NAMES
030aba7e9688        gestioip/gestioip:35510   "/gestioip_install/s…"   13 minutes ago      Up 12 minutes       0.0.0.0:3080->80/tcp                       gip
9ac8cc929058        mysql:5                   "docker-entrypoint.s…"   13 minutes ago      Up 12 minutes       3306/tcp, 33060/tcp                        gip-mysql

As soon as you try to login with the user AD account (username or username@domain format), I am getting this "Internal Server Error" in the application.
Checking docker logs, I can only see the logs related to the LDAP and LDAP Group configuration. During the authentication process, no log is generated.

# docker logs -f gip
 * Stopping internet superserver xinetd
   ...done.
 * Starting internet superserver xinetd
   ...done.
System has not been booted with systemd as init system (PID 1). Can't operate.
Failed to connect to bus: Host is down
Synchronizing state of vsftpd.service with SysV service script with /lib/systemd/systemd-sysv-install.
Executing: /lib/systemd/systemd-sysv-install disable vsftpd
Removed /etc/systemd/system/multi-user.target.wants/vsftpd.service.
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message
[Mon Feb 22 11:30:26.306705 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00489: Apache/2.4.41 (Ubuntu) mod_perl/2.0.11 Perl/v5.30.0 configured -- resuming normal operations
[Mon Feb 22 11:30:26.306851 2021] [core:notice] [pid 45:tid 139762663439424] AH00094: Command line: '/usr/sbin/apache2 -D FOREGROUND'
[Mon Feb 22 11:35:13.936600 2021] [cgi:error] [pid 46:tid 139762362922752] [client 192.168.126.126:51912] AH01215: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message: /var/www/html/gestioip/res/ip_insert_ldap_server.cgi, referer: http://192.168.126.37:3080/res/ip_check_ldap_server.cgi
[Mon Feb 22 11:35:13.936649 2021] [cgi:error] [pid 46:tid 139762362922752] [client 192.168.126.126:51912] AH01215: Syntax OK: /var/www/html/gestioip/res/ip_insert_ldap_server.cgi, referer: http://192.168.126.37:3080/res/ip_check_ldap_server.cgi
[Mon Feb 22 11:35:13.961751 2021] [cgi:error] [pid 46:tid 139762362922752] [client 192.168.126.126:51912] AH01215:  * Reloading Apache httpd web server apache2: /var/www/html/gestioip/res/ip_insert_ldap_server.cgi, referer: http://192.168.126.37:3080/res/ip_check_ldap_server.cgi
[Mon Feb 22 11:35:14.138809 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00493: SIGUSR1 received.  Doing graceful restart
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message
[Mon Feb 22 11:35:14.150761 2021] [cgi:error] [pid 46:tid 139762362922752] [client 192.168.126.126:51912] AH01215:  * : /var/www/html/gestioip/res/ip_insert_ldap_server.cgi, referer: http://192.168.126.37:3080/res/ip_check_ldap_server.cgi
[Mon Feb 22 11:35:14.158412 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00489: Apache/2.4.41 (Ubuntu) mod_perl/2.0.11 Perl/v5.30.0 configured -- resuming normal operations
[Mon Feb 22 11:35:14.158437 2021] [core:notice] [pid 45:tid 139762663439424] AH00094: Command line: '/usr/sbin/apache2 -D FOREGROUND'
[Mon Feb 22 11:35:30.796121 2021] [cgi:error] [pid 145:tid 139761448642304] [client 192.168.126.126:51935] AH01215: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message: /var/www/html/gestioip/res/ip_insert_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_insert_ldap_group_form.cgi?client_id=1
[Mon Feb 22 11:35:30.796169 2021] [cgi:error] [pid 145:tid 139761448642304] [client 192.168.126.126:51935] AH01215: Syntax OK: /var/www/html/gestioip/res/ip_insert_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_insert_ldap_group_form.cgi?client_id=1
[Mon Feb 22 11:35:30.820139 2021] [cgi:error] [pid 145:tid 139761448642304] [client 192.168.126.126:51935] AH01215:  * Reloading Apache httpd web server apache2: /var/www/html/gestioip/res/ip_insert_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_insert_ldap_group_form.cgi?client_id=1
[Mon Feb 22 11:35:31.000198 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00493: SIGUSR1 received.  Doing graceful restart
[Mon Feb 22 11:35:31.011683 2021] [cgi:error] [pid 145:tid 139761448642304] [client 192.168.126.126:51935] AH01215:  * : /var/www/html/gestioip/res/ip_insert_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_insert_ldap_group_form.cgi?client_id=1
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message
[Mon Feb 22 11:35:31.020947 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00489: Apache/2.4.41 (Ubuntu) mod_perl/2.0.11 Perl/v5.30.0 configured -- resuming normal operations
[Mon Feb 22 11:35:31.020964 2021] [core:notice] [pid 45:tid 139762663439424] AH00094: Command line: '/usr/sbin/apache2 -D FOREGROUND'
[Mon Feb 22 11:35:57.046236 2021] [cgi:error] [pid 257:tid 139761238923008] [client 192.168.126.126:51958] AH01215: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message: /var/www/html/gestioip/res/ip_mod_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_mod_ldap_group_form.cgi
[Mon Feb 22 11:35:57.046284 2021] [cgi:error] [pid 257:tid 139761238923008] [client 192.168.126.126:51958] AH01215: Syntax OK: /var/www/html/gestioip/res/ip_mod_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_mod_ldap_group_form.cgi
[Mon Feb 22 11:35:57.071181 2021] [cgi:error] [pid 257:tid 139761238923008] [client 192.168.126.126:51958] AH01215:  * Reloading Apache httpd web server apache2: /var/www/html/gestioip/res/ip_mod_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_mod_ldap_group_form.cgi
[Mon Feb 22 11:35:57.247711 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00493: SIGUSR1 received.  Doing graceful restart
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message
[Mon Feb 22 11:35:57.259103 2021] [cgi:error] [pid 257:tid 139761238923008] [client 192.168.126.126:51958] AH01215:  * : /var/www/html/gestioip/res/ip_mod_ldap_group.cgi, referer: http://192.168.126.37:3080/res/ip_mod_ldap_group_form.cgi
[Mon Feb 22 11:35:57.266599 2021] [mpm_event:notice] [pid 45:tid 139762663439424] AH00489: Apache/2.4.41 (Ubuntu) mod_perl/2.0.11 Perl/v5.30.0 configured -- resuming normal operations
[Mon Feb 22 11:35:57.266614 2021] [core:notice] [pid 45:tid 139762663439424] AH00094: Command line: '/usr/sbin/apache2 -D FOREGROUND'

Not sure how we can troubleshoot this directly inside the container.

Going back to the AD, my service account is a member of the default "Domain Users" group with the default "Read all properties" permission at domain level. I have other applications integrated with this domain and working without any issue.
Is there any additional permission that I must grant to this service account?

Thank you.

[muebel]

Thank you for that information.

Do you have multiple active LDAP groups configured?

[jmgascoriego]

Hi Marc,

No, I just have the one defined in OP.

Thank you!

[muebel]

Hi
you can rise the apache log level:
Access to the container:
docker exec -it gip bash
Open /etc/apache2/apache2.conf with an editor and set "LogLevel=debug":
Restart Apache:
/etc/init.d/apache2 restart

Then display again the logs with "docker logs -f gip" and try the login again.

Regards

[muebel]

Please try also the following:

Access, to the container, open the file /etc/apache2/sites-available/gestioip.conf with an editor and change the line

            AuthFormProvider file

to

            AuthFormProvider file ldap

Then restart the apache web server and check if the LDAP authentication error persists.

[jmgascoriego]

Hi Marc,

Thanks a lot for all those suggestions. Enabling the debugging mode in Apache provides better visibility of the errors. After some troubleshooting, I think I'm on the way to get it fixed, but I'm not there yet.
Checking the Apache debugging logs, I could see something interesting. If the BindDN string contains a "space" (because my OU naming convention follows a bad practice, I know), the application automatically translates the "space" to a "+" symbol.
I think this unexpected symbol breaks the LDAP URI. However, this behaviour doesn't happen with the LDAP group definition. If the LDAP group DN contains a space in the string, the GUI respects it.

Even fixing the above finding manually inside the container, I can't connect with the AD user yet, but I'm no longer receiving the "Internal Server Error". It just keeps asking you for user and password on the login page while I'm getting the below error in the logs:

[Tue Feb 23 19:09:12.672872 2021] [authnz_ldap:info] [pid 11:tid 139877437904640] [client 192.168.126.126:59896] AH01695: auth_ldap authenticate: user a-jmgr authentication failed; URI / [ldap_search_ext_s() for user failed][No such object], referer: http://192.168.126.37:3080/

Comparing the above error with a ldapsearch request using the same parameters that I can see in the LDAP URI string, I'm getting a successful output:

root@4cf89f8c72c2:/gestioip_install# ldapsearch -LLL -H ldap://192.168.126.23:389 -b 'OU=<OU_Name_with_space>,DC=<domain_name>,DC=<root_domain>' -D '<service_account>@<domain>' -w '<password>' '(objectClass=*)' | grep a-jmgr
sAMAccountName: a-jmgr
userPrincipalName: a-jmgr@<domain>

I'm still not sure about the root cause, but I will continue troubleshooting and testing.

Regarding the AuthFormProvider parameter, I can see it included already when you configure the LDAP server:

root@4cf89f8c72c2:/gestioip_install# cat /usr/share/gestioip/etc/apache/apache_ldap.conf
    AuthFormProvider file ldap

However, it's also present by default in /etc/apache2/sites-enabled/gestioip.conf as below:

AuthFormProvider file

Deleting the line from gestioip.conf doesn't make any difference.

In parallel, I have noticed that if you redeploy gip container keeping MySQL DB container alive, GestioIP shows the LDAP server configuration is correctly defined. Still, the configuration itself is missing in the container conf files. Maybe something to look at afterwards:

[root@docker gestioip-docker-compose]# docker ps -a
CONTAINER ID   IMAGE                     COMMAND                  CREATED         STATUS         PORTS                                      NAMES
4cf89f8c72c2   gestioip/gestioip:35510   "/gestioip_install/s…"   31 seconds ago   Up 30 seconds   0.0.0.0:3080->80/tcp                       gip
9ac8cc929058   mysql:5                   "docker-entrypoint.s…"   31 hours ago    Up 24 hours    3306/tcp, 33060/tcp                        gip-mysql
[root@docker gestioip-docker-compose]# docker exec gip cat /usr/share/gestioip/etc/apache/apache_ldap.conf
#    AuthFormProvider file ldap
#    AuthLDAPBindDN uid=user,ou=People,dc=example,dc=com
#    AuthLDAPBindPassword xxxxxx
#    AuthLDAPUrl "LDAP://ldap_server:389/dc=example,dc=com?uid" NONE
#    AuthLDAPGroupAttribute member uniqueMember memberUid

# Default values
#    AuthLDAPGroupAttribute member uniqueMember
#    AuthLDAPGroupAttributeIsDN on
#    AuthLDAPMaxSubGroupDepth 10
#    AuthLDAPSubGroupAttribute memberUid
#    AuthLDAPSubGroupClass posixgroup

GUI LDAP Server section view: https://imgur.com/UJNAG3U

I just need to delete the current configuration from the GUI and recreate it again.

Sorry for the long update, but I wanted to share as many details as possible.

Thank you!

[muebel]

Hi jmgascoriego

Thank you very much for this information.

I'm made some more tests, and noticed also login problems. In my deployment, they seem to be in relation with the line

AuthFormProvider file

In my case I changed the line to

AuthFormProvider file ldap

and deleted the line from /usr/share/gestioip/etc/apache/apache_ldap.conf

After this the authentication with an LDAP user group is working.

I will make some more tests and tell you something.

Also may thanks for advising the issue with the "+"/whitespace. This will be fixed in the next days.

I was able to reproduce the redeploy issue. I will also have a look at this issue.

Regards,

[muebel]

Hi jmgascoriego
I just updated the gip image with a new Apache configuration, using now only a AuthFormProvider directive in gestioip.conf. mod_ldap is now enabled by default.
I tried the AD LDAP authentification with one and multiple groups and did not noticed any errors. Please try if the new image resolves the issue for you.
The new version also fixes the DN-"+" error.
Thank you!
Marc

[jmgascoriego]

Hi Marc,

I'm happy to confirm that it's working perfectly with the latest version.
Many thanks for all your support!

[muebel]

Hi jmgascoriego
I'm happy to hear that!
Thanks a lot for your support to debug this issue.

A new version, resolving the problem, that the content of the files in /usr/share/gestioip/etc/apache is reset to the default values after a redeploy, will be released, soon.

Best regards

[jmgascoriego]

Hi Marc,

Appreciated your time fixing these bugs. I will be happy to test the new container once is ready.

Thanks!

[cairoapcampos]

@muebel @jmgascoriego I was having problems using reverse proxy with GestioIP. So I created the containers again and didn't use a proxy. I created self-signed certificates and set the url to https://localhost. When I login with the default username and password I get the message below. On the GestioIp screen it shows "Internal Server Error". It's like I logged in with the wrong username and password.

gip          | [Thu Feb 23 18:35:40.994828 2023] [authn_file:error] [pid 89:tid 139629487437568] (2)No such file or directory: [client 10.20.0.1:54888] AH01620: Could not open password file: /etc/apache2/users-gestioip, referer: https://localhost/

When I don't use ssl this error doesn't happen.

[cairoapcampos]

I created a new Dockerfile with few lines. It looks like it solved the problem for now. I will run more tests.

FROM gestioip/gestioip:3570

COPY conf/ /usr/share/gestioip/etc/apache/
RUN ln -s /usr/share/gestioip/etc/apache/users-gestioip /etc/apache2/users-gestioip