Kohei Nozaki created MAILBOX-218:
------------------------------------
Summary: Deadlock on JPAMessageMapper.commit()
Key: MAILBOX-218
URL: https://issues.apache.org/jira/browse/MAILBOX-218
Project: James Mailbox
Issue Type: Bug
Components: jpa
Affects Versions: 0.5
Environment: Apache Derby 10.11.1.1 (Embedded)
Reporter: Kohei Nozaki
I acquired the source tree in February 4 of this year.
{noformat}
$ pwd
/Users/kyle/src/james-server
$ svn info | grep "Revision:"
Revision: 1657019
{noformat}
Related libraries:
{noformat}
-rw------- 1 james james 118172 Feb 4 15:59
apache-james-mailbox-api-0.6-20150204.040032-612.jar
-rw------- 1 james james 38208 Feb 4 16:05
apache-james-mailbox-cassandra-0.6-20150204.040425-162.jar
-rw------- 1 james james 58663 Feb 4 16:05
apache-james-mailbox-jcr-0.6-20150204.040507-581.jar
-rw------- 1 james james 78735 Feb 4 16:05
apache-james-mailbox-jpa-0.6-20150204.040524-579.jar
-rw------- 1 james james 33190 Feb 4 16:05
apache-james-mailbox-lucene-0.6-20150204.040533-581.jar
-rw------- 1 james james 75204 Feb 4 15:59
apache-james-mailbox-maildir-0.6-20150204.040556-576.jar
-rw------- 1 james james 23255 Feb 4 15:59
apache-james-mailbox-memory-0.6-20150204.040602-577.jar
-rw------- 1 james james 18574 Feb 4 16:05
apache-james-mailbox-spring-0.6-20150204.040621-568.jar
-rw------- 1 james james 188973 Feb 4 15:59
apache-james-mailbox-store-0.6-20150204.040045-608.jar
-rw------- 1 james james 25298 Feb 4 15:59
apache-james-mailbox-tool-0.6-20150204.040612-571.jar
{noformat}
Full stacktrace: (My domain name is replaced by example.org).
{noformat}
INFO 02:59:39,076 | james.imapserver | ID=1273650075 Unable to append message
to mailbox #private:[email protected]:Freelancer
org.apache.james.mailbox.exception.MailboxException: Commit of transaction
failed
at
org.apache.james.mailbox.jpa.mail.JPAMessageMapper.commit(JPAMessageMapper.java:95)
at
org.apache.james.mailbox.store.transaction.TransactionalMapper.execute(TransactionalMapper.java:38)
at
org.apache.james.mailbox.store.StoreMessageManager.appendMessageToStore(StoreMessageManager.java:607)
at
org.apache.james.mailbox.store.StoreMessageManager$1.execute(StoreMessageManager.java:373)
at
org.apache.james.mailbox.store.StoreMessageManager$1.execute(StoreMessageManager.java:369)
at
org.apache.james.mailbox.store.AbstractMailboxPathLocker.executeWithLock(AbstractMailboxPathLocker.java:38)
at
org.apache.james.mailbox.store.StoreMessageManager.appendMessage(StoreMessageManager.java:369)
at
org.apache.james.imap.processor.AppendProcessor.appendToMailbox(AppendProcessor.java:135)
at
org.apache.james.imap.processor.AppendProcessor.doProcess(AppendProcessor.java:72)
at
org.apache.james.imap.processor.AppendProcessor.doProcess(AppendProcessor.java:48)
at
org.apache.james.imap.processor.AbstractMailboxProcessor.doProcess(AbstractMailboxProcessor.java:100)
at
org.apache.james.imap.processor.AbstractMailboxProcessor.process(AbstractMailboxProcessor.java:89)
at
org.apache.james.imap.processor.AbstractMailboxProcessor.doProcess(AbstractMailboxProcessor.java:83)
at
org.apache.james.imap.processor.AbstractMailboxProcessor.doProcess(AbstractMailboxProcessor.java:66)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:52)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:54)
at
org.apache.james.imapserver.netty.ImapChannelUpstreamHandler.messageReceived(ImapChannelUpstreamHandler.java:187)
at
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:558)
at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:777)
at
org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296)
at
org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:327)
at
org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:305)
at
org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:218)
at
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:558)
at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:777)
at
org.jboss.netty.handler.execution.ChannelUpstreamEventRunnable.run(ChannelUpstreamEventRunnable.java:44)
at
org.jboss.netty.handler.execution.OrderedMemoryAwareThreadPoolExecutor$ChildExecutor.run(OrderedMemoryAwareThreadPoolExecutor.java:312)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: <openjpa-2.2.1-r422266:1396819 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.
FailedObject: org.apache.james.mailbox.jpa.mail.model.JPAProperty@64540477
at
org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:594)
at
org.apache.james.mailbox.jpa.mail.JPAMessageMapper.commit(JPAMessageMapper.java:93)
... 51 more
Caused by: <openjpa-2.2.1-r422266:1396819 fatal general error>
org.apache.openjpa.persistence.PersistenceException: The transaction has been
rolled back. See the nested exceptions for details on the errors that occurred.
FailedObject: org.apache.james.mailbox.jpa.mail.model.JPAProperty@64540477
at
org.apache.openjpa.kernel.BrokerImpl.newFlushException(BrokerImpl.java:2339)
at org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2176)
at org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:2074)
at
org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:1992)
at
org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81)
at org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1516)
at
org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:933)
at
org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:570)
... 52 more
Caused by: <openjpa-2.2.1-r422266:1396819 nonfatal store error>
org.apache.openjpa.persistence.OptimisticLockException: Unable to obtain an
object lock on "org.apache.james.mailbox.jpa.mail.model.JPAProperty@64540477".
FailedObject: org.apache.james.mailbox.jpa.mail.model.JPAProperty@64540477
at
org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4940)
at
org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4918)
at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:136)
at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:78)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:143)
at
org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flushAndUpdate(BatchingPreparedStatementManagerImpl.java:79)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushInternal(PreparedStatementManagerImpl.java:99)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flush(PreparedStatementManagerImpl.java:87)
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:357)
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flushGraph(ConstraintUpdateManager.java:349)
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:97)
at
org.apache.openjpa.jdbc.kernel.BatchingConstraintUpdateManager.flush(BatchingConstraintUpdateManager.java:59)
at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:105)
at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:78)
at
org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.java:735)
at
org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:131)
... 59 more
Caused by: org.apache.openjpa.lib.jdbc.ReportingSQLException: A lock could not
be obtained due to a deadlock, cycle of locks and waiters is:
Lock : TABLE, JAMES_MAIL_PROPERTY, Tablelock
Waiting XID : {830775058, IX} , APP, INSERT INTO APP.JAMES_MAIL_PROPERTY
(PROPERTY_ID, PROPERTY_LINE_NUMBER, PROPERTY_LOCAL_NAME, PROPERTY_NAME_SPACE,
PROPERTY_VALUE, MAILBOX_ID, MAIL_UID) VALUES (?, ?, ?, ?, ?, ?, ?)
Granted XID : {830775037, X}
Lock : ROW, JAMES_MAIL, (1078,6)
Waiting XID : {830775037, U} , APP, DELETE FROM APP.JAMES_MAIL WHERE EXISTS
(SELECT 1 FROM APP.JAMES_MAIL t0 WHERE (t0.MAILBOX_ID = ? AND
t0.MAIL_IS_DELETED = ?) AND (t0.MAILBOX_ID = APP.JAMES_MAIL.MAILBOX_ID AND
t0.MAIL_UID = APP.JAMES_MAIL.MAIL_UID))
Granted XID : {830775058, X}
. The selected victim is XID : 830775058. {prepstmnt 1111910471 INSERT INTO
APP.JAMES_MAIL_PROPERTY (PROPERTY_ID, PROPERTY_LINE_NUMBER,
PROPERTY_LOCAL_NAME, PROPERTY_NAME_SPACE, PROPERTY_VALUE, MAILBOX_ID, MAIL_UID)
VALUES (?, ?, ?, ?, ?, ?, ?)} [code=30000, state=40001]
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:219)
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:195)
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.access$1000(LoggingConnectionDecorator.java:59)
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator$LoggingConnection$LoggingPreparedStatement.executeUpdate(LoggingConnectionDecorator.java:1134)
at
org.apache.openjpa.lib.jdbc.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:272)
at
org.apache.openjpa.jdbc.kernel.JDBCStoreManager$CancelPreparedStatement.executeUpdate(JDBCStoreManager.java:1765)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.executeUpdate(PreparedStatementManagerImpl.java:267)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:118)
... 70 more
INFO 03:01:45,143 | james.imapserver | ID=1773825505 Logout client
i114-187-224-118.s41.a037.ap.plala.or.jp (114.187.224.118) because it idled for
too long...
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
