You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Alex Rudyy (JIRA)" <ji...@apache.org> on 2014/12/04 16:18:12 UTC

[jira] [Created] (QPID-6260) [Java Broker] On running out of disk space in BDB committer thread the broker continues running with closed environment and an ACTIVE virtual host

Alex Rudyy created QPID-6260:
--------------------------------

             Summary: [Java Broker] On running out of disk space in BDB committer thread the broker continues running with closed environment and an ACTIVE virtual host
                 Key: QPID-6260
                 URL: https://issues.apache.org/jira/browse/QPID-6260
             Project: Qpid
          Issue Type: Bug
          Components: Java Broker
    Affects Versions: 0.30
            Reporter: Alex Rudyy


On running out of disk space in BDB committer thread the broker continues running with closed environment and an ACTIVE virtual host.
{noformat}
2014-12-04 09:38:01,172 INFO  [IoReceiver - /169.124.113.161:46753] (connection.open) - [con:7(/169.124.113.161:46753)] CON-1001 : Open
2014-12-04 09:38:01,173 INFO  [IoReceiver - /169.124.113.161:46753] (connection.open) - [con:7(/169.124.113.161:46753)] CON-1001 : Open : Protocol Version : 0-10
2014-12-04 09:38:01,180 INFO  [IoReceiver - /169.124.113.161:46753] (connection.open) - [con:7(guest@/169.124.113.161:46753/default)] CON-1001 : Open : Client ID : clientid : Protocol Version : 0-10 : Client Version : 0.30;JPMC 5.0.0-SNAPSHOT : Client Product : qpid
2014-12-04 09:38:01,185 INFO  [IoReceiver - /169.124.113.161:46753] (channel.create) - [con:7(guest@/169.124.113.161:46753/default)/ch:0] CHN-1001 : Create
2014-12-04 09:38:01,198 INFO  [IoReceiver - /169.124.113.161:46753] (channel.create) - [con:7(guest@/169.124.113.161:46753/default)/ch:1] CHN-1001 : Create
2014-12-04 09:38:01,210 ERROR [Commit-Thread-default] (berkeleydb.CoalescingCommiter$CommitThread) - Exception during environment log flush
com.sleepycat.je.LogWriteException: (JE 5.0.97) /home/a_qpid/destructive-tests/qpid-broker/5.1.0-SNAPSHOT/my-work/default/messages java.io.IOException: No space left on device LOG_WRITE: IOException on write, log is likely incomplete. Environment is invalid and must be closed.
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1648)
        at com.sleepycat.je.log.LogBufferPool.writeBufferToFile(LogBufferPool.java:411)
        at com.sleepycat.je.log.LogBufferPool.writeDirty(LogBufferPool.java:370)
        at com.sleepycat.je.log.SyncedLogManager.flushInternal(SyncedLogManager.java:81)
        at com.sleepycat.je.log.LogManager.flush(LogManager.java:1231)
        at com.sleepycat.je.dbi.EnvironmentImpl.flushLog(EnvironmentImpl.java:2060)
        at com.sleepycat.je.Environment.flushLog(Environment.java:1593)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.processJobs(CoalescingCommiter.java:236)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.run(CoalescingCommiter.java:217)
Caused by: java.io.IOException: No space left on device
        at java.io.RandomAccessFile.writeBytes0(Native Method)
        at java.io.RandomAccessFile.writeBytes(RandomAccessFile.java:520)
        at java.io.RandomAccessFile.write(RandomAccessFile.java:550)
        at com.sleepycat.je.log.FileManager.writeToFile(FileManager.java:1753)
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1633)
        ... 8 more
2014-12-04 09:38:01,213 ERROR [Commit-Thread-default] (berkeleydb.CoalescingCommiter$CommitThread) - Closing store environment
com.sleepycat.je.LogWriteException: (JE 5.0.97) /home/a_qpid/destructive-tests/qpid-broker/5.1.0-SNAPSHOT/my-work/default/messages java.io.IOException: No space left on device LOG_WRITE: IOException on write, log is likely incomplete. Environment is invalid and must be closed.
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1648)
        at com.sleepycat.je.log.LogBufferPool.writeBufferToFile(LogBufferPool.java:411)
        at com.sleepycat.je.log.LogBufferPool.writeDirty(LogBufferPool.java:370)
        at com.sleepycat.je.log.SyncedLogManager.flushInternal(SyncedLogManager.java:81)
        at com.sleepycat.je.log.LogManager.flush(LogManager.java:1231)
        at com.sleepycat.je.dbi.EnvironmentImpl.flushLog(EnvironmentImpl.java:2060)
        at com.sleepycat.je.Environment.flushLog(Environment.java:1593)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.processJobs(CoalescingCommiter.java:236)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.run(CoalescingCommiter.java:217)
