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

Exception while storing messages on heavy load

    XMLWordPrintableJSON

    Details

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

      Description

      On heavy load (many concurrent connections), I saw the following exception in the log:

      INFO 16:54:17,184 | 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 d
      etails on the errors that occurred.
      at org.apache.james.imap.store.StoreMailbox.appendMessage(StoreMailbox.java:215)
      at org.apache.james.imapserver.mina.AsyncImapServer.postToMailbox(AsyncImapServer.java:191)
      at org.apache.james.imapserver.mina.AsyncImapServer.post(AsyncImapServer.java:159)
      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.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:223)
      at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:153)
      at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:91)
      at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
      at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:206)
      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:223)
      at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:153)
      at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:91)
      at org.apache.camel.processor.DefaultErrorHandler.process(DefaultErrorHandler.java:49)
      at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:206)
      at org.apache.camel.processor.Pipeline.process(Pipeline.java:74)
      at org.apache.camel.processor.MulticastProcessor.doProcess(MulticastProcessor.java:241)
      at org.apache.camel.processor.MulticastProcessor.access$000(MulticastProcessor.java:57)
      at org.apache.camel.processor.MulticastProcessor$1.call(MulticastProcessor.java:166)
      at org.apache.camel.processor.MulticastProcessor$1.call(MulticastProcessor.java:160)
      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:885)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
      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.mail.JPATransactionalMapper.commit(JPATransactionalMapper.java:61)
      at org.apache.james.imap.store.mail.AbstractTransactionalMapper.execute(AbstractTransactionalMapper.java:40)
      at org.apache.james.imap.store.StoreMailbox.appendMessage(StoreMailbox.java:203)
      ... 42 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.mail.JPATransactionalMapper.commit(JPATransactionalMapper.java:59)
      ... 44 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)
      ... 45 more
      Caused by: <openjpa-1.2.1-r752877:753278 nonfatal store error> org.apache.openjpa.persistence.EntityExistsException: Duplicate entry '1-11054' for key 'PRIMARY'

      {prepstmnt 13351016 INSERT INTO Membership (mailboxId, uid, answered, deleted, draft, flagged, internalDate, recent, seen, size, MESSAGE_ID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [params=(long) 1, (long) 11054, (int) 0, (int) 0, (int) 0, (int) 0, (Timestamp) 2010-03-08 16:54:17.076, (int) 1, (int) 0, (int) 4087, (long) 468918]}

      [code=1062, state=23000]
      FailedObject: org.apache.james.imap.jpa.mail.model.JPAMailboxMembership@1360f88
      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)
      ... 52 more
      Caused by: org.apache.openjpa.lib.jdbc.ReportingSQLException: Duplicate entry '1-11054' for key 'PRIMARY'

      {prepstmnt 13351016 INSERT INTO Membership (mailboxId, uid, answered, deleted, draft, flagged, internalDate, recent, seen, size, MESSAGE_ID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [params=(long) 1, (long) 11054, (int) 0, (int) 0, (int) 0, (int) 0, (Timestamp) 2010-03-08 16:54:17.076, (int) 1, (int) 0, (int) 4087, (long) 468918]}

      [code=1062, state=23000]
      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)
      ... 62 more
      INFO 16:54:17,292 | james.mailetcontext | Storing mail Mail1268067257191-220-!1034249 in file://var/mail/error/

        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: