[
https://issues.apache.org/activemq/browse/AMQ-1720?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=42751#action_42751
]
Hiram Chirino commented on AMQ-1720:
------------------------------------
Pasting in a log showing a broker who's DB connection has died and the broker
tired to shutdown the but the process has not exited.
{code}
ACTIVEMQ_HOME: C:\iona\apache-activemq-5.0.0.11-fuse\bin\..
ACTIVEMQ_BASE: C:\iona\apache-activemq-5.0.0.11-fuse\bin\..
Loading message broker from: xbean:activemq.xml
INFO BrokerService - Using Persistence Adapter:
JDBCPersistenceAdaptor([EMAIL PROTECTED])
INFO BrokerService - ActiveMQ 5.0.0.11-fuse JMS Message
Broker (localhost) is starting
INFO BrokerService - For help or more information please see:
http://activemq.apache.org/
INFO ManagementContext - JMX consoles can connect to
service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
INFO JDBCPersistenceAdapter - Database driver recognized:
[mysql-ab_jdbc_driver]
INFO DefaultDatabaseLocker - Attempting to acquire the exclusive lock
to become the Master broker
INFO DefaultDatabaseLocker - Becoming the master on dataSource:
[EMAIL PROTECTED]
INFO TransportServerThreadSupport - Listening for connections at:
tcp://jluod810:61616
INFO TransportConnector - Connector openwire Started
INFO TransportServerThreadSupport - Listening for connections at:
ssl://jluod810:61617
INFO TransportConnector - Connector ssl Started
INFO TransportServerThreadSupport - Listening for connections at:
stomp://jluod810:61613
INFO TransportConnector - Connector stomp Started
INFO TransportServerThreadSupport - Listening for connections at:
xmpp://jluod810:61222
INFO TransportConnector - Connector xmpp Started
INFO NetworkConnector - Network Connector [EMAIL PROTECTED]
Started
INFO BrokerService - ActiveMQ JMS Message Broker (localhost,
ID:jluod810-2851-1210614072672-0:0) started
INFO DiscoveryNetworkConnector - Establishing network connection between
from vm://localhost to tcp://martinmd800:61616
INFO TransportConnector - Connector vm://localhost Started
INFO DemandForwardingBridge - Network connection between
vm://localhost#2 and tcp://martinmd800/10.5.1.158:61616(localhost) has been
established.
INFO log - Logging to
org.slf4j.impl.JCLLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
INFO log - jetty-6.1.0.1-fuse
INFO WebConsoleStarter - ActiveMQ WebConsole initialized.
INFO /admin - Initializing Spring FrameworkServlet
'dispatcher'
INFO log - ActiveMQ Console at
http://0.0.0.0:8161/admin
INFO log - ActiveMQ Web Demos at
http://0.0.0.0:8161/demo
INFO log - Started [EMAIL PROTECTED]:8161
ERROR DefaultDatabaseLocker - Failed to update database lock:
com.mysql.jdbc.CommunicationsException: Communications link failure due to
underlying exception:
** BEGIN NESTED EXCEPTION **
java.net.SocketException
MESSAGE: Connection reset by peer: socket write error
STACKTRACE:
java.net.SocketException: Connection reset by peer: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2744)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1612)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1723)
at com.mysql.jdbc.Connection.execSQL(Connection.java:3283)
at
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1332)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1604)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1519)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1504)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:94)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:94)
at
org.apache.activemq.store.jdbc.DefaultDatabaseLocker.keepAlive(DefaultDatabaseLocker.java:103)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.databaseLockKeepAlive(JDBCPersistenceAdapter.java:458)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter$3.run(JDBCPersistenceAdapter.java:260)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
** END NESTED EXCEPTION **
Last packet sent to the server was 0 ms ago.
com.mysql.jdbc.CommunicationsException: Communications link failure due to
underlying exception:
** BEGIN NESTED EXCEPTION **
java.net.SocketException
MESSAGE: Connection reset by peer: socket write error
STACKTRACE:
java.net.SocketException: Connection reset by peer: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2744)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1612)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1723)
at com.mysql.jdbc.Connection.execSQL(Connection.java:3283)
at
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1332)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1604)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1519)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1504)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:94)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:94)
at
org.apache.activemq.store.jdbc.DefaultDatabaseLocker.keepAlive(DefaultDatabaseLocker.java:103)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.databaseLockKeepAlive(JDBCPersistenceAdapter.java:458)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter$3.run(JDBCPersistenceAdapter.java:260)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
** END NESTED EXCEPTION **
Last packet sent to the server was 0 ms ago.
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2759)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1612)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1723)
at com.mysql.jdbc.Connection.execSQL(Connection.java:3283)
at
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1332)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1604)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1519)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1504)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:94)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:94)
at
org.apache.activemq.store.jdbc.DefaultDatabaseLocker.keepAlive(DefaultDatabaseLocker.java:103)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.databaseLockKeepAlive(JDBCPersistenceAdapter.java:458)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter$3.run(JDBCPersistenceAdapter.java:260)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
INFO JDBCPersistenceAdapter - No longer able to keep the exclusive
lock so giving up being a master
INFO BrokerService - ActiveMQ Message Broker (localhost,
ID:jluod810-2851-1210614072672-0:0) is shutting down
INFO DemandForwardingBridge - localhost bridge to localhost stopped
INFO NetworkConnector - Network Connector [EMAIL PROTECTED]
Stopped
INFO TransportConnector - Connector openwire Stopped
INFO TransportConnector - Connector ssl Stopped
WARN ActiveMQConnection - Async exception with no exception
listener: org.apache.activemq.transport.InactivityIOException: Channel was
inactive for too long: localhost/127.0.0.1:61616
org.apache.activemq.transport.InactivityIOException: Channel was inactive for
too long: localhost/127.0.0.1:61616
at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:225)
at
org.apache.activemq.transport.InactivityMonitor$3.run(InactivityMonitor.java:135)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
INFO TransportConnector - Connector stomp Stopped
INFO TransportConnector - Connector xmpp Stopped
ERROR JDBCPersistenceAdapter - Could not stop service:
JDBCPersistenceAdaptor([EMAIL PROTECTED]). Reason:
com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException:
Connection.close() has already been called. Invalid operation in this state.
com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException:
Connection.close() has already been called. Invalid operation in this state.
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
at com.mysql.jdbc.Connection.getMutex(Connection.java:3755)
at com.mysql.jdbc.Connection.rollback(Connection.java:5251)
at
org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:220)
at
org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:220)
at
org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:288)
at
org.apache.activemq.store.jdbc.DefaultDatabaseLocker.stop(DefaultDatabaseLocker.java:94)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.stop(JDBCPersistenceAdapter.java:204)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:475)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.stopBroker(JDBCPersistenceAdapter.java:474)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.databaseLockKeepAlive(JDBCPersistenceAdapter.java:466)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter$3.run(JDBCPersistenceAdapter.java:260)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
ERROR ManagedTopicRegion - Could not stop service: TopicRegion:
destinations=9, subscriptions=2, memory=0%. Reason:
java.lang.InterruptedException
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at
org.apache.activemq.thread.DedicatedTaskRunner.shutdown(DedicatedTaskRunner.java:72)
at
org.apache.activemq.thread.DedicatedTaskRunner.shutdown(DedicatedTaskRunner.java:83)
at org.apache.activemq.broker.region.Topic.stop(Topic.java:469)
at
org.apache.activemq.broker.region.AbstractRegion.stop(AbstractRegion.java:110)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.region.RegionBroker.doStop(RegionBroker.java:629)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.doStop(ManagedRegionBroker.java:109)
at
org.apache.activemq.broker.region.RegionBroker.stop(RegionBroker.java:187)
at
org.apache.activemq.broker.TransactionBroker.stop(TransactionBroker.java:117)
at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:157)
at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:157)
at
org.apache.activemq.broker.BrokerService$2.stop(BrokerService.java:1513)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:477)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.stopBroker(JDBCPersistenceAdapter.java:474)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.databaseLockKeepAlive(JDBCPersistenceAdapter.java:466)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter$3.run(JDBCPersistenceAdapter.java:260)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
ERROR BrokerService$2 - Could not stop service: [EMAIL
PROTECTED] Reason: java.lang.InterruptedException
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at
org.apache.activemq.thread.DedicatedTaskRunner.shutdown(DedicatedTaskRunner.java:72)
at
org.apache.activemq.thread.DedicatedTaskRunner.shutdown(DedicatedTaskRunner.java:83)
at org.apache.activemq.broker.region.Topic.stop(Topic.java:469)
at
org.apache.activemq.broker.region.AbstractRegion.stop(AbstractRegion.java:110)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.region.RegionBroker.doStop(RegionBroker.java:629)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.doStop(ManagedRegionBroker.java:109)
at
org.apache.activemq.broker.region.RegionBroker.stop(RegionBroker.java:187)
at
org.apache.activemq.broker.TransactionBroker.stop(TransactionBroker.java:117)
at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:157)
at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:157)
at
org.apache.activemq.broker.BrokerService$2.stop(BrokerService.java:1513)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:477)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.stopBroker(JDBCPersistenceAdapter.java:474)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.databaseLockKeepAlive(JDBCPersistenceAdapter.java:466)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter$3.run(JDBCPersistenceAdapter.java:260)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
WARN ActiveMQConnection - Async exception with no exception
listener: org.apache.activemq.transport.TransportDisposedIOException: Peer
(vm://localhost#1) disposed.
org.apache.activemq.transport.TransportDisposedIOException: Peer
(vm://localhost#1) disposed.
at
org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:198)
at
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
at
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
INFO TransportConnector - Connector vm://localhost Stopped
INFO BrokerService - ActiveMQ JMS Message Broker (localhost,
ID:jluod810-2851-1210614072672-0:0) stopped
WARN JDBCPersistenceAdapter - Failed to stop
brokercom.mysql.jdbc.exceptions.MySQLNonTransientConnectionException:
Connection.close() has already been called. Invalid operation in this state.
{code}
> Default Broker config does not shutdown when an internal persistence error
> occurs.
> ----------------------------------------------------------------------------------
>
> Key: AMQ-1720
> URL: https://issues.apache.org/activemq/browse/AMQ-1720
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker
> Affects Versions: 5.1.0
> Reporter: Hiram Chirino
> Assignee: Hiram Chirino
>
> This is due to all the other non-deamon threads running that are not part of
> the broker but in the default config. For example jetty threads and camel
> stuff.
> We should allow the broker server to callback to a listener to that the Main
> that starts it all can System.exit properly when the broker is shutdown..
> that should cause the non-daemon stuff to exit too.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