Caused by: java.io.IOException: No space left on device
        at java.io.RandomAccessFile.writeBytes0(Native Method)
        at java.io.RandomAccessFile.writeBytes(RandomAccessFile.java:520)
        at java.io.RandomAccessFile.write(RandomAccessFile.java:550)
        at com.sleepycat.je.log.FileManager.writeToFile(FileManager.java:1753)
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1633)
        ... 8 more
2014-12-04 09:38:01,213 ERROR [IoReceiver - /169.124.113.161:46753] (v0_10.ServerSessionDelegate) - Exception processing command
com.sleepycat.je.LogWriteException: (JE 5.0.97) /home/a_qpid/destructive-tests/qpid-broker/5.1.0-SNAPSHOT/my-work/default/messages java.io.IOException: No space left on device LOG_WRITE: IOException on write, log is likely incomplete. Environment is invalid and must be closed.
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1648)
        at com.sleepycat.je.log.LogBufferPool.writeBufferToFile(LogBufferPool.java:411)
        at com.sleepycat.je.log.LogBufferPool.writeDirty(LogBufferPool.java:370)
        at com.sleepycat.je.log.SyncedLogManager.flushInternal(SyncedLogManager.java:81)
        at com.sleepycat.je.log.LogManager.flush(LogManager.java:1231)
        at com.sleepycat.je.dbi.EnvironmentImpl.flushLog(EnvironmentImpl.java:2060)
        at com.sleepycat.je.Environment.flushLog(Environment.java:1593)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.processJobs(CoalescingCommiter.java:236)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.run(CoalescingCommiter.java:217)
Caused by: java.io.IOException: No space left on device
        at java.io.RandomAccessFile.writeBytes0(Native Method)
        at java.io.RandomAccessFile.writeBytes(RandomAccessFile.java:520)
        at java.io.RandomAccessFile.write(RandomAccessFile.java:550)
        at com.sleepycat.je.log.FileManager.writeToFile(FileManager.java:1753)
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1633)
        ... 8 more
2014-12-04 09:38:01,216 ERROR [Commit-Thread-default] (berkeleydb.CoalescingCommiter$CommitThread) - Exception closing store environment
com.sleepycat.je.LogWriteException: (JE 5.0.97) Environment must be closed, caused by: com.sleepycat.je.LogWriteException: Environment invalid because of previous exception: (JE 5.0.97) /home/a_qpid/destructive-tests/qpid-broker/5.1.0-SNAPSHOT/my-work/default/messages java.io.IOException: No space left on device LOG_WRITE: IOException on write, log is likely incomplete. Environment is invalid and must be closed.
        at com.sleepycat.je.LogWriteException.wrapSelf(LogWriteException.java:72)
        at com.sleepycat.je.dbi.EnvironmentImpl.checkIfInvalid(EnvironmentImpl.java:1594)
        at com.sleepycat.je.Environment.checkEnv(Environment.java:2225)
        at com.sleepycat.je.Environment.cleanLog(Environment.java:1677)
        at org.apache.qpid.server.store.berkeleydb.BDBUtils.runCleaner(BDBUtils.java:87)
        at org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.closeEnvironment(StandardEnvironmentFacade.java:265)
        at org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.close(StandardEnvironmentFacade.java:161)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.processJobs(CoalescingCommiter.java:278)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.run(CoalescingCommiter.java:217)
Caused by: com.sleepycat.je.LogWriteException: Environment invalid because of previous exception: (JE 5.0.97) /home/a_qpid/destructive-tests/qpid-broker/5.1.0-SNAPSHOT/my-work/default/messages java.io.IOException: No space left on device LOG_WRITE: IOException on write, log is likely incomplete. Environment is invalid and must be closed.
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1648)
        at com.sleepycat.je.log.LogBufferPool.writeBufferToFile(LogBufferPool.java:411)
        at com.sleepycat.je.log.LogBufferPool.writeDirty(LogBufferPool.java:370)
        at com.sleepycat.je.log.SyncedLogManager.flushInternal(SyncedLogManager.java:81)
        at com.sleepycat.je.log.LogManager.flush(LogManager.java:1231)
        at com.sleepycat.je.dbi.EnvironmentImpl.flushLog(EnvironmentImpl.java:2060)
        at com.sleepycat.je.Environment.flushLog(Environment.java:1593)
        at org.apache.qpid.server.store.berkeleydb.CoalescingCommiter$CommitThread.processJobs(CoalescingCommiter.java:236)
        ... 1 more
