You are viewing a plain text version of this content. The canonical link for it is here.
Posted to server-user@james.apache.org by l0c4l h0st <l0...@gmail.com> on 2012/03/21 12:21:59 UTC

Message logged at wrong logging level (debug, should be error or fatal)

When appending a message through IMAP, that is too big, because of
server settings, a DEBUG message is logged with this error. However,
due to logging levels in James, this message is not visible and you
just get a "APPEND failed. Save failed.", without any error message in
the James console or log files.

I think this message should be logged with ERROR by default.

Maybe James should try to set max_allowed_packet in the MySQL-session
(same for Oracle, PgSQL, etc of course)?

At the very least, users that run the server should be notified about
this. So the message should not be DEBUG.

DEBUG 12:05:40,353 | james.imapserver | ID=2067447613 Unable to append message
org.apache.james.mailbox.MailboxException: Unable to parse message
	at org.apache.james.mailbox.store.StoreMessageManager.appendMessage(StoreMessageManager.java:314)
	at org.apache.james.imap.processor.AppendProcessor.appendToMailbox(AppendProcessor.java:137)
	at org.apache.james.imap.processor.AppendProcessor.doProcess(AppendProcessor.java:74)
	at org.apache.james.imap.processor.AppendProcessor.doProcess(AppendProcessor.java:48)
	at org.apache.james.imap.processor.AbstractMailboxProcessor.doProcess(AbstractMailboxProcessor.java:90)
	at org.apache.james.imap.processor.AbstractMailboxProcessor.process(AbstractMailboxProcessor.java:79)
	at org.apache.james.imap.processor.AbstractMailboxProcessor.doProcess(AbstractMailboxProcessor.java:73)
	at org.apache.james.imap.processor.AbstractMailboxProcessor.doProcess(AbstractMailboxProcessor.java:56)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:55)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imap.processor.base.AbstractChainedProcessor.process(AbstractChainedProcessor.java:57)
	at org.apache.james.imapserver.netty.ImapChannelUpstreamHandler.messageReceived(ImapChannelUpstreamHandler.java:175)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.handler.stream.ChunkedWriteHandler.handleUpstream(ChunkedWriteHandler.java:148)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:134)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:302)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:317)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:299)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:216)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:302)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:317)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:299)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:214)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:134)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:134)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.SimpleChannelHandler.messageReceived(SimpleChannelHandler.java:154)
	at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:100)
	at org.jboss.netty.handler.timeout.IdleStateAwareChannelHandler.handleUpstream(IdleStateAwareChannelHandler.java:48)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.handler.timeout.IdleStateHandler.messageReceived(IdleStateHandler.java:276)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:134)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:540)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:274)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:261)
	at org.jboss.netty.channel.socket.oio.OioWorker.run(OioWorker.java:90)
	at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
	at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:44)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:636)
Caused by: org.apache.james.mailbox.MailboxException: Commit of
transaction failed
	at org.apache.james.mailbox.jpa.mail.JPAMessageMapper.commit(JPAMessageMapper.java:93)
	at org.apache.james.mailbox.store.transaction.TransactionalMapper.execute(TransactionalMapper.java:39)
	at org.apache.james.mailbox.store.StoreMessageManager.appendMessageToStore(StoreMessageManager.java:494)
	at org.apache.james.mailbox.store.StoreMessageManager.appendMessage(StoreMessageManager.java:303)
	... 78 more
Caused by: <openjpa-2.1.0-r422266:1071316 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.openjpa.JPAMessage@71a9b093
	at org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:585)
	at org.apache.james.mailbox.jpa.mail.JPAMessageMapper.commit(JPAMessageMapper.java:91)
	... 81 more
Caused by: <openjpa-2.1.0-r422266:1071316 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.openjpa.JPAMessage@71a9b093
	at org.apache.openjpa.kernel.BrokerImpl.newFlushException(BrokerImpl.java:2316)
	at org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2153)
	at org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:2051)
	at org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:1969)
	at org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81)
	at org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1493)
	at org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:925)
	at org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:561)
	... 82 more
Caused by: <openjpa-2.1.0-r422266:1071316 fatal general error>
org.apache.openjpa.persistence.PersistenceException: Packet for query
is too large (16653098 > 1048576). You can change this value on the
server by setting the max_allowed_packet' variable. {prepstmnt
1319977873 INSERT INTO JAMES_MAIL (MAILBOX_ID, MAIL_UID,
MAIL_IS_ANSWERED, MAIL_BODY_START_OCTET, MAIL_CONTENT_OCTETS_COUNT,
MAIL_IS_DELETED, MAIL_IS_DRAFT, MAIL_IS_FLAGGED, MAIL_DATE,
MAIL_MIME_TYPE, MAIL_MODSEQ, MAIL_IS_RECENT, MAIL_IS_SEEN,
MAIL_MIME_SUBTYPE, MAIL_TEXTUAL_LINE_COUNT, MAIL_BYTES, HEADER_BYTES)
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [params=?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?]} [code=0, state=S1000]
FailedObject: org.apache.james.mailbox.jpa.mail.model.openjpa.JPAMessage@71a9b093
	at org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4869)
	at org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4829)
	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:81)
	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:103)
	at org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:76)
	at org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.java:742)
	at org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:131)
	... 89 more
Caused by: org.apache.openjpa.lib.jdbc.ReportingSQLException: Packet
for query is too large (16653098 > 1048576). You can change this value
on the server by setting the max_allowed_packet' variable. {prepstmnt
1319977873 INSERT INTO JAMES_MAIL (MAILBOX_ID, MAIL_UID,
MAIL_IS_ANSWERED, MAIL_BODY_START_OCTET, MAIL_CONTENT_OCTETS_COUNT,
MAIL_IS_DELETED, MAIL_IS_DRAFT, MAIL_IS_FLAGGED, MAIL_DATE,
MAIL_MIME_TYPE, MAIL_MODSEQ, MAIL_IS_RECENT, MAIL_IS_SEEN,
MAIL_MIME_SUBTYPE, MAIL_TEXTUAL_LINE_COUNT, MAIL_BYTES, HEADER_BYTES)
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [params=?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?]} [code=0, state=S1000]
	at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:281)
	at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:257)
	at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.access$1000(LoggingConnectionDecorator.java:72)
	at org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator$LoggingConnection$LoggingPreparedStatement.executeUpdate(LoggingConnectionDecorator.java:1199)
	at org.apache.openjpa.lib.jdbc.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:291)
	at org.apache.openjpa.jdbc.kernel.JDBCStoreManager$CancelPreparedStatement.executeUpdate(JDBCStoreManager.java:1776)
	at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.executeUpdate(PreparedStatementManagerImpl.java:267)
	at org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:118)
	... 100 more

---------------------------------------------------------------------
To unsubscribe, e-mail: server-user-unsubscribe@james.apache.org
For additional commands, e-mail: server-user-help@james.apache.org