Hi there,
We're facing a strange problem with our master slave configuration.
We are using ActiveMQ 5.8.0 with a master/slave configuration with a mysql
persistent storage.
This morning we were browsing the activemq admin console
(http://<host>:8161/admin/queues.jsp)
and wanted to browse 360 messages that was in the queue.
The request seemed to make mysql a bit overloaded :) and ActiveMq failed to
update the lease (is this the lock ?) and decided to shutdown.
But, it seems jetty was blocking the shutdown with one of its threads.
So both instance remained active (the admin console was still available).
We had to shut down both instances and restart them. Everything restarted
well,
master was available and slave was waiting.
How can we avoid this behavior ?
Thanks in advance !
Manuel
Here is the log extract :
2014-07-03 08:18:14,049 | WARN | locker keepalive resulted in:
java.io.IOException: The last packet successfully received from the server
was 46 618 422 milliseconds ago. The last packet sent successfully to the
server was 46 618 424 milliseconds ago. is longer than the server
configured value of 'wait_timeout'. You should consider either expiring
and/or testing connection validity before use in your application,
increasing the server configured values for client timeouts, or using the
Connector/J connection property 'autoReconnect=true' to avoid this problem.
| org.apache.activemq.broker.LockableServiceSupport | ActiveMQ Cleanup Timer
java.io.IOException: The last packet successfully received from the server
was 46 618 422 milliseconds ago. The last packet sent successfully to the
server was 46 618 424 milliseconds ago. is longer than the server
configured value of 'wait_timeout'. You should consider either expiring
and/or testing connection validity before use in your application,
increasing the server configured values for client timeouts, or using the
Connector/J connection property 'autoReconnect=true' to avoid this problem.
at
org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:45)
at
org.apache.activemq.store.jdbc.LeaseDatabaseLocker.keepAlive(LeaseDatabaseLocker.java:231)
at
org.apache.activemq.broker.LockableServiceSupport.keepLockAlive(LockableServiceSupport.java:115)
at
org.apache.activemq.broker.LockableServiceSupport$1.run(LockableServiceSupport.java:88)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown
Source)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(Unknown
Source)
at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(Unknown
Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(Unknown
Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The
last packet successfully received from the server was 46 618 422
milliseconds ago. The last packet sent successfully to the server was 46
618 424 milliseconds ago. is longer than the server configured value of
'wait_timeout'. You should consider either expiring and/or testing
connection validity before use in your application, increasing the server
configured values for client timeouts, or using the Connector/J connection
property 'autoReconnect=true' to avoid this problem.
at sun.reflect.GeneratedConstructorAccessor8.newInstance(Unknown
Source)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at
com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1121)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3938)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2551)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2809)
at
com.mysql.jdbc.StatementImpl.executeSimpleNonQuery(StatementImpl.java:1703)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2447)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375)
at
com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
at
org.apache.activemq.store.jdbc.LeaseDatabaseLocker.keepAlive(LeaseDatabaseLocker.java:228)
... 11 more
Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(Unknown Source)
at java.net.SocketOutputStream.write(Unknown Source)
at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.io.BufferedOutputStream.flush(Unknown Source)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3919)
... 22 more
2014-07-03 08:18:19,050 | INFO | amq01, no longer able to keep the
exclusive lock so giving up being a master |
org.apache.activemq.broker.LockableServiceSupport | ActiveMQ Cleanup Timer
2014-07-03 08:18:19,051 | INFO | Apache ActiveMQ 5.8.0 (amq01,
ID:esb01-46942-1403704389061-0:1) is shutting down |
org.apache.activemq.broker.BrokerService | ActiveMQ Cleanup Timer
2014-07-03 08:18:21,144 | INFO | Connector openwire Stopped |
org.apache.activemq.broker.TransportConnector | ActiveMQ Cleanup Timer
2014-07-03 08:18:29,998 | INFO |
PListStore:[/opt/activemq/data/amq01/tmp_storage] stopped |
org.apache.activemq.store.kahadb.plist.PListStoreImpl | ActiveMQ Cleanup
Timer
2014-07-03 08:18:30,005 | INFO | Apache ActiveMQ 5.8.0 (amq01,
ID:esb01-46942-1403704389061-0:1) uptime 7 days 16 hours |
org.apache.activemq.broker.BrokerService | ActiveMQ Cleanup Timer
2014-07-03 08:18:30,005 | INFO | Apache ActiveMQ 5.8.0 (amq01,
ID:esb01-46942-1403704389061-0:1) is shutdown |
org.apache.activemq.broker.BrokerService | ActiveMQ Cleanup Timer
2014-07-03 08:18:30,005 | INFO | Closing
org.apache.activemq.xbean.XBeanBrokerFactory$1@6f878144: startup date [Wed
Jun 25 15:53:05 CEST 2014]; root of context hierarchy |
org.apache.activemq.xbean.XBeanBrokerFactory$1 | ActiveMQ Cleanup Timer
2014-07-03 08:18:30,021 | INFO | Destroying Spring FrameworkServlet
'dispatcher' | /admin | ActiveMQ Cleanup Timer
2014-07-03 08:18:30,124 | WARN | 1 threads could not be stopped |
org.eclipse.jetty.util.thread.QueuedThreadPool | ActiveMQ Cleanup Timer
