Wrong ldap.bind.password after 4.19 upgrade

[levindecaro]

ISSUE TYPE

• Bug Report

COMPONENT NAME

LDAP

CLOUDSTACK VERSION

4.19

CONFIGURATION

N/A

OS / ENVIRONMENT

CentOS 7

SUMMARY

After upgrade from 4.18.1 to 4.19, ldap.bind.password became invalid for ldap binding, even reset it via UI again, the password never correct. Ultimately solved by update the ldap.bind.password in domain_details table with plain text.

STEPS TO REPRODUCE

Upgrade from 4.18.1 to 4.19

EXPECTED RESULTS

Domain with ldap backend should able to login

ACTUAL RESULTS

All ldap user failed to login

[correajl]

After upgrade from 4.17.2 to 4.19.0, management.log was showing errors with cloud.jks and LDAP users couldn't authenticate.

DEBUG [o.a.c.l.LdapManagerImpl] (qtp1753127384-22:ctx-cfc59ea9) (logid:c7732509) ldap Exception:
javax.naming.CommunicationException: ldapserver.mydomain:636 [Root exception is java.net.SocketException: java.security.NoSuchAlgorithmException: Error constructing implementation (algorithm: Default, provider: SunJSSE, class: sun.security.ssl.SSLContextImpl$DefaultSSLContext)]

Caused by: java.net.SocketException: java.security.NoSuchAlgorithmException: Error constructing implementation (algorithm: Default, provider: SunJSSE, class: sun.security.ssl.SSLContextImpl$DefaultSSLContext)

Caused by: java.security.NoSuchAlgorithmException: Error constructing implementation (algorithm: Default, provider: SunJSSE, class: sun.security.ssl.SSLContextImpl$DefaultSSLContext)

Caused by: java.security.KeyStoreException: problem accessing trust store

Caused by: java.io.IOException: keystore password was incorrect

Caused by: java.security.UnrecoverableKeyException: failed to decrypt safe contents entry: javax.crypto.BadPaddingException: Given final block not properly padded. Such issues can arise if a bad key is used during decryption.

In my case the LDAP server accepts anonymous bind. So, instead of updating the value for ldap.bind.password (there is no line with this value) I had to update lines with ldap.truststore.password.

After that LDAP users are authenticating again.

[weizhouapache]

This may be related to #6812

@BryanMLima can you please have a look ?

[BryanMLima]

This may be related to #6812

@BryanMLima can you please have a look ?

I will have a look at this.

[BryanMLima]

@correajl @levindecaro, do any of you still have the management logs of the day of the upgrade to the 4.19 version? If so, could you make available the section regarding the normalization of the encryption of the configurations (omitting any sensible information)?

The related message logs are between these two messages below:

Decrypting global configuration values from the following tables: account_details and domain_details.
(...)
Successfully decrypted configurations from domain_details table.

---

@levindecaro you mentioned that you solved this case by updating the configuration ldap.bind.password with plain text via DB, however, this should throw an exception as ACS would try to decrypt plain text. I am trying to find out how you did not encounter an exception with this manual change.

[correajl]

@BryanMLima here is the log of the day of upgrade to 4.19.

2024-02-09 14:49:17,012 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Decrypting global configuration values from the following tables: account_details and domain_details.
2024-02-09 14:49:17,017 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Successfully decrypted configurations from account_details table.
2024-02-09 14:49:17,025 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [1] to value [/etc/cloudstack/management/cloud.jks].
2024-02-09 14:49:17,029 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [3] to value [_SOMELDAPINFO_].
2024-02-09 14:49:17,033 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [4] to value [groupOfNames].
2024-02-09 14:49:17,037 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [5] to value [member].
2024-02-09 14:49:17,041 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [6] to value [/etc/cloudstack/management/cloud.jks].
2024-02-09 14:49:17,045 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [8] to value [_SOMELDAPINFO_].
2024-02-09 14:49:17,049 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [9] to value [groupOfNames].
2024-02-09 14:49:17,052 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [10] to value [member].
2024-02-09 14:49:17,056 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [11] to value [/etc/cloudstack/management/cloud.jks].
2024-02-09 14:49:17,059 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [13] to value [_SOMELDAPINFO_].
2024-02-09 14:49:17,062 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [14] to value [groupOfNames].
2024-02-09 14:49:17,066 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [15] to value [member].
2024-02-09 14:49:17,070 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [21] to value [/etc/cloudstack/management/cloud.jks].
2024-02-09 14:49:17,073 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [23] to value [_SOMELDAPINFO_].
2024-02-09 14:49:17,076 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [24] to value [groupOfNames].
2024-02-09 14:49:17,078 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [25] to value [member].
2024-02-09 14:49:17,081 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [26] to value [/etc/cloudstack/management/cloud.jks].
2024-02-09 14:49:17,083 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [28] to value [_SOMELDAPINFO_].
2024-02-09 14:49:17,086 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [29] to value [groupOfNames].
2024-02-09 14:49:17,088 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Updating config with ID [30] to value [member].
2024-02-09 14:49:17,089 INFO  [c.c.u.d.Upgrade41810to41900] (main:null) (logid:) Successfully decrypted configurations from domain_details table.

