activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Christian Posta <christian.po...@gmail.com>
Subject Re: Master not correctly shuting down
Date Wed, 16 Jul 2014 14:23:14 GMT
If there is a blocked thread somehow, your stack trace didn't indicate any
Jetty thread issues.
It did indicate some problems with the mysql connection, however.


On Wed, Jul 16, 2014 at 1:07 AM, Manu <mektoub@gmail.com> wrote:

> Any clue ?
>
>
>
> On Fri, Jul 4, 2014 at 9:52 AM, Manu <mektoub@gmail.com> wrote:
>
> > No that large : 360 messages of average size of less than 1Ko.
> > I did not check the heap at the time of the event. I'll take a look at
> > those next time ...
> >
> > But do you think Jetty can have keep ActiveMq from shutting down ?
> >
> >
> >
> > On Thu, Jul 3, 2014 at 5:58 PM, Christian Posta <
> christian.posta@gmail.com
> > > wrote:
> >
> >> How large were these messages you were trying to browse, and how much
> >> broker memory and JVM heap was available?
> >>
> >>
> >> On Thu, Jul 3, 2014 at 3:07 AM, Manu <mektoub@gmail.com> wrote:
> >>
> >> > 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
> >> >
> >>
> >>
> >>
> >> --
> >> *Christian Posta*
> >> http://www.christianposta.com/blog
> >> http://fabric8.io
> >> twitter: @christianposta
> >>
> >
> >
>



-- 
*Christian Posta*
http://www.christianposta.com/blog
http://fabric8.io
twitter: @christianposta

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message