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: [email protected]
For additional commands, e-mail: [email protected]