As mentioned, in my case I had to update lines with ldap.truststore.password in domain_details table. Currently they are in plain text and working.

A thing I noted here, maybe can help. When merging configuration files, in db.properties the new configuration has a new parameter.

Before upgrade:

# Encryption Settings
db.cloud.encryption.type=file
db.cloud.encrypt.secret=ENC(_A_VALUE_)

After the upgrade I can see db.cloud.encryptor.version=. Here it was left empty.

db.cloud.encryption.type=file
db.cloud.encrypt.secret=ENC(_A_VALUE_)
db.cloud.encryptor.version=

I don't know if it is related.

[3X0mre]

@levindecaro you mentioned that you solved this case by updating the configuration ldap.bind.password with plain text via DB, however, this should throw an exception as ACS would try to decrypt plain text. I am trying to find out how you did not encounter an exception with this manual change.

i'd like to add to this: i can confirm that LDAP with Active Directory works if the ldap.bind.password is stored in plaintext in the database, like so:

mysql
use cloud;
update domain_details set value='my_unencrypted_pass' where name='ldap.bind.password';

after that, i am able to login with only login/pass (no need to specify Domain)

this is a POC, so i only have one Domain (ROOT). i only configured LDAP for the Domain ROOT (Domains/Settings), not in Global Settings.

EDIT: also, i forgot to say that this is a completely new v4.19 install, not an upgraded version

this is this error i had when the password was stored encrypted:

2024-05-14 16:34:34,161 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Attempting to log in user: my_test_user in domain 1
2024-05-14 16:34:34,162 DEBUG [o.a.c.s.a.PBKDF2UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Retrieving user: my_test_user
2024-05-14 16:34:34,164 DEBUG [o.a.c.s.a.PBKDF2UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to find user with my_test_user in domain 1
2024-05-14 16:34:34,164 DEBUG [o.a.c.a.SHA256SaltedUserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Retrieving user: my_test_user
2024-05-14 16:34:34,165 DEBUG [o.a.c.a.SHA256SaltedUserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to find user with my_test_user in domain 1
2024-05-14 16:34:34,165 DEBUG [o.a.c.a.MD5UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Retrieving user: my_test_user
2024-05-14 16:34:34,166 DEBUG [o.a.c.a.MD5UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to find user with my_test_user in domain 1
2024-05-14 16:34:34,166 DEBUG [o.a.c.l.LdapAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Retrieving ldap user: my_test_user
2024-05-14 16:34:34,175 DEBUG [o.a.c.l.LdapContextFactory] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) initializing ldap with provider url: ldap://xx.xx.xx.xx:389
2024-05-14 16:34:34,180 DEBUG [o.a.c.l.LdapManagerImpl] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) ldap Exception:
javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C09056B, comment: AcceptSecurityContext error, data 52e, v4f7c]
        at java.naming/com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3259)
        at java.naming/com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3205)
        at java.naming/com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2991)
        at java.naming/com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2905)
        at java.naming/com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:348)
        at java.naming/com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxFromUrl(LdapCtxFactory.java:266)
        at java.naming/com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:226)
        at java.naming/com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:284)
        at java.naming/com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:185)
        at java.naming/com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:115)
        at java.naming/javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:730)
        at java.naming/javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:305)
        at java.naming/javax.naming.InitialContext.init(InitialContext.java:236)
        at java.naming/javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:154)
        at org.apache.cloudstack.ldap.LdapContextFactory.createInitialDirContext(LdapContextFactory.java:62)
        at org.apache.cloudstack.ldap.LdapContextFactory.createBindContext(LdapContextFactory.java:51)
        at org.apache.cloudstack.ldap.LdapContextFactory.createBindContext(LdapContextFactory.java:45)
        at org.apache.cloudstack.ldap.LdapManagerImpl.getUser(LdapManagerImpl.java:314)
        at org.apache.cloudstack.ldap.LdapAuthenticator.authenticate(LdapAuthenticator.java:229)
        at org.apache.cloudstack.ldap.LdapAuthenticator.authenticate(LdapAuthenticator.java:84)
        at com.cloud.user.AccountManagerImpl.getUserAccount(AccountManagerImpl.java:2656)
        at com.cloud.user.AccountManagerImpl.authenticateUser(AccountManagerImpl.java:2494)
        at jdk.internal.reflect.GeneratedMethodAccessor241.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
        at com.sun.proxy.$Proxy124.authenticateUser(Unknown Source)
        at com.cloud.api.ApiServer.loginUser(ApiServer.java:1132)
        at com.cloud.api.auth.DefaultLoginAPIAuthenticatorCmd.authenticate(DefaultLoginAPIAuthenticatorCmd.java:156)
        at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:252)
        at com.cloud.api.ApiServlet$1.run(ApiServlet.java:149)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:146)
        at com.cloud.api.ApiServlet.doPost(ApiServlet.java:105)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:665)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
        at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1450)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:554)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        at org.eclipse.jetty.server.Server.handle(Server.java:516)
        at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
        at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
        at java.base/java.lang.Thread.run(Thread.java:829)
