activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Hiram Chirino (JIRA)" <j...@apache.org>
Subject [jira] Commented: (AMQ-1720) Default Broker config does not shutdown when an internal persistence error occurs.
Date Mon, 12 May 2008 18:04:43 GMT

    [ 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(org.apache.commons.dbcp.BasicDataSource@c272bc)
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: org.apache.commons.dbcp.BasicDataSource@c272bc
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 org.apache.activemq.transport.discovery.multicast.MulticastDiscoveryAgent@25491d
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 SelectChannelConnector@0.0.0.0: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 org.apache.activemq.transport.discovery.multicast.MulticastDiscoveryAgent@25491d
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(org.apache.commons.dbcp.BasicDataSource@c272bc).
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: org.apache.activemq.broker.BrokerService$2@12b9f14.
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.


Mime
View raw message