Uploaded image for project: 'Isis'
  1. Isis
  2. ISIS-1481

Duplicate PK exception for SessoinLogEntry (isisaddons implementation of SessionLoggingService) due to race condition.

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 1.13.0
    • Fix Version/s: 1.13.1
    • Component/s: Core
    • Labels:
      None

      Description

      for example:

      java.sql.BatchUpdateException: Violation of PRIMARY KEY constraint 'SessionLogEntry_PK'. Cannot insert duplicate key in object 'isissessionlogger.SessionLogEntry'. The duplicate key value is (1379530416).
              at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:543)
              at org.datanucleus.api.jdo.JDOPersistenceManager.flush(JDOPersistenceManager.java:2070)
              at org.apache.isis.core.runtime.system.persistence.PersistenceSession.executeCommands(PersistenceSession.java:1255)
              at org.apache.isis.core.runtime.system.persistence.PersistenceSession.execute(PersistenceSession.java:1247)
              at org.apache.isis.core.runtime.system.transaction.IsisTransaction.doFlush(IsisTransaction.java:378)
              at org.apache.isis.core.runtime.system.transaction.IsisTransaction.preCommit(IsisTransaction.java:419)
              at org.apache.isis.core.runtime.system.transaction.IsisTransactionManager.endTransaction(IsisTransactionManager.java:344)
              at org.apache.isis.core.runtime.system.transaction.IsisTransactionManager.executeWithinTransaction(IsisTransactionManager.java:145)
              at org.apache.isis.core.runtime.system.transaction.IsisTransactionManager.executeWithinTransaction(IsisTransactionManager.java:133)
              at org.apache.isis.core.runtime.system.persistence.PersistenceSession.makePersistentInTransaction(PersistenceSession.java:1102)
              at org.apache.isis.core.runtime.services.persistsession.PersistenceSessionServiceInternalDefault.makePersistent(PersistenceSessionServiceInternalDefault.java:83)
              at org.apache.isis.core.metamodel.services.repository.RepositoryServiceInternalDefault.persist(RepositoryServiceInternalDefault.java:96)
              at org.apache.isis.core.metamodel.services.container.DomainObjectContainerDefault.persistIfNotAlready(DomainObjectContainerDefault.java:365)
              at org.apache.isis.applib.AbstractContainedObject.persistIfNotAlready(AbstractContainedObject.java:574)
              at org.isisaddons.module.sessionlogger.dom.SessionLoggingServiceDefault.log(SessionLoggingServiceDefault.java:42)
              at org.apache.isis.viewer.wicket.viewer.integration.wicket.AuthenticatedWebSessionForIsis$1.run(AuthenticatedWebSessionForIsis.java:180)
              at org.apache.isis.core.runtime.system.session.IsisSessionFactory$1.call(IsisSessionFactory.java:316)
              at org.apache.isis.core.runtime.system.session.IsisSessionFactory$1.call(IsisSessionFactory.java:313)
              at org.apache.isis.core.runtime.system.session.IsisSessionFactory.doInSession(IsisSessionFactory.java:347)
              ... 60 more
      
      
      sessionId causedBy loginTimestamp logoutTimestamp user
      1379530416 NULL 2016-09-07 10:14:47.5690000 NULL enicoletti@ecp.loc

      Here's some more:

      11:46:37,702 [WebRequestCycleForIsis        ] Unable to obtain exceptionRecognizers (no session), will be treated as unrecognized exception
      org.apache.wicket.protocol.http.PageExpiredException: Page with id '8' has expired.
      11:48:11,808 [PersistenceSession            ] close: failed to close JDO persistenceManager; continuing to avoid memory leakage
      07-Sep-2016 11:48:09.973 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.core.StandardContext.backgroundProcess Exception processing manager org.apache.catalina.session.StandardManager[/estatioprod] background process
       java.lang.IllegalStateException: No service of type class org.apache.isis.applib.services.command.CommandContext is available on this
              at org.apache.isis.core.runtime.services.ServiceInstantiator$2.invoke(ServiceInstantiator.java:217)
              at org.apache.isis.applib.services.command.CommandContext_$$_jvst9b7_2.getCommand(CommandContext_$$_jvst9b7_2.java)
              at org.apache.isis.core.runtime.system.persistence.PersistenceSession.completeCommandFromInteractionAndClearDomainEvents(PersistenceSession.java:483)
              at org.apache.isis.core.runtime.system.persistence.PersistenceSession.close(PersistenceSession.java:414)
              at org.apache.isis.core.runtime.system.session.IsisSession.close(IsisSession.java:69)
              at org.apache.isis.core.runtime.system.session.IsisSessionFactory.closeSession(IsisSessionFactory.java:263)
              at org.apache.isis.core.runtime.system.session.IsisSessionFactory.doInSession(IsisSessionFactory.java:354)
              at org.apache.isis.core.runtime.system.session.IsisSessionFactory.doInSession(IsisSessionFactory.java:327)
              at org.apache.isis.viewer.wicket.viewer.integration.wicket.AuthenticatedWebSessionForIsis.getSessionLoggingService(AuthenticatedWebSessionForIsis.java:187)
              at org.apache.isis.viewer.wicket.viewer.integration.wicket.AuthenticatedWebSessionForIsis.log(AuthenticatedWebSessionForIsis.java:173)
              at org.apache.isis.viewer.wicket.viewer.integration.wicket.AuthenticatedWebSessionForIsis.onInvalidate(AuthenticatedWebSessionForIsis.java:120)
              at org.apache.wicket.session.HttpSessionStore$SessionBindingListener.valueUnbound(HttpSessionStore.java:471)
              at org.apache.catalina.session.StandardSession.removeAttributeInternal(StandardSession.java:1838)
              at org.apache.catalina.session.StandardSession.expire(StandardSession.java:891)
              at org.apache.catalina.session.StandardSession.isValid(StandardSession.java:694)
              at org.apache.catalina.session.ManagerBase.processExpires(ManagerBase.java:666)
              at org.apache.catalina.session.ManagerBase.backgroundProcess(ManagerBase.java:651)
              at org.apache.catalina.core.StandardContext.backgroundProcess(StandardContext.java:5625)
              at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1377)
              at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1381)
              at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1381)
              at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1349)
              at java.lang.Thread.run(Thread.java:745)
      

        Activity

        Hide
        danhaywood Dan Haywood added a comment -

        Martin Grigorov helped track it down:

        [13:38:59] Martin Grigorov: so there are two login attempts on the same session ... This is strange
        [13:40:07] Martin Grigorov: it could be a bug in https://github.com/apache/wicket/blob/master/wicket-auth-roles/src/main/java/org/apache/wicket/authroles/authentication/AuthenticatedWebSession.java
        [13:40:20] Martin Grigorov: there is no synchronization on 'signedIn'
        [13:41:04] Martin Grigorov: but it is volatile
        [13:41:16] Martin Grigorov: so this is not the problem
        [13:41:36] Martin Grigorov: well, it IS possible
        [13:41:45] Dan Haywood: But perhaps the signIn() method should be synchronized?
        [13:41:55] Martin Grigorov: exactly
        [13:42:10] Martin Grigorov: all of the methods should be, IMO
        [13:42:40] Martin Grigorov: or signIn() should at least do another check before calling authenticate()
        [13:43:06] Martin Grigorov: I think all methods need synchronization
        [13:43:16] Martin Grigorov: this volatile boolean is not enough
        [13:43:41] Dan Haywood: OK.  Thanks.  I'll do exactly that.
        
        Show
        danhaywood Dan Haywood added a comment - Martin Grigorov helped track it down: [13:38:59] Martin Grigorov: so there are two login attempts on the same session ... This is strange [13:40:07] Martin Grigorov: it could be a bug in https: //github.com/apache/wicket/blob/master/wicket-auth-roles/src/main/java/org/apache/wicket/authroles/authentication/AuthenticatedWebSession.java [13:40:20] Martin Grigorov: there is no synchronization on 'signedIn' [13:41:04] Martin Grigorov: but it is volatile [13:41:16] Martin Grigorov: so this is not the problem [13:41:36] Martin Grigorov: well, it IS possible [13:41:45] Dan Haywood: But perhaps the signIn() method should be synchronized ? [13:41:55] Martin Grigorov: exactly [13:42:10] Martin Grigorov: all of the methods should be, IMO [13:42:40] Martin Grigorov: or signIn() should at least do another check before calling authenticate() [13:43:06] Martin Grigorov: I think all methods need synchronization [13:43:16] Martin Grigorov: this volatile boolean is not enough [13:43:41] Dan Haywood: OK. Thanks. I'll do exactly that.
        Hide
        jira-bot ASF subversion and git services added a comment -

        Commit bab40dc25d00761bd447a0aaa7305f4efea7044d in isis's branch refs/heads/maint-1.13.1 from Dan Haywood
        [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=bab40dc ]

        ISIS-1481: ensures that all methods of AuthenticatedWebSession are synchronized, in order to avoid a race conditions, eg in SessionLoggingService when authenicating.

        Show
        jira-bot ASF subversion and git services added a comment - Commit bab40dc25d00761bd447a0aaa7305f4efea7044d in isis's branch refs/heads/maint-1.13.1 from Dan Haywood [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=bab40dc ] ISIS-1481 : ensures that all methods of AuthenticatedWebSession are synchronized, in order to avoid a race conditions, eg in SessionLoggingService when authenicating.
        Hide
        jira-bot ASF subversion and git services added a comment -

        Commit e5ecb8821717b287f96eee4cd711665b5c14b87f in isis's branch refs/heads/maint-1.13.1 from Dan Haywood
        [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=e5ecb88 ]

        ISIS-1481: no need to obtain SessionLoggingService from within a session.

        Show
        jira-bot ASF subversion and git services added a comment - Commit e5ecb8821717b287f96eee4cd711665b5c14b87f in isis's branch refs/heads/maint-1.13.1 from Dan Haywood [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=e5ecb88 ] ISIS-1481 : no need to obtain SessionLoggingService from within a session.
        Hide
        jira-bot ASF subversion and git services added a comment -

        Commit 6a2061e8c14525eac2390b372cef84ad91752934 in isis's branch refs/heads/master from Dan Haywood
        [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=6a2061e ]

        ISIS-1481: ensures that all methods of AuthenticatedWebSession are synchronized, in order to avoid a race conditions, eg in SessionLoggingService when authenicating.

        Show
        jira-bot ASF subversion and git services added a comment - Commit 6a2061e8c14525eac2390b372cef84ad91752934 in isis's branch refs/heads/master from Dan Haywood [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=6a2061e ] ISIS-1481 : ensures that all methods of AuthenticatedWebSession are synchronized, in order to avoid a race conditions, eg in SessionLoggingService when authenicating.
        Hide
        jira-bot ASF subversion and git services added a comment -

        Commit db49606ef37ecba2b67492a192235963e195efaa in isis's branch refs/heads/master from Dan Haywood
        [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=db49606 ]

        ISIS-1481: no need to obtain SessionLoggingService from within a session.

        Show
        jira-bot ASF subversion and git services added a comment - Commit db49606ef37ecba2b67492a192235963e195efaa in isis's branch refs/heads/master from Dan Haywood [ https://git-wip-us.apache.org/repos/asf?p=isis.git;h=db49606 ] ISIS-1481 : no need to obtain SessionLoggingService from within a session.
        Show
        mgrigorov Martin Grigorov added a comment - Hi Dan, Here is my suggested fix in Wicket: https://git1-us-west.apache.org/repos/asf?p=wicket.git;a=commitdiff;h=a384c6f7;hp=6f530a925c25006a80cc97c5a30bca66a471cfe8 We also discuss it at dev@wicket.apache.org ( http://markmail.org/message/syo3m6hrf2ix55rz )

          People

          • Assignee:
            danhaywood Dan Haywood
            Reporter:
            danhaywood Dan Haywood
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development