Description:
We configured a distributed API-M Deployment with Traffic Manager separated from the Control Plane in a K8 cluster
When throttle data is published to the TM nodes, we encounter a primary key violation issue at the initial stage when the initial traffic is received to the TM nodes initially.
While analyzing the user core logs,I could observe that concurrent invocation of the method:getRoleListOfUser(user) in AbstractUserStoreManager class has caused the particular issue. I have attached logs herewith and it shows that there is parallel effort going on to store an entry with user ID and userstore domain in a read path.
(This is a harmless issue)
Error log in TM Node:
[2021-12-14 16:35:41,626] INFO - JMSConnectionFactory JMS ConnectionFactory : jmsEventPublisher initialized [2021-12-14 16:35:41,646] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,646] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,647] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,649] INFO - JMSConnectionFactory JMS ConnectionFactory : jmsEventPublisher2 initialized [2021-12-14 16:35:41,662] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,663] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,663] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,703] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:35:41,703] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:35:41,704] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:35:41,704] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:35:41,704] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,704] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,742] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,742] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,743] DEBUG - UserUniqueIDDomainResolver Cache miss for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 searching from the database. [2021-12-14 16:35:41,743] DEBUG - UserUniqueIDDomainResolver Cache miss for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 searching from the database. [2021-12-14 16:35:41,744] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,744] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver Persisting user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 against domain: PRIMARY [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver Persisting user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 against domain: PRIMARY [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver No domain name found for the give user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 Hence adding it as a new value. [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver No domain name found for the give user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 Hence adding it as a new value. [2021-12-14 16:35:41,746] DEBUG - UserUniqueIDDomainResolver Successfully persisted user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 against domain: PRIMARY and added to the cache. [2021-12-14 16:35:41,747] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,748] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,749] DEBUG - UniqueIDJDBCUserStoreManager Searching for userID b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,749] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,749] DEBUG - UniqueIDJDBCUserStoreManager Getting roles of user: b248e917-63dc-4cd5-b646-80c5d7cebe16 with filter: * [2021-12-14 16:35:41,749] DEBUG - UniqueIDJDBCUserStoreManager Executing Query: SELECT UM_ROLE_NAME FROM UM_USER_ROLE, UM_ROLE, UM_USER WHERE UM_USER.UM_USER_ID=? AND UM_USER.UM_ID=UM_USER_ROLE.UM_USER_ID AND UM_ROLE.UM_ID=UM_USER_ROLE.UM_ROLE_ID AND UM_USER_ROLE.UM_TENANT_ID=? AND UM_ROLE.UM_TENANT_ID=? AND UM_USER.UM_TENANT_ID=? [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: -1234 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: -1234 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: -1234 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Found role: admin [2021-12-14 16:35:41,751] DEBUG - UserUniqueIDDomainResolver Cache hit for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,751] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,835] DEBUG - UserUniqueIDDomainResolver Cache hit for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,835] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,748] ERROR - AndesAuthorizationPlugin Error while invoking AndesAuthorizationHandler org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandlerException: Error handling publish queue. at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:587) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.service.andes.AndesAuthorizationPlugin.authorise(AndesAuthorizationPlugin.java:156) [org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.andes.server.security.SecurityManager$12.allowed(SecurityManager.java:394) [andes_3.3.11.jar:?] at org.wso2.andes.server.security.SecurityManager.checkAllPlugins(SecurityManager.java:238) [andes_3.3.11.jar:?] at org.wso2.andes.server.security.SecurityManager.authorisePublish(SecurityManager.java:390) [andes_3.3.11.jar:?] at org.wso2.andes.server.AMQChannel.setPublishFrame(AMQChannel.java:392) [andes_3.3.11.jar:?] at org.wso2.andes.server.handler.BasicPublishMethodHandler.methodReceived(BasicPublishMethodHandler.java:95) [andes_3.3.11.jar:?] at org.wso2.andes.server.handler.ServerMethodDispatcherImpl.dispatchBasicPublish(ServerMethodDispatcherImpl.java:245) [andes_3.3.11.jar:?] at org.wso2.andes.framing.amqp_0_91.BasicPublishBodyImpl.execute(BasicPublishBodyImpl.java:156) [andes_3.3.11.jar:?] at org.wso2.andes.server.state.AMQStateManager.methodReceived(AMQStateManager.java:169) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine.methodFrameReceived(AMQProtocolEngine.java:388) [andes_3.3.11.jar:?] at org.wso2.andes.framing.AMQMethodBodyImpl.handle(AMQMethodBodyImpl.java:92) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine.frameReceived(AMQProtocolEngine.java:333) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine.dataBlockReceived(AMQProtocolEngine.java:282) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine$1.run(AMQProtocolEngine.java:251) [andes_3.3.11.jar:?] at org.wso2.andes.pool.Job.processAll(Job.java:111) [andes_3.3.11.jar:?] at org.wso2.andes.pool.Job.run(Job.java:158) [andes_3.3.11.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:834) [?:?] Caused by: org.wso2.carbon.user.core.UserStoreException: Error occurred while persisting domain against the user id. at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:215) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: java.security.PrivilegedActionException at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: java.lang.reflect.InvocationTargetException at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager$2.run(AbstractUserStoreManager.java:204) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: org.wso2.carbon.user.core.UserStoreException: Error occurred while persisting domain against the user id. at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.persistDomainAgainstUserId(UserUniqueIDDomainResolver.java:219) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.setDomainForUserId(UserUniqueIDDomainResolver.java:151) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreInternalWithId(AbstractUserStoreManager.java:7332) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.lambda$getUserStoreWithID$11(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreWithID(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserNameFromUserID(AbstractUserStoreManager.java:12297) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.doGetRoleListOfUserWithID(AbstractUserStoreManager.java:8435) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6649) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager$2.run(AbstractUserStoreManager.java:204) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: org.h2.jdbc.JdbcSQLIntegrityConstraintViolationException: Unique index or primary key violation: "PUBLIC.CONSTRAINT_INDEX_DC ON PUBLIC.UM_UUID_DOMAIN_MAPPER(UM_USER_ID) VALUES 2"; SQL statement: INSERT INTO UM_UUID_DOMAIN_MAPPER (UM_USER_ID, UM_DOMAIN_ID, UM_TENANT_ID) VALUES (?, (SELECT UM_DOMAIN_ID FROM UM_DOMAIN WHERE UM_DOMAIN_NAME = ? AND UM_TENANT_ID = ?), ?) [23505-199] at org.h2.message.DbException.getJdbcSQLException(DbException.java:457) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.message.DbException.getJdbcSQLException(DbException.java:427) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.message.DbException.get(DbException.java:205) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.message.DbException.get(DbException.java:181) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:103) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:220) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.mvstore.db.MVSecondaryIndex.add(MVSecondaryIndex.java:196) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.mvstore.db.MVTable.addRow(MVTable.java:546) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.dml.Insert.insertRows(Insert.java:180) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.dml.Insert.update(Insert.java:132) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.CommandContainer.update(CommandContainer.java:133) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.Command.executeUpdate(Command.java:267) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.jdbc.JdbcPreparedStatement.execute(JdbcPreparedStatement.java:250) ~[h2_1.4.199.wso2v1.jar:?] at jdk.internal.reflect.GeneratedMethodAccessor84.invoke(Unknown Source) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114) ~[jdbc-pool_9.0.35.wso2v1.jar:?] at com.sun.proxy.$Proxy53.execute(Unknown Source) ~[?:?] at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.persistDomainAgainstUserId(UserUniqueIDDomainResolver.java:213) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.setDomainForUserId(UserUniqueIDDomainResolver.java:151) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreInternalWithId(AbstractUserStoreManager.java:7332) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.lambda$getUserStoreWithID$11(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreWithID(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserNameFromUserID(AbstractUserStoreManager.java:12297) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.doGetRoleListOfUserWithID(AbstractUserStoreManager.java:8435) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6649) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager$2.run(AbstractUserStoreManager.java:204) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more [2021-12-14 16:35:41,909] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,910] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,910] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,912] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:35:41,912] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:35:41,913] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,868] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,868] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,869] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,872] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:36:16,872] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:36:16,872] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,934] DEBUG - JDBCAuthorizationManager Executed query is INSERT INTO UM_PERMISSION (UM_RESOURCE_ID, UM_ACTION, UM_TENANT_ID) VALUES (?, ?, ?) and number of updated rows :: 1 [2021-12-14 16:36:16,935] DEBUG - JDBCAuthorizationManager Adding permission Id: 32 to the role: admin of tenant: -1234 of domain: PRIMARY to resource: event/topics/throttledata [2021-12-14 16:36:16,936] DEBUG - JDBCAuthorizationManager Executed query is INSERT INTO UM_PERMISSION (UM_RESOURCE_ID, UM_ACTION, UM_TENANT_ID) VALUES (?, ?, ?) and number of updated rows :: 1 [2021-12-14 16:36:16,936] DEBUG - JDBCAuthorizationManager Adding permission Id: 33 to the role: admin of tenant: -1234 of domain: PRIMARY to resource: event/topics/throttledata [2021-12-14 16:36:16,937] DEBUG - JDBCAuthorizationManager Executed query is INSERT INTO UM_PERMISSION (UM_RESOURCE_ID, UM_ACTION, UM_TENANT_ID) VALUES (?, ?, ?) and number of updated rows :: 1 [2021-12-14 16:36:16,937] DEBUG - JDBCAuthorizationManager Adding permission Id: 34 to the role: admin of tenant: -1234 of domain: PRIMARY to resource: event/topics/throttledata [2021-12-14 16:36:20,875] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:20,875] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:20,875] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:20,877] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:36:20,877] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:36:20,878] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully.
Suggested Labels:
Suggested Assignees:
Affected Product Version:
APIM 4.0.0
OS, DB, other environment details and versions:
Steps to reproduce:
APIM distributed setup TM is separated from Control plane.
2 cp instences
2TM instences
GW 2 replicas.
I configured them in AWS cluster.
Description: We configured a distributed API-M Deployment with Traffic Manager separated from the Control Plane in a K8 cluster
When throttle data is published to the TM nodes, we encounter a primary key violation issue at the initial stage when the initial traffic is received to the TM nodes initially.
While analyzing the user core logs,I could observe that concurrent invocation of the method:getRoleListOfUser(user) in AbstractUserStoreManager class has caused the particular issue. I have attached logs herewith and it shows that there is parallel effort going on to store an entry with user ID and userstore domain in a read path. (This is a harmless issue)
Error log in TM Node:
[2021-12-14 16:35:41,626] INFO - JMSConnectionFactory JMS ConnectionFactory : jmsEventPublisher initialized [2021-12-14 16:35:41,646] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,646] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,647] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,649] INFO - JMSConnectionFactory JMS ConnectionFactory : jmsEventPublisher2 initialized [2021-12-14 16:35:41,662] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,663] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,663] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,703] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:35:41,703] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:35:41,704] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:35:41,704] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:35:41,704] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,704] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,742] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,742] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,743] DEBUG - UserUniqueIDDomainResolver Cache miss for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 searching from the database. [2021-12-14 16:35:41,743] DEBUG - UserUniqueIDDomainResolver Cache miss for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 searching from the database. [2021-12-14 16:35:41,744] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,744] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver Persisting user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 against domain: PRIMARY [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver Persisting user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 against domain: PRIMARY [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver No domain name found for the give user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 Hence adding it as a new value. [2021-12-14 16:35:41,745] DEBUG - UserUniqueIDDomainResolver No domain name found for the give user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 Hence adding it as a new value. [2021-12-14 16:35:41,746] DEBUG - UserUniqueIDDomainResolver Successfully persisted user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 against domain: PRIMARY and added to the cache. [2021-12-14 16:35:41,747] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,748] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,749] DEBUG - UniqueIDJDBCUserStoreManager Searching for userID b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,749] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,749] DEBUG - UniqueIDJDBCUserStoreManager Getting roles of user: b248e917-63dc-4cd5-b646-80c5d7cebe16 with filter: * [2021-12-14 16:35:41,749] DEBUG - UniqueIDJDBCUserStoreManager Executing Query: SELECT UM_ROLE_NAME FROM UM_USER_ROLE, UM_ROLE, UM_USER WHERE UM_USER.UM_USER_ID=? AND UM_USER.UM_ID=UM_USER_ROLE.UM_USER_ID AND UM_ROLE.UM_ID=UM_USER_ROLE.UM_ROLE_ID AND UM_USER_ROLE.UM_TENANT_ID=? AND UM_ROLE.UM_TENANT_ID=? AND UM_USER.UM_TENANT_ID=? [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: -1234 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: -1234 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Input value: -1234 [2021-12-14 16:35:41,750] DEBUG - UniqueIDJDBCUserStoreManager Found role: admin [2021-12-14 16:35:41,751] DEBUG - UserUniqueIDDomainResolver Cache hit for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,751] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,835] DEBUG - UserUniqueIDDomainResolver Cache hit for user id: b248e917-63dc-4cd5-b646-80c5d7cebe16 [2021-12-14 16:35:41,835] DEBUG - UserIdResolverCache Cache: user_name_from_user_id_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: admin for the key: b248e917-63dc-4cd5-b646-80c5d7cebe16 successfully. [2021-12-14 16:35:41,748] ERROR - AndesAuthorizationPlugin Error while invoking AndesAuthorizationHandler org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandlerException: Error handling publish queue. at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:587) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.service.andes.AndesAuthorizationPlugin.authorise(AndesAuthorizationPlugin.java:156) [org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.andes.server.security.SecurityManager$12.allowed(SecurityManager.java:394) [andes_3.3.11.jar:?] at org.wso2.andes.server.security.SecurityManager.checkAllPlugins(SecurityManager.java:238) [andes_3.3.11.jar:?] at org.wso2.andes.server.security.SecurityManager.authorisePublish(SecurityManager.java:390) [andes_3.3.11.jar:?] at org.wso2.andes.server.AMQChannel.setPublishFrame(AMQChannel.java:392) [andes_3.3.11.jar:?] at org.wso2.andes.server.handler.BasicPublishMethodHandler.methodReceived(BasicPublishMethodHandler.java:95) [andes_3.3.11.jar:?] at org.wso2.andes.server.handler.ServerMethodDispatcherImpl.dispatchBasicPublish(ServerMethodDispatcherImpl.java:245) [andes_3.3.11.jar:?] at org.wso2.andes.framing.amqp_0_91.BasicPublishBodyImpl.execute(BasicPublishBodyImpl.java:156) [andes_3.3.11.jar:?] at org.wso2.andes.server.state.AMQStateManager.methodReceived(AMQStateManager.java:169) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine.methodFrameReceived(AMQProtocolEngine.java:388) [andes_3.3.11.jar:?] at org.wso2.andes.framing.AMQMethodBodyImpl.handle(AMQMethodBodyImpl.java:92) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine.frameReceived(AMQProtocolEngine.java:333) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine.dataBlockReceived(AMQProtocolEngine.java:282) [andes_3.3.11.jar:?] at org.wso2.andes.server.protocol.AMQProtocolEngine$1.run(AMQProtocolEngine.java:251) [andes_3.3.11.jar:?] at org.wso2.andes.pool.Job.processAll(Job.java:111) [andes_3.3.11.jar:?] at org.wso2.andes.pool.Job.run(Job.java:158) [andes_3.3.11.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:834) [?:?] Caused by: org.wso2.carbon.user.core.UserStoreException: Error occurred while persisting domain against the user id. at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:215) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: java.security.PrivilegedActionException at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: java.lang.reflect.InvocationTargetException at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager$2.run(AbstractUserStoreManager.java:204) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: org.wso2.carbon.user.core.UserStoreException: Error occurred while persisting domain against the user id. at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.persistDomainAgainstUserId(UserUniqueIDDomainResolver.java:219) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.setDomainForUserId(UserUniqueIDDomainResolver.java:151) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreInternalWithId(AbstractUserStoreManager.java:7332) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.lambda$getUserStoreWithID$11(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreWithID(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserNameFromUserID(AbstractUserStoreManager.java:12297) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.doGetRoleListOfUserWithID(AbstractUserStoreManager.java:8435) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6649) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager$2.run(AbstractUserStoreManager.java:204) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more Caused by: org.h2.jdbc.JdbcSQLIntegrityConstraintViolationException: Unique index or primary key violation: "PUBLIC.CONSTRAINT_INDEX_DC ON PUBLIC.UM_UUID_DOMAIN_MAPPER(UM_USER_ID) VALUES 2"; SQL statement: INSERT INTO UM_UUID_DOMAIN_MAPPER (UM_USER_ID, UM_DOMAIN_ID, UM_TENANT_ID) VALUES (?, (SELECT UM_DOMAIN_ID FROM UM_DOMAIN WHERE UM_DOMAIN_NAME = ? AND UM_TENANT_ID = ?), ?) [23505-199] at org.h2.message.DbException.getJdbcSQLException(DbException.java:457) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.message.DbException.getJdbcSQLException(DbException.java:427) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.message.DbException.get(DbException.java:205) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.message.DbException.get(DbException.java:181) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:103) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:220) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.mvstore.db.MVSecondaryIndex.add(MVSecondaryIndex.java:196) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.mvstore.db.MVTable.addRow(MVTable.java:546) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.dml.Insert.insertRows(Insert.java:180) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.dml.Insert.update(Insert.java:132) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.CommandContainer.update(CommandContainer.java:133) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.command.Command.executeUpdate(Command.java:267) ~[h2_1.4.199.wso2v1.jar:?] at org.h2.jdbc.JdbcPreparedStatement.execute(JdbcPreparedStatement.java:250) ~[h2_1.4.199.wso2v1.jar:?] at jdk.internal.reflect.GeneratedMethodAccessor84.invoke(Unknown Source) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114) ~[jdbc-pool_9.0.35.wso2v1.jar:?] at com.sun.proxy.$Proxy53.execute(Unknown Source) ~[?:?] at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.persistDomainAgainstUserId(UserUniqueIDDomainResolver.java:213) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.UserUniqueIDDomainResolver.setDomainForUserId(UserUniqueIDDomainResolver.java:151) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreInternalWithId(AbstractUserStoreManager.java:7332) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.lambda$getUserStoreWithID$11(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserStoreWithID(AbstractUserStoreManager.java:7224) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getUserNameFromUserID(AbstractUserStoreManager.java:12297) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.doGetRoleListOfUserWithID(AbstractUserStoreManager.java:8435) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6649) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager$2.run(AbstractUserStoreManager.java:204) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at java.security.AccessController.doPrivileged(Native Method) ~[?:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.callSecure(AbstractUserStoreManager.java:201) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.user.core.common.AbstractUserStoreManager.getRoleListOfUser(AbstractUserStoreManager.java:6615) ~[org.wso2.carbon.user.core_4.6.2.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.isAdmin(AndesAuthorizationHandler.java:821) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] at org.wso2.carbon.andes.authorization.andes.AndesAuthorizationHandler.handlePublishToExchange(AndesAuthorizationHandler.java:563) ~[org.wso2.carbon.andes.authorization_3.3.15.jar:?] ... 19 more [2021-12-14 16:35:41,909] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,910] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,910] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:35:41,912] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:35:41,912] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:35:41,913] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,868] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,868] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,869] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,872] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:36:16,872] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:36:16,872] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:16,934] DEBUG - JDBCAuthorizationManager Executed query is INSERT INTO UM_PERMISSION (UM_RESOURCE_ID, UM_ACTION, UM_TENANT_ID) VALUES (?, ?, ?) and number of updated rows :: 1 [2021-12-14 16:36:16,935] DEBUG - JDBCAuthorizationManager Adding permission Id: 32 to the role: admin of tenant: -1234 of domain: PRIMARY to resource: event/topics/throttledata [2021-12-14 16:36:16,936] DEBUG - JDBCAuthorizationManager Executed query is INSERT INTO UM_PERMISSION (UM_RESOURCE_ID, UM_ACTION, UM_TENANT_ID) VALUES (?, ?, ?) and number of updated rows :: 1 [2021-12-14 16:36:16,936] DEBUG - JDBCAuthorizationManager Adding permission Id: 33 to the role: admin of tenant: -1234 of domain: PRIMARY to resource: event/topics/throttledata [2021-12-14 16:36:16,937] DEBUG - JDBCAuthorizationManager Executed query is INSERT INTO UM_PERMISSION (UM_RESOURCE_ID, UM_ACTION, UM_TENANT_ID) VALUES (?, ?, ?) and number of updated rows :: 1 [2021-12-14 16:36:16,937] DEBUG - JDBCAuthorizationManager Adding permission Id: 34 to the role: admin of tenant: -1234 of domain: PRIMARY to resource: event/topics/throttledata [2021-12-14 16:36:20,875] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:20,875] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:20,875] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully. [2021-12-14 16:36:20,877] DEBUG - UniqueIDJDBCUserStoreManager SELECT UM_USER_ID, UM_USER_NAME, UM_USER_PASSWORD, UM_SALT_VALUE, UM_REQUIRE_CHANGE, UM_CHANGED_TIME FROM UM_USER WHERE LOWER(UM_USER_NAME)=LOWER(?) AND UM_TENANT_ID=? [2021-12-14 16:36:20,877] DEBUG - UniqueIDJDBCUserStoreManager UserName admin login attempt. Login success: true [2021-12-14 16:36:20,878] DEBUG - UserIdResolverCache Cache: user_id_from_user_name_cache which is under USER_ID_RESOLVER_CACHE_MANAGER, found the entry: b248e917-63dc-4cd5-b646-80c5d7cebe16 for the key: admin successfully.Suggested Labels:
Suggested Assignees:
Affected Product Version: APIM 4.0.0
OS, DB, other environment details and versions:
Steps to reproduce: APIM distributed setup TM is separated from Control plane. 2 cp instences 2TM instences GW 2 replicas. I configured them in AWS cluster.
Related Issues: