Uploaded image for project: 'OpenAM'
  1. OpenAM
  2. OPENAM-14175

CTS updates on multivalue attributes may throws Duplicate values exception

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 5.5.1, 6.0.0, 6.0.0.1, 6.0.0.2, 6.0.0.3, 6.0.0.4, 6.0.0.5, 6.0.0.6, 6.5.0
    • Fix Version/s: 6.5.1, 6.0.1, 7.0.0, 5.5.2
    • Component/s: CTS, session
    • Labels:
    • Environment:
      AM not sticky and possibly concurrent access happens to register agent notification on 2 AM at the same time. (This issues requires updates to the CoreTokenMultiString* happening)
    • Sprint:
      AM Sustaining Sprint 59, AM Sustaining Sprint 60
    • Story Points:
      5
    • Needs backport:
      No
    • Support Ticket IDs:
    • Needs QA verification:
      No
    • Functional tests:
      No
    • Are the reproduction steps defined?:
      Yes and I used the same an in the description

      Description

      Bug description

      As user is firing requests in parallel to the protected application, more than one agent gets the request and they reach openam server for validating the request through sessionservice call. As request goes to two AM servers in parallel, both of them tries to update the SSO session in CTS at the same time and the following happens:

       

      org.forgerock.openam.sm.datalayer.api.LdapOperationFailedException:
      CTS: Operation failed:
      Result Code: Attribute or Value Exists
      Diagnostic Message: Entry coreTokenId=.....,ou=famrecords,ou=openam-session,ou=tokens,dc=openam,dc=forgerock,dc=com cannot be modified because it would have resulted in one or more duplicate values for attribute coreTokenMultiString01: d73f9fca-5772-404e-a159-c8e93af50729
      Matched DN:
      at org.forgerock.openam.cts.impl.LdapAdapter.update(LdapAdapter.java:168)
      at org.forgerock.openam.sm.datalayer.impl.tasks.UpdateTask.performTask(UpdateTask.java:59)
      at org.forgerock.openam.sm.datalayer.api.AbstractTask.execute(AbstractTask.java:53)
      at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutor$TaskDecorator.execute(SeriesTaskExecutor.java:231)
      at org.forgerock.openam.sm.datalayer.impl.SimpleTaskExecutor.execute(SimpleTaskExecutor.java:59)
      at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:86)
      at org.forgerock.openam.audit.context.AuditRequestContextPropagatingRunnable.run(AuditRequestContextPropagatingRunnable.java:34)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
      Wrapped by: org.forgerock.openam.cts.exceptions.CoreTokenException:
      CTS:
      CTS: Operation failed:
      Result Code: Attribute or Value Exists
      Diagnostic Message: Entry coreTokenId=....=,ou=famrecords,ou=openam-session,ou=tokens,dc=openam,dc=forgerock,dc=org cannot be modified because it would have resulted in one or more duplicate values for attribute coreTokenMultiString01: d73f9fca-5772-404e-a159-c8e93af50729
      Matched DN:
      at org.forgerock.openam.cts.impl.queue.AsyncResultHandler.getResults(AsyncResultHandler.java:95)
      at org.forgerock.openam.cts.monitoring.impl.queue.TokenMonitoringResultHandler.getResults(TokenMonitoringResultHandler.java:42)
      at org.forgerock.openam.cts.monitoring.impl.queue.TokenMonitoringResultHandler.getResults(TokenMonitoringResultHandler.java:19)
      at org.forgerock.openam.cts.CTSPersistentStoreImpl.update(CTSPersistentStoreImpl.java:162)
      at org.forgerock.openam.cts.CTSPersistentStoreImpl.update(CTSPersistentStoreImpl.java:155)
      at org.forgerock.openam.session.cts.SessionPersistenceStore.update(SessionPersistenceStore.java:119)
      at org.forgerock.openam.session.cts.CtsSessionPersistenceStore.store(CtsSessionPersistenceStore.java:53)
      at org.forgerock.openam.session.cts.CtsSessionStoreChain$ChainIterator.store(CtsSessionStoreChain.java:64)
      at org.forgerock.openam.session.cts.SessionPersistenceManagerStep.store(SessionPersistenceManagerStep.java:44)
      at org.forgerock.openam.session.cts.CtsSessionStoreChain$ChainIterator.store(CtsSessionStoreChain.java:62)
      at org.forgerock.openam.session.cts.DsameSessionInterceptorStep.store(DsameSessionInterceptorStep.java:59)
      at org.forgerock.openam.session.cts.CtsSessionStoreChain$ChainIterator.store(CtsSessionStoreChain.java:62)
      at org.forgerock.openam.session.cts.InMemoryCtsSessionCacheStep.store(InMemoryCtsSessionCacheStep.java:108)
      at org.forgerock.openam.session.cts.CtsSessionStoreChain$ChainIterator.store(CtsSessionStoreChain.java:62)
      at org.forgerock.openam.session.cts.AbstractCtsSessionStoreStep.store(AbstractCtsSessionStoreStep.java:29)
      at org.forgerock.openam.session.cts.CtsSessionStoreChain$ChainIterator.store(CtsSessionStoreChain.java:62)
      at org.forgerock.openam.session.cts.CtsSessionStoreChain.store(CtsSessionStoreChain.java:38)
      at org.forgerock.openam.session.cts.SessionPersistenceManagerStep.notifyUpdate(SessionPersistenceManagerStep.java:62)
      at org.forgerock.openam.session.cts.CtsSession.notifyPersistenceManager(CtsSession.java:865)
      at org.forgerock.openam.session.cts.CtsOperations.notifyListenerFor(CtsOperations.java:373)
      at com.iplanet.dpro.session.monitoring.MonitoredOperations.lambda$notifyListenerFor$7(MonitoredOperations.java:132)
      at com.iplanet.dpro.session.monitoring.MonitoredOperations.time(MonitoredOperations.java:200)
      at com.iplanet.dpro.session.monitoring.MonitoredOperations.notifyListenerFor(MonitoredOperations.java:132)
      at com.iplanet.dpro.session.service.SessionService.notifyListenerFor(SessionService.java:317)
      at com.sun.identity.policy.plugins.AMIdentitySubject.isMember(AMIdentitySubject.java:407)
      at com.sun.identity.entitlement.opensso.PolicySubject.evaluate(PolicySubject.java:220)
      at com.sun.identity.entitlement.Privilege.doesSubjectMatch(Privilege.java:669)
      at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.internalEvaluate(OpenSSOPrivilege.java:140)
      at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.access$000(OpenSSOPrivilege.java:63)
      at com.sun.identity.entitlement.opensso.OpenSSOPrivilege$1.run(OpenSSOPrivilege.java:105)
      at com.sun.identity.entitlement.opensso.OpenSSOPrivilege$1.run(OpenSSOPrivilege.java:99)
      at com.sun.identity.session.util.RestrictedTokenContext.doUsing(RestrictedTokenContext.java:81)
      at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.evaluate(OpenSSOPrivilege.java:98)
      at com.sun.identity.entitlement.PrivilegeEvaluator$PrivilegeTask.run(PrivilegeEvaluator.java:421)
      at com.sun.identity.entitlement.ThreadPool$WorkerThread.run(ThreadPool.java:166)
      

       

       

      How to reproduce the issue

      Customer reported. However code analysis does indicate that this is plausible on the way the LDAP update on CoreTokenAdapter and LdapAdapter since if there on an update it read the value from LDAP and then try to merge the update using a "add". For multiple value attributes this is BAD and the same exception will expected to be see say using a sample ldapmodify ldif.

      Conditon:

      • Must have non-sticy AM and a few AM getting concurrent access.

      Impact:

      • For exception on multi-value attributes (for this is on the Notification listener id). this means there is a duplicate so not issue other than some other attributes possibly say idletimout may not be updated.
      Expected behaviour
      Concurrently request for session adding notification not trigger exception
      
      Current behaviour
      Exception happens if there
      

      Work around

      • Depending on the context of the error, as it is a duplicate, this may not be a serious issue (as the other request may probably have identical value) and so not an issue other than the ERROR exception
      • But based on analysis, the best solution is still to ensure AM stickiness (or some form of affinity to AM session)

      Code analysis

      UpdateTask.java
          public Optional<TokenType> performTask(TokenStorageAdapter adapter) throws DataLayerException {
              Token previous = adapter.read(token.getTokenId(), options);
              Token updated;
              if (previous == null) {
                  updated = adapter.create(token, options);
              } else {
                  updated = adapter.update(previous, token, options);
              }
              handler.processResults(updated);
              return Optional.ofNullable(updated).map(Token::getType);
          }
      
      LdapAdapter.java
          public Token update(Token previous, Token updated, Options options) throws DataLayerException {
              Entry currentEntry = conversion.getEntry(updated);
              LdapTokenAttributeConversion.stripObjectClass(currentEntry);
      
              Entry previousEntry = conversion.getEntry(previous);
              LdapTokenAttributeConversion.stripObjectClass(previousEntry);
      
              ModifyRequest request = Entries.diffEntries(previousEntry, currentEntry,
                      Entries.diffOptions().replaceSingleValuedAttributes());
      
              if (request.getModifications().isEmpty()) {
                  return previous;
              }
      

      This piece of code takes an copy (at the time is valid) and the value that it needs to updated on and use Entries.diffEntries to create the change modification (ala LDIF)
      The LDIF to be made to LDAP are then run. Notice that it generated a ldif like this when the value is not there originally:

      add: coreTokenMultiString01
      coreTokenMultiString01: d73f9fca-5772-404e-a159-c8e93af50729
      

      So if there is an update is made to directory after that time the "previous" value is taken, this may be a bit inconsistent.

      The above seems to by synthetic testing to happen if say SessionService.notifyListenerFor update the session for listeners. it seems at least for MT on same AM the issue does not happen as updates seems to be sequential-ised to the same worker thread (based on tokenId) and the concurrent issue is not seen (due to the same Worker thread works on only the same tokenId). However it seems if concurrent updates on two AM as in the reported case can happen like the following case the exception may happen

      1. Login to AM1
      2. Now access AM1 with a call to (SessionService.notifyListenerFor(thissession, somelistener)
        (for good measure say UpdateTask is a bit slow (ie it read the previous value) but have not updated
        #. Now at the same time AM2 is issues the same command but run quickly to update DJ with new values
      3. Then exception happens

      Maybe the code should use Entries.diffOptions().alwaysReplaceAttributes()
      instead so all updates uses replace. (But this is a bit dangerous due to lost update.).
      In fact one wonder for if all these multi-valued should use permissive modify control

       

       

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                lawrence.yarham Lawrence Yarham
                Reporter:
                chee-weng.chea C-Weng C
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 8h
                  8h