Uploaded image for project: 'James Imap'
  1. James Imap
  2. IMAP-137

JPA fails to persist MailboxMembership Entity on heavy load

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Blocker
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.1
    • Component/s: JPA Mailbox
    • Labels:
      None

      Description

      On heavy load JPA fails to persist MailboxMembership Enitity objects. Thats because it not use the right locking..

      Exception:

      ******************************************************************************

      INFO 10:44:16,401 | james.smtpserver | Successfully spooled mail Mail1271954641807-3007 from rgurule@localhost on 127.0.0.1 for [rlgurule@localhost]
      INFO 10:44:16,404 | james.mailetcontext | Error while storing mail.
      org.apache.james.imap.mailbox.MailboxException: failed. Mail cannot be parsed.;
      nested exception is:
      org.apache.james.imap.mailbox.StorageException: failed. Transaction commit failed.;
      nested exception is:
      <openjpa-1.2.1-r752877:753278 fatal store error> org.apache.openjpa.persistence.RollbackException: The transaction has been rolled back. See the nested exceptions for details on the errors that occurred.
      at org.apache.james.imap.store.StoreMailbox.appendMessage(StoreMailbox.java:265)
      at org.apache.james.MailboxManagerPoster.post(MailboxManagerPoster.java:125)
      at org.apache.jsieve.mailet.SieveMailboxMailet.storeMessageInbox(SieveMailboxMailet.java:369)
      at org.apache.jsieve.mailet.SieveMailboxMailet.sieveMessage(SieveMailboxMailet.java:363)
      at org.apache.jsieve.mailet.SieveMailboxMailet.storeMail(SieveMailboxMailet.java:330)
      at org.apache.jsieve.mailet.SieveMailboxMailet.service(SieveMailboxMailet.java:263)
      at org.apache.james.transport.mailets.LocalDelivery.service(LocalDelivery.java:103)
      at org.apache.james.transport.camel.MailetProcessor.process(MailetProcessor.java:60)
      at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
      at org.apache.camel.processor.DelegateProcessor.proceed(DelegateProcessor.java:82)
      at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:93)
      at org.apache.camel.processor.RedeliveryErrorHandler.processExchange(RedeliveryErrorHandler.java:177)
      at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:143)
      at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:88)
      at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
      at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:228)
      at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
      at org.apache.camel.processor.ChoiceProcessor.process(ChoiceProcessor.java:51)
      at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:67)
      at org.apache.camel.processor.DelegateProcessor.processNext(DelegateProcessor.java:53)
      at org.apache.camel.processor.DelegateProcessor.proceed(DelegateProcessor.java:82)
      at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:93)
      at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:67)
      at org.apache.camel.processor.RedeliveryErrorHandler.processExchange(RedeliveryErrorHandler.java:177)
      at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:143)
      at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:88)
      at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
      at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:228)
      at org.apache.camel.processor.Pipeline.process(Pipeline.java:74)
      at org.apache.camel.processor.RedeliveryErrorHandler.processExchange(RedeliveryErrorHandler.java:177)
      at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:143)
      at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:88)
      at org.apache.camel.spring.spi.TransactionErrorHandler.processByRegularErrorHandler(TransactionErrorHandler.java:90)
      at org.apache.camel.spring.spi.TransactionErrorHandler.process(TransactionErrorHandler.java:81)
      at org.apache.camel.processor.MulticastProcessor.doProcess(MulticastProcessor.java:266)
      at org.apache.camel.processor.MulticastProcessor.access$000(MulticastProcessor.java:59)
      at org.apache.camel.processor.MulticastProcessor$1.call(MulticastProcessor.java:178)
      at org.apache.camel.processor.MulticastProcessor$1.call(MulticastProcessor.java:172)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
      at java.lang.Thread.run(Thread.java:619)
      Caused by: org.apache.james.imap.mailbox.StorageException: failed. Transaction commit failed.;
      nested exception is:
      <openjpa-1.2.1-r752877:753278 fatal store error> org.apache.openjpa.persistence.RollbackException: The transaction has been rolled back. See the nested exceptions for details on the errors that occurred.
      at org.apache.james.imap.jpa.JPATransactionalMapper.commit(JPATransactionalMapper.java:64)
      at org.apache.james.imap.store.transaction.AbstractTransactionalMapper.execute(AbstractTransactionalMapper.java:39)
      at org.apache.james.imap.store.StoreMailbox.appendMessage(StoreMailbox.java:251)
      ... 47 more
      Caused by: <openjpa-1.2.1-r752877:753278 fatal store error> org.apache.openjpa.persistence.RollbackException: The transaction has been rolled back. See the nested exceptions for details on the errors that occurred.
      at org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:523)
      at org.apache.james.imap.jpa.JPATransactionalMapper.commit(JPATransactionalMapper.java:62)
      ... 49 more
      Caused by: <openjpa-1.2.1-r752877:753278 fatal store error> org.apache.openjpa.persistence.EntityExistsException: The transaction has been rolled back. See the nested exceptions for details on the errors that occurred.
      at org.apache.openjpa.kernel.BrokerImpl.newFlushException(BrokerImpl.java:2163)
      at org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2010)
      at org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:1908)
      at org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:1826)
      at org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81)
      at org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1350)
      at org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:877)
      at org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:512)
      ... 50 more
      Caused by: <openjpa-1.2.1-r752877:753278 nonfatal store error> org.apache.openjpa.persistence.EntityExistsException: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL100421033345040' defined on 'MEMBERSHIP'.

      {prepstmnt 1969035904 INSERT INTO Membership (mailboxId, uid, answered, deleted, draft, flagged, internalDate, recent, seen, size, MESSAGE_ID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [params=(long) 1, (long) 1684, (int) 0, (int) 0, (int) 0, (int) 0, (Timestamp) 2010-04-22 10:44:10.092, (int) 1, (int) 0, (int) 10458, (long) 18520]}

      [code=20000, state=23505]
      FailedObject: org.apache.james.imap.jpa.mail.model.JPAMailboxMembership@442adbf4
      at org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4224)
      at org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4197)
      at org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:102)
      at org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:72)
      at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:131)
      at org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flushAndUpdate(BatchingPreparedStatementManagerImpl.java:82)
      at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushInternal(PreparedStatementManagerImpl.java:89)
      at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flush(PreparedStatementManagerImpl.java:72)
      at org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:543)
      at org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:105)
      at org.apache.openjpa.jdbc.kernel.BatchingConstraintUpdateManager.flush(BatchingConstraintUpdateManager.java:59)
      at org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:89)
      at org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:72)
      at org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.java:717)
      at org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:130)
      ... 57 more
      Caused by: org.apache.openjpa.lib.jdbc.ReportingSQLException: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL100421033345040' defined on 'MEMBERSHIP'.

      {prepstmnt 1969035904 INSERT INTO Membership (mailboxId, uid, answered, deleted, draft, flagged, internalDate, recent, seen, size, MESSAGE_ID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [params=(long) 1, (long) 1684, (int) 0, (int) 0, (int) 0, (int) 0, (Timestamp) 2010-04-22 10:44:10.092, (int) 1, (int) 0, (int) 10458, (long) 18520]}

      [code=20000, state=23505]
      at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:192)
      at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.access$700(LoggingConnectionDecorator.java:57)
      at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator$LoggingConnection$LoggingPreparedStatement.executeUpdate(LoggingConnectionDecorator.java:866)
      at org.apache.openjpa.lib.jdbc.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:269)
      at org.apache.openjpa.jdbc.kernel.JDBCStoreManager$CancelPreparedStatement.executeUpdate(JDBCStoreManager.java:1586)
      at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.executeUpdate(PreparedStatementManagerImpl.java:151)
      at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:120)
      ... 67 more

        Attachments

          Activity

            People

            • Assignee:
              norman Norman Maurer
              Reporter:
              norman Norman Maurer
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: