You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by shyam <Sh...@franklintempleton.com> on 2019/10/29 10:44:34 UTC
Unexpected BDB exception resulting in
org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment
is restarting
Hello,
We are getting this exception resulting in resubmitting the messages again
to the queue. Can you please help how to resolve this?
Extract from QPid logs:
2019-10-29 03:07:23,757 INFO [IO-/10.72.88.6:39273] (q.m.c.close) -
[con:5,011(tis_fix@/10.72.88.6:39273/FIX_VHNG)/ch:2]
[con:5,011(tis_fix@/10.72.88.6:39273/FIX_VHNG)/ch:2] CHN-1003 : Close
2019-10-29 03:07:23,757 INFO [Broker-Config] (q.m.c.close) -
[con:5,009(tis_ctm@/10.72.88.6:39271/FIX_VHNG)] CON-1002 : Close :
Connection closed by external action
2019-10-29 03:07:23,757 INFO [IO-/10.65.106.158:53816] (q.m.c.close) -
[con:5,040(fis@/10.65.106.158:53816/FIX_VHNG)/ch:1]
[con:5,040(fis@/10.65.106.158:53816/FIX_VHNG)/ch:1] CHN-1003 : Close
2019-10-29 03:07:23,756 ERROR [IO-/10.72.88.6:35505]
(o.a.q.s.s.b.BDBConfigurationStore) - Unexpected BDB exception
org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment is
restarting
at
org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.getEnvironment(ReplicatedEnvironmentFacade.java:1269)
at
org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.beginTransaction(ReplicatedEnvironmentFacade.java:319)
at
org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.removeMessage(AbstractBDBMessageStore.java:330)
at
org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$StoredBDBMessage.remove(AbstractBDBMessageStore.java:1192)
at
org.apache.qpid.server.message.AbstractServerMessageImpl.decrementReference(AbstractServerMessageImpl.java:127)
at
org.apache.qpid.server.message.AbstractServerMessageImpl.access$500(AbstractServerMessageImpl.java:40)
at
org.apache.qpid.server.message.AbstractServerMessageImpl$Reference.release(AbstractServerMessageImpl.java:356)
at
org.apache.qpid.server.protocol.v1_0.StandardReceivingLinkEndpoint.receiveDelivery(StandardReceivingLinkEndpoint.java:364)
at
org.apache.qpid.server.protocol.v1_0.AbstractReceivingLinkEndpoint.receiveTransfer(AbstractReceivingLinkEndpoint.java:165)
at
org.apache.qpid.server.protocol.v1_0.Session_1_0.receiveTransfer(Session_1_0.java:614)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receiveTransfer(AMQPConnection_1_0Impl.java:792)
at
org.apache.qpid.server.protocol.v1_0.type.transport.Transfer.invoke(Transfer.java:295)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.received(AMQPConnection_1_0Impl.java:515)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.lambda$receive$0(AMQPConnection_1_0Impl.java:467)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receive(AMQPConnection_1_0Impl.java:461)
at
org.apache.qpid.server.protocol.v1_0.framing.FrameHandler.parse(FrameHandler.java:224)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.onReceive(AMQPConnection_1_0Impl.java:1312)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.lambda$received$2(AbstractAMQPConnection.java:574)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.received(AbstractAMQPConnection.java:569)
at
org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:135)
at
org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:611)
at
org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
at
org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:496)
at
org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:270)
at
org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:134)
at
org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:575)
at
org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:366)
at
org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
at
org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:533)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
at java.lang.Thread.run(Thread.java:748)
2019-10-29 03:07:23,757 INFO [VirtualHostNode-RCO_1_FIX_VHN-Config]
(q.m.s.close) - [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1]
[sub:37(vh(/FIX_VHNG)/qu(QP.FTT.TIS.FIX.EXEC_RESP_5)] SUB-1002 : Close
2019-10-29 03:07:23,757 WARN [IO-/10.72.88.6:35505]
(o.a.q.s.p.v.f.FrameHandler) - Unexpected exception handling frame
org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment is
restarting
at
org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.getEnvironment(ReplicatedEnvironmentFacade.java:1269)
at
org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.beginTransaction(ReplicatedEnvironmentFacade.java:319)
at
org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.removeMessage(AbstractBDBMessageStore.java:330)
at
org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$StoredBDBMessage.remove(AbstractBDBMessageStore.java:1192)
at
org.apache.qpid.server.message.AbstractServerMessageImpl.decrementReference(AbstractServerMessageImpl.java:127)
at
org.apache.qpid.server.message.AbstractServerMessageImpl.access$500(AbstractServerMessageImpl.java:40)
at
org.apache.qpid.server.message.AbstractServerMessageImpl$Reference.release(AbstractServerMessageImpl.java:356)
at
org.apache.qpid.server.protocol.v1_0.StandardReceivingLinkEndpoint.receiveDelivery(StandardReceivingLinkEndpoint.java:364)
at
org.apache.qpid.server.protocol.v1_0.AbstractReceivingLinkEndpoint.receiveTransfer(AbstractReceivingLinkEndpoint.java:165)
at
org.apache.qpid.server.protocol.v1_0.Session_1_0.receiveTransfer(Session_1_0.java:614)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receiveTransfer(AMQPConnection_1_0Impl.java:792)
at
org.apache.qpid.server.protocol.v1_0.type.transport.Transfer.invoke(Transfer.java:295)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.received(AMQPConnection_1_0Impl.java:515)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.lambda$receive$0(AMQPConnection_1_0Impl.java:467)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receive(AMQPConnection_1_0Impl.java:461)
at
org.apache.qpid.server.protocol.v1_0.framing.FrameHandler.parse(FrameHandler.java:224)
at
org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.onReceive(AMQPConnection_1_0Impl.java:1312)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.lambda$received$2(AbstractAMQPConnection.java:574)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.received(AbstractAMQPConnection.java:569)
at
org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:135)
at
org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:611)
at
org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
at
org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:496)
at
org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:270)
at
org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:134)
at
org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:575)
at
org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:366)
at
org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
at
org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:533)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
at java.lang.Thread.run(Thread.java:748)
2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39277] (q.m.c.close) -
[con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1]
[con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1] CHN-1003 : Close
2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39277] (q.m.c.close) -
[con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:2]
[con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:2] CHN-1003 : Close
2019-10-29 03:07:23,758 INFO [VirtualHostNode-RCO_1_FIX_VHN-Config]
(q.m.s.close) - [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2]
[sub:47(vh(/FIX_VHNG)/qu(QP.FTT.TIS.FIX.IOI_ADV)] SUB-1002 : Close
2019-10-29 03:07:23,758 INFO [IO-/10.65.106.158:53820] (q.m.c.close) -
[con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:0]
[con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:0] CHN-1003 : Close
2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39284] (q.m.c.close) -
[con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2]
[con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2] CHN-1003 : Close
2019-10-29 03:07:23,758 INFO [IO-/10.65.106.158:53820] (q.m.c.close) -
[con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:1]
[con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:1] CHN-1003 : Close
--
Sent from: http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
Re: Unexpected BDB exception resulting in org.apache.qpid.server.util.ConnectionScopedRuntimeException:
Environment is restarting
Posted by Igor Natanzon <ig...@gmail.com>.
Hi Alex, after few weeks of research we have determined that what we are
experiencing is what's called VM Stunning (
https://cormachogan.com/2015/04/28/when-and-why-do-we-stun-a-virtual-machine/ )
during a VMWare backup operation (our cluster majority is installed on two
VM's).
The stun last long enough to trigger failover from the master (which isn't
stunned at the time, but is in minority). It occurs on and off for duration
of maybe 15 minutes until VM snapshot is completed. Eventually the cluster
becomes unstable and appears to be unable to fully synchronize itself from
that point on. While continuing to operate, it reports clock skew errors,
and other 'unknown/unhandled' bdb exceptions, until at least one of the
nodes eventually crashes a few hours later.
Needless to say, we had the backup operation stopped, and are looking at
various workarounds, such as moving one of the backups to another
timeframe, so that only one of 3 nodes is stunned at any given time,
preserving cluster majority, and of course trying to see if we can prevent
the stun altogether. A this point we will assume that bdb just doesn't
handle VM stun, and will try work on avoiding it.
Thanks!
On Sun, Nov 3, 2019 at 6:45 PM Oleksandr Rudyy <or...@gmail.com> wrote:
> Hi,
>
> The provided exception stack trace indicate that on receiving of incoming
> message by the broker, the BDB JE environment was in process of restarting.
> As result, a "ConnectionScopedRuntimeException: Environment is restarting"
> was thrown to indicate that message cannot be received.
> The exception caused a connection close.
>
> The environment restart could be caused by a loss of majority of the nodes
> on performing previous messaging operation.
> The corresponding log record should be reported into the broker logs.
>
> Do you have any other exception or warning reported into broker logs before
> "ConnectionScopedRuntimeException: Environment is restarting"?
>
> It should give you the reason why BDB JE Environment was restarting.
>
> Kind Regards,
> Alex
>
> On Tue, 29 Oct 2019 at 10:44, shyam <
> Shyamsundar.Muralidharan@franklintempleton.com> wrote:
>
> > Hello,
> >
> > We are getting this exception resulting in resubmitting the messages
> again
> > to the queue. Can you please help how to resolve this?
> >
> > Extract from QPid logs:
> > 2019-10-29 03:07:23,757 INFO [IO-/10.72.88.6:39273] (q.m.c.close) -
> > [con:5,011(tis_fix@/10.72.88.6:39273/FIX_VHNG)/ch:2]
> > [con:5,011(tis_fix@/10.72.88.6:39273/FIX_VHNG)/ch:2] CHN-1003 : Close
> > 2019-10-29 03:07:23,757 INFO [Broker-Config] (q.m.c.close) -
> > [con:5,009(tis_ctm@/10.72.88.6:39271/FIX_VHNG)] CON-1002 : Close :
> > Connection closed by external action
> > 2019-10-29 03:07:23,757 INFO [IO-/10.65.106.158:53816] (q.m.c.close) -
> > [con:5,040(fis@/10.65.106.158:53816/FIX_VHNG)/ch:1]
> > [con:5,040(fis@/10.65.106.158:53816/FIX_VHNG)/ch:1] CHN-1003 : Close
> > 2019-10-29 03:07:23,756 ERROR [IO-/10.72.88.6:35505]
> > (o.a.q.s.s.b.BDBConfigurationStore) - Unexpected BDB exception
> > org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment
> > is
> > restarting
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.getEnvironment(ReplicatedEnvironmentFacade.java:1269)
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.beginTransaction(ReplicatedEnvironmentFacade.java:319)
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.removeMessage(AbstractBDBMessageStore.java:330)
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$StoredBDBMessage.remove(AbstractBDBMessageStore.java:1192)
> > at
> >
> >
> org.apache.qpid.server.message.AbstractServerMessageImpl.decrementReference(AbstractServerMessageImpl.java:127)
> > at
> >
> >
> org.apache.qpid.server.message.AbstractServerMessageImpl.access$500(AbstractServerMessageImpl.java:40)
> > at
> >
> >
> org.apache.qpid.server.message.AbstractServerMessageImpl$Reference.release(AbstractServerMessageImpl.java:356)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.StandardReceivingLinkEndpoint.receiveDelivery(StandardReceivingLinkEndpoint.java:364)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AbstractReceivingLinkEndpoint.receiveTransfer(AbstractReceivingLinkEndpoint.java:165)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.Session_1_0.receiveTransfer(Session_1_0.java:614)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receiveTransfer(AMQPConnection_1_0Impl.java:792)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.type.transport.Transfer.invoke(Transfer.java:295)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.received(AMQPConnection_1_0Impl.java:515)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.lambda$receive$0(AMQPConnection_1_0Impl.java:467)
> > at java.security.AccessController.doPrivileged(Native Method)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receive(AMQPConnection_1_0Impl.java:461)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.framing.FrameHandler.parse(FrameHandler.java:224)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.onReceive(AMQPConnection_1_0Impl.java:1312)
> > at
> >
> >
> org.apache.qpid.server.transport.AbstractAMQPConnection.lambda$received$2(AbstractAMQPConnection.java:574)
> > at java.security.AccessController.doPrivileged(Native Method)
> > at
> >
> >
> org.apache.qpid.server.transport.AbstractAMQPConnection.received(AbstractAMQPConnection.java:569)
> > at
> >
> >
> org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:135)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:611)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:496)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:270)
> > at
> >
> >
> org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:134)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:575)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:366)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:533)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> > at
> >
> >
> org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
> > at java.lang.Thread.run(Thread.java:748)
> > 2019-10-29 03:07:23,757 INFO [VirtualHostNode-RCO_1_FIX_VHN-Config]
> > (q.m.s.close) - [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1]
> > [sub:37(vh(/FIX_VHNG)/qu(QP.FTT.TIS.FIX.EXEC_RESP_5)] SUB-1002 : Close
> > 2019-10-29 03:07:23,757 WARN [IO-/10.72.88.6:35505]
> > (o.a.q.s.p.v.f.FrameHandler) - Unexpected exception handling frame
> > org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment
> > is
> > restarting
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.getEnvironment(ReplicatedEnvironmentFacade.java:1269)
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.beginTransaction(ReplicatedEnvironmentFacade.java:319)
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.removeMessage(AbstractBDBMessageStore.java:330)
> > at
> >
> >
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$StoredBDBMessage.remove(AbstractBDBMessageStore.java:1192)
> > at
> >
> >
> org.apache.qpid.server.message.AbstractServerMessageImpl.decrementReference(AbstractServerMessageImpl.java:127)
> > at
> >
> >
> org.apache.qpid.server.message.AbstractServerMessageImpl.access$500(AbstractServerMessageImpl.java:40)
> > at
> >
> >
> org.apache.qpid.server.message.AbstractServerMessageImpl$Reference.release(AbstractServerMessageImpl.java:356)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.StandardReceivingLinkEndpoint.receiveDelivery(StandardReceivingLinkEndpoint.java:364)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AbstractReceivingLinkEndpoint.receiveTransfer(AbstractReceivingLinkEndpoint.java:165)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.Session_1_0.receiveTransfer(Session_1_0.java:614)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receiveTransfer(AMQPConnection_1_0Impl.java:792)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.type.transport.Transfer.invoke(Transfer.java:295)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.received(AMQPConnection_1_0Impl.java:515)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.lambda$receive$0(AMQPConnection_1_0Impl.java:467)
> > at java.security.AccessController.doPrivileged(Native Method)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receive(AMQPConnection_1_0Impl.java:461)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.framing.FrameHandler.parse(FrameHandler.java:224)
> > at
> >
> >
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.onReceive(AMQPConnection_1_0Impl.java:1312)
> > at
> >
> >
> org.apache.qpid.server.transport.AbstractAMQPConnection.lambda$received$2(AbstractAMQPConnection.java:574)
> > at java.security.AccessController.doPrivileged(Native Method)
> > at
> >
> >
> org.apache.qpid.server.transport.AbstractAMQPConnection.received(AbstractAMQPConnection.java:569)
> > at
> >
> >
> org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:135)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:611)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:496)
> > at
> >
> >
> org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:270)
> > at
> >
> >
> org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:134)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:575)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:366)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
> > at
> >
> >
> org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:533)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> > at
> >
> >
> org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
> > at java.lang.Thread.run(Thread.java:748)
> > 2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39277] (q.m.c.close) -
> > [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1]
> > [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1] CHN-1003 : Close
> > 2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39277] (q.m.c.close) -
> > [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:2]
> > [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:2] CHN-1003 : Close
> > 2019-10-29 03:07:23,758 INFO [VirtualHostNode-RCO_1_FIX_VHN-Config]
> > (q.m.s.close) - [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2]
> > [sub:47(vh(/FIX_VHNG)/qu(QP.FTT.TIS.FIX.IOI_ADV)] SUB-1002 : Close
> > 2019-10-29 03:07:23,758 INFO [IO-/10.65.106.158:53820] (q.m.c.close) -
> > [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:0]
> > [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:0] CHN-1003 : Close
> > 2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39284] (q.m.c.close) -
> > [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2]
> > [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2] CHN-1003 : Close
> > 2019-10-29 03:07:23,758 INFO [IO-/10.65.106.158:53820] (q.m.c.close) -
> > [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:1]
> > [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:1] CHN-1003 : Close
> >
> >
> >
> >
> > --
> > Sent from:
> > http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> > For additional commands, e-mail: users-help@qpid.apache.org
> >
> >
>
Re: Unexpected BDB exception resulting in org.apache.qpid.server.util.ConnectionScopedRuntimeException:
Environment is restarting
Posted by Oleksandr Rudyy <or...@gmail.com>.
Hi,
The provided exception stack trace indicate that on receiving of incoming
message by the broker, the BDB JE environment was in process of restarting.
As result, a "ConnectionScopedRuntimeException: Environment is restarting"
was thrown to indicate that message cannot be received.
The exception caused a connection close.
The environment restart could be caused by a loss of majority of the nodes
on performing previous messaging operation.
The corresponding log record should be reported into the broker logs.
Do you have any other exception or warning reported into broker logs before
"ConnectionScopedRuntimeException: Environment is restarting"?
It should give you the reason why BDB JE Environment was restarting.
Kind Regards,
Alex
On Tue, 29 Oct 2019 at 10:44, shyam <
Shyamsundar.Muralidharan@franklintempleton.com> wrote:
> Hello,
>
> We are getting this exception resulting in resubmitting the messages again
> to the queue. Can you please help how to resolve this?
>
> Extract from QPid logs:
> 2019-10-29 03:07:23,757 INFO [IO-/10.72.88.6:39273] (q.m.c.close) -
> [con:5,011(tis_fix@/10.72.88.6:39273/FIX_VHNG)/ch:2]
> [con:5,011(tis_fix@/10.72.88.6:39273/FIX_VHNG)/ch:2] CHN-1003 : Close
> 2019-10-29 03:07:23,757 INFO [Broker-Config] (q.m.c.close) -
> [con:5,009(tis_ctm@/10.72.88.6:39271/FIX_VHNG)] CON-1002 : Close :
> Connection closed by external action
> 2019-10-29 03:07:23,757 INFO [IO-/10.65.106.158:53816] (q.m.c.close) -
> [con:5,040(fis@/10.65.106.158:53816/FIX_VHNG)/ch:1]
> [con:5,040(fis@/10.65.106.158:53816/FIX_VHNG)/ch:1] CHN-1003 : Close
> 2019-10-29 03:07:23,756 ERROR [IO-/10.72.88.6:35505]
> (o.a.q.s.s.b.BDBConfigurationStore) - Unexpected BDB exception
> org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment
> is
> restarting
> at
>
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.getEnvironment(ReplicatedEnvironmentFacade.java:1269)
> at
>
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.beginTransaction(ReplicatedEnvironmentFacade.java:319)
> at
>
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.removeMessage(AbstractBDBMessageStore.java:330)
> at
>
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$StoredBDBMessage.remove(AbstractBDBMessageStore.java:1192)
> at
>
> org.apache.qpid.server.message.AbstractServerMessageImpl.decrementReference(AbstractServerMessageImpl.java:127)
> at
>
> org.apache.qpid.server.message.AbstractServerMessageImpl.access$500(AbstractServerMessageImpl.java:40)
> at
>
> org.apache.qpid.server.message.AbstractServerMessageImpl$Reference.release(AbstractServerMessageImpl.java:356)
> at
>
> org.apache.qpid.server.protocol.v1_0.StandardReceivingLinkEndpoint.receiveDelivery(StandardReceivingLinkEndpoint.java:364)
> at
>
> org.apache.qpid.server.protocol.v1_0.AbstractReceivingLinkEndpoint.receiveTransfer(AbstractReceivingLinkEndpoint.java:165)
> at
>
> org.apache.qpid.server.protocol.v1_0.Session_1_0.receiveTransfer(Session_1_0.java:614)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receiveTransfer(AMQPConnection_1_0Impl.java:792)
> at
>
> org.apache.qpid.server.protocol.v1_0.type.transport.Transfer.invoke(Transfer.java:295)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.received(AMQPConnection_1_0Impl.java:515)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.lambda$receive$0(AMQPConnection_1_0Impl.java:467)
> at java.security.AccessController.doPrivileged(Native Method)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receive(AMQPConnection_1_0Impl.java:461)
> at
>
> org.apache.qpid.server.protocol.v1_0.framing.FrameHandler.parse(FrameHandler.java:224)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.onReceive(AMQPConnection_1_0Impl.java:1312)
> at
>
> org.apache.qpid.server.transport.AbstractAMQPConnection.lambda$received$2(AbstractAMQPConnection.java:574)
> at java.security.AccessController.doPrivileged(Native Method)
> at
>
> org.apache.qpid.server.transport.AbstractAMQPConnection.received(AbstractAMQPConnection.java:569)
> at
>
> org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:135)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:611)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:496)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:270)
> at
>
> org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:134)
> at
>
> org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:575)
> at
>
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:366)
> at
>
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
> at
>
> org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:533)
> at
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at
>
> org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
> at java.lang.Thread.run(Thread.java:748)
> 2019-10-29 03:07:23,757 INFO [VirtualHostNode-RCO_1_FIX_VHN-Config]
> (q.m.s.close) - [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1]
> [sub:37(vh(/FIX_VHNG)/qu(QP.FTT.TIS.FIX.EXEC_RESP_5)] SUB-1002 : Close
> 2019-10-29 03:07:23,757 WARN [IO-/10.72.88.6:35505]
> (o.a.q.s.p.v.f.FrameHandler) - Unexpected exception handling frame
> org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment
> is
> restarting
> at
>
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.getEnvironment(ReplicatedEnvironmentFacade.java:1269)
> at
>
> org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.beginTransaction(ReplicatedEnvironmentFacade.java:319)
> at
>
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.removeMessage(AbstractBDBMessageStore.java:330)
> at
>
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$StoredBDBMessage.remove(AbstractBDBMessageStore.java:1192)
> at
>
> org.apache.qpid.server.message.AbstractServerMessageImpl.decrementReference(AbstractServerMessageImpl.java:127)
> at
>
> org.apache.qpid.server.message.AbstractServerMessageImpl.access$500(AbstractServerMessageImpl.java:40)
> at
>
> org.apache.qpid.server.message.AbstractServerMessageImpl$Reference.release(AbstractServerMessageImpl.java:356)
> at
>
> org.apache.qpid.server.protocol.v1_0.StandardReceivingLinkEndpoint.receiveDelivery(StandardReceivingLinkEndpoint.java:364)
> at
>
> org.apache.qpid.server.protocol.v1_0.AbstractReceivingLinkEndpoint.receiveTransfer(AbstractReceivingLinkEndpoint.java:165)
> at
>
> org.apache.qpid.server.protocol.v1_0.Session_1_0.receiveTransfer(Session_1_0.java:614)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receiveTransfer(AMQPConnection_1_0Impl.java:792)
> at
>
> org.apache.qpid.server.protocol.v1_0.type.transport.Transfer.invoke(Transfer.java:295)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.received(AMQPConnection_1_0Impl.java:515)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.lambda$receive$0(AMQPConnection_1_0Impl.java:467)
> at java.security.AccessController.doPrivileged(Native Method)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.receive(AMQPConnection_1_0Impl.java:461)
> at
>
> org.apache.qpid.server.protocol.v1_0.framing.FrameHandler.parse(FrameHandler.java:224)
> at
>
> org.apache.qpid.server.protocol.v1_0.AMQPConnection_1_0Impl.onReceive(AMQPConnection_1_0Impl.java:1312)
> at
>
> org.apache.qpid.server.transport.AbstractAMQPConnection.lambda$received$2(AbstractAMQPConnection.java:574)
> at java.security.AccessController.doPrivileged(Native Method)
> at
>
> org.apache.qpid.server.transport.AbstractAMQPConnection.received(AbstractAMQPConnection.java:569)
> at
>
> org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:135)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:611)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:496)
> at
>
> org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:270)
> at
>
> org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:134)
> at
>
> org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:575)
> at
>
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:366)
> at
>
> org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
> at
>
> org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:533)
> at
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at
>
> org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
> at java.lang.Thread.run(Thread.java:748)
> 2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39277] (q.m.c.close) -
> [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1]
> [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:1] CHN-1003 : Close
> 2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39277] (q.m.c.close) -
> [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:2]
> [con:5,015(tis_fix@/10.72.88.6:39277/FIX_VHNG)/ch:2] CHN-1003 : Close
> 2019-10-29 03:07:23,758 INFO [VirtualHostNode-RCO_1_FIX_VHN-Config]
> (q.m.s.close) - [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2]
> [sub:47(vh(/FIX_VHNG)/qu(QP.FTT.TIS.FIX.IOI_ADV)] SUB-1002 : Close
> 2019-10-29 03:07:23,758 INFO [IO-/10.65.106.158:53820] (q.m.c.close) -
> [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:0]
> [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:0] CHN-1003 : Close
> 2019-10-29 03:07:23,758 INFO [IO-/10.72.88.6:39284] (q.m.c.close) -
> [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2]
> [con:5,022(tis_fix@/10.72.88.6:39284/FIX_VHNG)/ch:2] CHN-1003 : Close
> 2019-10-29 03:07:23,758 INFO [IO-/10.65.106.158:53820] (q.m.c.close) -
> [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:1]
> [con:5,042(fis@/10.65.106.158:53820/FIX_VHNG)/ch:1] CHN-1003 : Close
>
>
>
>
> --
> Sent from:
> http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>
>