LDAP Auth not invoked

[chris001]

Can you set APP_ENV=qa, this should provide additional detail, and report back your results?

[maverickws]

# cat .env | grep APP_ENV
#  * .env.$APP_ENV       committed environment-specific defaults
#  * .env.$APP_ENV.local uncommitted environment-specific overrides
APP_ENV=qa

Login credentials incorrect, please try again.

No entries on either logs/prod/prod.log or public/legacy/suitecrm.log

EDIT:
To test I performed the following steps

1. edited .env
2. ran bin/console cache:clear and bin/console cache:pool:clear cache.global_clearer
   tried to login.

I would also like to add that in the course of debugging this situation I have created multiple .env files, such as:

$ ls -la .env*
-rw-r--r--. 1 apache apache 1932 Jan 25 17:54 .env
-rw-r--r--. 1 apache apache  889 Jan 23 17:20 .env.local
-rw-r--r--. 1 apache apache  889 Jan 23 17:27 .env.prod.local
-rw-r--r--. 1 apache apache  889 Jan 23 17:32 .env.qa.local

The locals are all copy of the original .local

[pgr]

I didn’t know about the qa environment, but I do know that the dev environment gives you access to elaborate error messages with full stack traces (I find these most useful for this kind of forum troubleshooting, I can go look at the actual code without having to set up a complex environment and trying to reproduce on my local).

However, the last few people whom I told to change to dev got a broken system with a Doctrine error. I believe this can be solved, I’ve solved it myself, but it was a long time ago and I don’t remember what it was. Maybe installing the dev package to get the dist precompiled folder, maybe running composer to update packages to better match the dev environment, maybe something else. Maybe it’s something as simple as giving the DB credentials in the .dev.env file.

@maverickws it’s up to you if want to try yet another environment, and go through the trouble of getting it to work, but I do think that might provide more information…

[chris001]

It’s several yarn commands + other commands, to get APP_ENV=dev to work and show more detailed error info:

Installing SuiteCRM 8 Development mode

[image] I’m trying to install Suite8 using the developer guide (for dev environment) and I’m getting this error while launching the command : yarn run build-dev:shell Developer Install Guide :: SuiteCRM Documentation

[pgr]

@chris001, but that is to set up the full dev environment that is able to compile the front end. That dev package I mentioned is meant to avoid that by providing a precompiled dist directory and some other bits. We won’t need to compile the front-end, just get Symfony to go trough the dev environment so it provides more detailed output…

[chris001]

Here’s the steps to install and setup dev mode (APP_ENV=dev) properly:

SuiteCRM 8.5 Live server with ng serve

Hey @wiFiriFi, Welcome to the community If you download the base package it doesn’t include the dist folder, which is needed for building the front end. For frontend development they provide a dev package that includes the dist folder, you can find it on the github release: Release 8.5.0 · salesagility/SuiteCRM-Core · GitHub SuiteCRM-8.5.0-dev.zip The dev package = base package + the dist folder. I don’t think ng serve is supported. They recommend using the build command with -…

if you would setup this dev mode as explained in the post above @maverickws and report back your more detailed error messages when the LDAP login fails to login on 8.5.

[maverickws]

I’m sorry I’m not a developer, someone f*cks up and I have to go and install dev releases, setup full development environments and whatever?
How about you install a freeipa server which is quite easy and test yourself? It’s free open source software.

This is not my work, I’ve done plenty of testing already, took hours from my day I should be working for this. Having to setup a full development environment just because this doesn’t generate proper log output is ridiculous.
If the stanza is to leave errors in the app until final users do all the work for you, then I’m just going back to 8.4.1 until I find some other solution for CRM.
As I’ve stated many times before, and I will stress it again, I am not a developer, I was evaluating SuiteCRM for inclusion in projects, and the whole lifecycle of this issue and these requests, make it clear that this is not suitable for anything.

[emanuele]