2024-05-14 16:34:34,181 DEBUG [o.a.c.l.LdapAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) No users matching: No Ldap User found for username: my_test_user in group: OU=my_OU,DC=my_test_dc,DC=lan of type: OU
2024-05-14 16:34:34,181 DEBUG [o.a.c.s.SAML2UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Trying SAML2 auth for user: my_test_user
2024-05-14 16:34:34,182 DEBUG [o.a.c.s.SAML2UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to find user with my_test_user in domain 1, or user source is not SAML2
2024-05-14 16:34:34,182 DEBUG [o.a.c.o.OAuth2UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Trying OAuth2 auth for user: my_test_user
2024-05-14 16:34:34,183 DEBUG [o.a.c.o.OAuth2UserAuthenticator] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to find user with my_test_user in domain 1, or user source is not OAUTH2
2024-05-14 16:34:34,183 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to authenticate user with username my_test_user in domain 1
2024-05-14 16:34:34,183 WARN  [c.c.u.AccountManagerImpl] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Unable to find an user with username my_test_user in domain 1
2024-05-14 16:34:34,183 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) User: my_test_user in domain 1 has failed to log in
2024-05-14 16:34:34,183 DEBUG [c.c.a.ApiSessionListener] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Session destroyed by Id : node04q3az8ttf10ylgzqxbqiy1yh49 , session: Session@4129045{id=node04q3az8ttf10ylgzqxbqiy1yh49,x=node04q3az8ttf10ylgzqxbqiy1yh49.node0,req=1,res=true} , source: Session@4129045{id=node04q3az8ttf10ylgzqxbqiy1yh49,x=node04q3az8ttf10ylgzqxbqiy1yh49.node0,req=1,res=true} , event: javax.servlet.http.HttpSessionEvent[source=Session@4129045{id=node04q3az8ttf10ylgzqxbqiy1yh49,x=node04q3az8ttf10ylgzqxbqiy1yh49.node0,req=1,res=true}]
2024-05-14 16:34:34,183 DEBUG [c.c.a.ApiServlet] (qtp31114735-463:ctx-a5b03841) (logid:b5550713) Authentication failure: {"loginresponse":{"uuidList":[],"errorcode":531,"errortext":"Failed to authenticate user my_test_user in domain 1; please provide valid credentials"}}

where LDAP error 52e refers to: Invalid credentials | Returned when a valid username is supplied but an invalid password/credential is supplied. If this error is received, it will prevent most other errors from being displayed.

and this is what i get now after putting the password in plain text in db, with a user previously unknown to Cloudstack:

2024-05-16 10:55:29,070 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Attempting to log in user: my_test_user in domain 1
2024-05-16 10:55:29,072 DEBUG [o.a.c.s.a.PBKDF2UserAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Retrieving user: my_test_user
2024-05-16 10:55:29,073 DEBUG [o.a.c.s.a.PBKDF2UserAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Unable to find user with my_test_user in domain 1
2024-05-16 10:55:29,073 DEBUG [o.a.c.a.SHA256SaltedUserAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Retrieving user: my_test_user
2024-05-16 10:55:29,074 DEBUG [o.a.c.a.SHA256SaltedUserAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Unable to find user with my_test_user in domain 1
2024-05-16 10:55:29,075 DEBUG [o.a.c.a.MD5UserAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Retrieving user: my_test_user
2024-05-16 10:55:29,076 DEBUG [o.a.c.a.MD5UserAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Unable to find user with my_test_user in domain 1
2024-05-16 10:55:29,076 DEBUG [o.a.c.l.LdapAuthenticator] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Retrieving ldap user: my_test_user
2024-05-16 10:55:29,094 DEBUG [o.a.c.l.LdapContextFactory] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) initializing ldap with provider url: ldap://xx.xx.xx.xx:389
2024-05-16 10:55:29,150 DEBUG [o.a.c.l.OpenLdapUserManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) searching user(s) with filter: "(&(objectClass=user)(sAMAccountName=my_test_user))"
2024-05-16 10:55:29,163 DEBUG [o.a.c.l.LdapContextFactory] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) initializing ldap with provider url: ldap://xx.xx.xx.xx:389
2024-05-16 10:55:29,170 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Access granted to Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}] to Domain:1/ by AffinityGroupAccessChecker
2024-05-16 10:55:29,196 DEBUG [c.c.n.s.SecurityGroupManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Created security group com.cloud.network.security.SecurityGroupVO$$EnhancerByCGLIB$$6244a1fa@313fdde1 for account id=6
2024-05-16 10:55:29,196 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) checking if user of account system [f54e630e-ef13-e4f7-a3f7-dae0fa8e4785] with role-id [1] can create an account of type my_test_user [7fb42e1e-ec62-4ecb-91b5-af1f43725636] with role-id [4]
2024-05-16 10:55:29,199 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2024-05-16 10:55:29,224 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
2024-05-16 10:55:29,241 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-924c801e) (logid:43cc0c24) Detected management node left, id:13, nodeIP:xx.xx.xx.zz
2024-05-16 10:55:29,241 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-924c801e) (logid:43cc0c24) Trying to connect to xx.xx.xx.zz
2024-05-16 10:55:29,241 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-924c801e) (logid:43cc0c24) Management node 13 is detected inactive by timestamp but is pingable
2024-05-16 10:55:29,245 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
...
2024-05-16 10:55:30,590 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
2024-05-16 10:55:30,590 DEBUG [o.a.c.h.HAManagerImpl] (BackgroundTaskPollManager-2:ctx-76b390d3) (logid:1e8e652b) HA health check task is running...
2024-05-16 10:55:30,594 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
...
2024-05-16 10:55:30,737 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
2024-05-16 10:55:30,740 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-c070a6b9) (logid:d1d68159) Detected management node left, id:13, nodeIP:xx.xx.xx.zz
2024-05-16 10:55:30,740 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-c070a6b9) (logid:d1d68159) Trying to connect to xx.xx.xx.zz
2024-05-16 10:55:30,740 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-c070a6b9) (logid:d1d68159) Management node 13 is detected inactive by timestamp but is pingable
2024-05-16 10:55:30,742 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
...
2024-05-16 10:55:31,803 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Account [Account [{"accountName":"system","id":1,"uuid":"f54e630e-ef13-e4f7-a3f7-dae0fa8e4785"}]] is Root Admin or Domain Admin, all APIs are allowed.
2024-05-16 10:55:32,126 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Creating user: my_test_user, accountId: 6 timezone:null
2024-05-16 10:55:32,127 WARN  [c.c.u.PasswordPolicyImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) User [my_test_user] has an empty password, skipping password policy checks. If this is not a LDAP user, there is something wrong.
2024-05-16 10:55:32,239 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-738b3524) (logid:7ff56895) Detected management node left, id:13, nodeIP:xx.xx.xx.zz
2024-05-16 10:55:32,239 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-738b3524) (logid:7ff56895) Trying to connect to xx.xx.xx.zz
2024-05-16 10:55:32,239 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-738b3524) (logid:7ff56895) Management node 13 is detected inactive by timestamp but is pingable
2024-05-16 10:55:32,495 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) (logid:) SeqA 11-12335: Processing Seq 11-12335:  { Cmd , MgmtId: -1, via: 11, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"12","_loadInfo":"{
  "connections": [],
  "removedSessions": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2024-05-16 10:55:32,499 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) (logid:) SeqA 11-12335: Sending Seq 11-12335:  { Ans: , MgmtId: 279278805462449, via: 11, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2024-05-16 10:55:32,578 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) CIDRs from which account 'Account [{"accountName":"my_test_user","id":6,"uuid":"7fb42e1e-ec62-4ecb-91b5-af1f43725636"}]' is allowed to perform API calls: 0.0.0.0/0,::/0
2024-05-16 10:55:32,579 DEBUG [c.c.u.AccountManagerImpl] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) User: my_test_user in domain 1 has successfully logged in
2024-05-16 10:55:32,585 INFO  [c.c.a.ApiServer] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Current user logged in under UTC timezone
2024-05-16 10:55:32,585 INFO  [c.c.a.ApiServer] (qtp31114735-357:ctx-b18d4ae8) (logid:973153b8) Timezone offset from UTC is: 0.0

also btw, if the LDAP user doesnt have a last name, Cloudstack doesnt like it and throws an error

[BryanMLima]

Hey, @levindecaro, @correajl, and @3X0mre

I managed to found the cause of error, it that was introduced in PR #6812 by me. The problem was that ACS did not decrypt the value, therefore, manually changing in the database resolved the problem. I created PR #9088 which fixes this issue. I could reproduce the error you guys mentioned, and with the patch, the error did not occur.