Caused by: java.io.IOException: No space left on device
        at java.io.RandomAccessFile.writeBytes0(Native Method)
        at java.io.RandomAccessFile.writeBytes(RandomAccessFile.java:520)
        at java.io.RandomAccessFile.write(RandomAccessFile.java:550)
        at com.sleepycat.je.log.FileManager.writeToFile(FileManager.java:1753)
        at com.sleepycat.je.log.FileManager.writeLogBuffer(FileManager.java:1633)
        ... 8 more
2014-12-04 09:38:01,232 INFO  [IoReceiver - /169.124.113.161:46753] (channel.close_forced) - [Broker] [con:7(clientid@/169.124.113.161:46753/default)/ch:0] CHN-1003 : Close : 541 - Exception processing command: com.sleepycat.je.LogWriteException: Environment invalid because of previous exception: (JE 5.0.97) /home/a_qpid/destructive-tests/qpid-broker/5.1.0-SNAPSHOT/my-work/default/messages java.io.IOException: No space left on device LOG_WRITE: IOException on write, log is likely incomplete. Environment is invalid and must be closed.
2014-12-04 09:38:01,232 INFO  [IoReceiver - /169.124.113.161:46753] (channel.close) - [Broker] [con:7(clientid@/169.124.113.161:46753/default)/ch:1] CHN-1003 : Close
2014-12-04 09:38:01,233 INFO  [IoReceiver - /169.124.113.161:46753] (connection.close) - [Broker] [con:7(clientid@/169.124.113.161:46753/default)] CON-1002 : Close

{noformat}
 On following messaging operation broker crashes because of unhandled org.apache.qpid.server.store.StoreException
{noformat}
########################################################################
#
# Unhandled Exception org.apache.qpid.server.store.StoreException: Unexpected exception occurred on store operation in Thread IoReceiver - /169.124.113.161:46817
#
# Exiting
#
########################################################################
org.apache.qpid.server.store.StoreException: Unexpected exception occurred on store operation
        at org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.handleDatabaseException(StandardEnvironmentFacade.java:286)
        at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.getNextMessageId(AbstractBDBMessageStore.java:140)
        at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.addMessage(AbstractBDBMessageStore.java:120)
        at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.createStoreMessage(ServerSessionDelegate.java:442)
        at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.messageTransfer(ServerSessionDelegate.java:379)
        at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.messageTransfer(ServerSessionDelegate.java:79)
        at org.apache.qpid.transport.MessageTransfer.dispatch(MessageTransfer.java:101)
        at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:55)
        at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.command(ServerSessionDelegate.java:96)
        at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.command(ServerSessionDelegate.java:79)
        at org.apache.qpid.transport.Method.delegate(Method.java:159)
        at org.apache.qpid.transport.Session.received(Session.java:596)
        at org.apache.qpid.transport.Connection.dispatch(Connection.java:452)
        at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64)
        at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40)
        at org.apache.qpid.transport.MethodDelegate.messageTransfer(MethodDelegate.java:113)
        at org.apache.qpid.transport.MessageTransfer.dispatch(MessageTransfer.java:101)
        at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54)
        at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40)
        at org.apache.qpid.transport.Method.delegate(Method.java:159)
        at org.apache.qpid.transport.Connection.received(Connection.java:405)
        at org.apache.qpid.server.protocol.v0_10.ServerConnection.access$001(ServerConnection.java:64)
        at org.apache.qpid.server.protocol.v0_10.ServerConnection$1.run(ServerConnection.java:316)
        at org.apache.qpid.server.protocol.v0_10.ServerConnection$1.run(ServerConnection.java:312)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:356)
        at org.apache.qpid.server.protocol.v0_10.ServerConnection.received(ServerConnection.java:311)
        at org.apache.qpid.server.protocol.v0_10.ServerConnection.received(ServerConnection.java:64)
        at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:97)
        at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:240)
        at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:131)
        at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
        at org.apache.qpid.transport.network.Assembler.received(Assembler.java:102)
        at org.apache.qpid.transport.network.Assembler.received(Assembler.java:44)
        at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:199)
        at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:114)
        at org.apache.qpid.server.protocol.v0_10.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:179)
        at org.apache.qpid.server.protocol.v0_10.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:43)
        at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:153)
        at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:51)
        at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:161)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
        at org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.openDatabase(StandardEnvironmentFacade.java:295)
        at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.getMessageMetaDataSeqDb(AbstractBDBMessageStore.java:1050)
        at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.getNextMessageId(AbstractBDBMessageStore.java:133)
        ... 40 more

{noformat}

Before that, Broker management is fully operational, i.e. creation of new configured object might even succeed if there will be enough space for the configuration store update. 



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org