I’m also testing SuiteCRM as an Open Source alternative to SugarCRM (and unfortunately I don’t have a lot of time 'cause I’m testing the product for my company and can squeeze a few hours out of normal activities).

[maverickws]

Following up on a request/suggestion from @pgr I’ve done the following test:

1. APP_ENV is “qa” - and cleared caches
2. Go to SuiteCRM with developer tools/inspector/console open
3. Try to login and get the error
4. Check for errors

There isn’t much “extended information”. There is only a

Failed to load resource: the server responded with a status of 401 (Unauthorized)
Login failed

Screenshot attached.

[emanuele]

I had done this test before. Same result.

[maverickws]

I was looking at the logs on the LDAP server side

SuiteCRM requests come like this:

[26/Jan/2024:12:59:41.190646024 +0000] conn=64347 fd=253 slot=253 connection from 1.1.1.1(crm-server-ip) to 2.2.2.2(idm-server-ip)
[26/Jan/2024:12:59:41.191192457 +0000] conn=64347 op=0 EXT oid="1.3.6.1.4.1.1466.20037" name="start_tls_plugin"
[26/Jan/2024:12:59:41.191280241 +0000] conn=64347 op=0 RESULT err=0 tag=120 nentries=0 wtime=0.000358914 optime=0.000129024 etime=0.000486443
[26/Jan/2024:12:59:41.228051635 +0000] conn=64347 TLS1.3 128-bit AES-GCM
[26/Jan/2024:12:59:41.228532725 +0000] conn=64347 op=1 BIND dn="uid=bind-dn,cn=sysaccounts,cn=etc,dc=domain,dc=tld" method=128 version=3
[26/Jan/2024:12:59:41.229479533 +0000] conn=64347 op=1 RESULT err=0 tag=97 nentries=0 wtime=0.021358633 optime=0.000938740 etime=0.022294725 dn="uid=bind-dn,cn=sysaccounts,cn=etc,dc=domain,dc=tld"
[26/Jan/2024:12:59:41.246339682 +0000] conn=64347 op=2 SRCH base="cn=accounts,dc=domain,dc=tld" scope=2 filter="(memberOf=cn=sales,cn=groups,cn=accounts,dc=domain,dc=tld)" attrs="* aci"
[26/Jan/2024:12:59:41.250503876 +0000] conn=64347 op=2 RESULT err=0 tag=101 nentries=2 wtime=0.000254305 optime=0.004170018 etime=0.004419211
[26/Jan/2024:12:59:41.311098525 +0000] conn=64347 op=3 BIND dn="uid=bind-dn,cn=sysaccounts,cn=etc,dc=domain,dc=tld" method=128 version=3
[26/Jan/2024:12:59:41.312039818 +0000] conn=64347 op=3 RESULT err=0 tag=97 nentries=0 wtime=0.000173717 optime=0.000960047 etime=0.001130890 dn="uid=bind-dn,cn=sysaccounts,cn=etc,dc=domain,dc=tld"
[26/Jan/2024:12:59:41.328356714 +0000] conn=64347 op=4 SRCH base="dc=domain,dc=tld" scope=2 filter="(uid=my-user)" attrs="* aci"
[26/Jan/2024:12:59:41.332848612 +0000] conn=64347 op=4 RESULT err=0 tag=101 nentries=1 wtime=0.000294621 optime=0.004498508 etime=0.004789213
[26/Jan/2024:12:59:41.351576404 +0000] conn=64347 op=5 UNBIND
[26/Jan/2024:12:59:41.351629711 +0000] conn=64347 op=5 fd=253 closed error - U1

So the number one question here is where does this attrs="* aci" part being parsed from. This is failing because the request isn’t properly formed.

[pgr]

@maverickws

Go to SuiteCRM with developer tools/inspector/console open

What about Network tab?

Any nice, detailed, Symfony exception there?

Your LDAP logs are also interesting!

[maverickws]

Network tab gives this:

Until the request is properly formed, it will always fail.
I have commenting the ### LDAP AUTO CREATE CONFIG
but the issue is the same.

Edit:
On the headers I have

URL https://suitecrm.app/login
Status: 401 Unauthorised
Source: Network
Address: suitecrm-server-ip:443
Initiator: poly fills.7539f468be309dcf.js:1:32939

If I put the mouse over this, I get:

dunno if this is of any help but well

[pgr]

No, that’s the front-end stack, might be useful for front-end bugs, but this is back-end.

The code appears to be this:

→ https://github.com/salesagility/SuiteCRM-Core/blob/master/public/legacy/modules/Users/authentication/LDAPAuthenticate/LDAPAuthenticateUser.php#L127

I see that it logs a lot if you increase your suitecrm.log log level to info, that might provide more clues. This can be changed from the UI: Admin / System settings, or from a text entry in public/legacy/config_override.php:

$sugar_config['logger']['level'] = 'info';

The messages will appear in public/legacy/suitecrm.log

[maverickws]

I can’t change anything via UI since I’m locked out since I ran the update.
I just have to finish a task here and I’ll add that to config override and increase the logging level in order to see if I get other feedback,
But I am starting to doubt that as I don’t believe the log will show how the request was being properly formed before, and is wrong now.

Which leaves us with the part where apparently the SuiteCRM developers did breaking changes that screwed up this, but are absolutely clueless about what changes were done, and how it came to affect LDAP. Clueless is a keyword.

Anyway, be back soon with the results.

[maverickws]

@pgr

$sugar_config['logger']['level'] = 'info';

Whenever I attempt to login, this is the output I get on suitecrm.log

Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Found language file: en_us.lang.php
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Found custom language file: en_us.lang.php
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query:SELECT id, name, symbol, conversion_rate FROM currencies WHERE status = 'Active' and deleted = 0
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query Execution Time:0.0011050701141357
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query:SELECT category, name, value FROM config
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query Execution Time:0.0012409687042236
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system' AND deleted = 0
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query Execution Time:0.00098991394042969
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query:SELECT * FROM outbound_email WHERE id = '67d4e908-187c-5bfe-0080-64440daa0029'
Fri Jan 26 16:01:53 2024 [1070][-none-][INFO] Query Execution Time:0.0011289119720459

EDIT: by the way that ID belongs to the system user (user_id = 1), just checked on the database at table outbound_email.

I have no idea why is it making this query.

[pgr]

Sorry, my bad, we want debug level, not info

I want to see the messages that have ldapauth, at least that will give me an idea of where we are in the code

The email messages are mysterious but for now I would say they’re harmless, probably just some part of the init process of the app, loading the current user and some other related info.

[maverickws]

with debug enabled you get this (I had actually tried it already but the output was so irrelevant I didn’t care to put it here)

==> public/legacy/suitecrm.log <==
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] current_language is: en_us
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheAPC
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheFile
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheMemcache
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheMemcached
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheMemory
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Using cache backend SugarCacheMemory, since 999 is less than 1000
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheRedis
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheWincache
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCacheZend
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Found cache backend SugarCachesMash
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Found language file: en_us.lang.php
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Found custom language file: en_us.lang.php
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query:SELECT id, name, symbol, conversion_rate FROM currencies WHERE status = 'Active' and deleted = 0
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query Execution Time:0.0010459423065186
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query:SELECT category, name, value FROM config
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query Execution Time:0.0010290145874023
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query:SELECT id FROM outbound_email WHERE type = 'system' AND deleted = 0
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query Execution Time:0.00092887878417969
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query:SELECT * FROM outbound_email WHERE id = '67d4e908-187c-5bfe-0080-64440daa0029'
Fri Jan 26 16:26:51 2024 [2598][-none-][INFO] Query Execution Time:0.0010130405426025
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Hook called: ::after_entry_point
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Including module specific hook file for custom/modules
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Including Ext hook file for custom/application
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Hook called: ::server_round_trip
Fri Jan 26 16:26:51 2024 [2598][-none-][DEBUG] Calling MySQLi::disconnect()

There’s no ldapauth, but if you have other level that want me to give a try, let’s have it.

[chris001]

I’d swap the FreeIPA server for any other LDAP server, and see what the difference is, if any.

[pgr]

That’s frustrating…

I really expected to see more, I can’t explain how SuiteCRM is attempting any LDAP authentication without passing through that code I linked above, which has several lines logging stuff…