You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by fenbers <Ma...@noaa.gov> on 2013/04/30 18:02:30 UTC
Is AMQ-4118 really fixed?? Doubt it...
Regarding https://issues.apache.org/jira/browse/AMQ-4118, the report says
this issue is fixed in 5.8.0, but I am running 5.8.0 and still have exactly
the same 3 stack traces as listed in the URL above. Moreover, I have
numbered .log files (journal files) that never get cleaned up automatically.
These average about every 7th file or so that does not get removed. TRACE
log entries indicate that two of the topics (of 5 total topics) are the
culprits, but I cannot figure out why. I have been trying to resolve this
for a year now!! I've traced my code for the 3 topics that don't leave
complaints vs the 2 topics that do leave complaints and I can't see any
functional differences in my code.
I'm at a loss! I'm currently running 5.8.0...
Mark
--
View this message in context: http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Is AMQ-4118 really fixed?? Doubt it...
Posted by fenbers <Ma...@noaa.gov>.
The following log is from April 30 in which the errors shown lead to a
self-shutdown of ActiveMQ. The log starts prior to when any problems were
noted and ends around the beginning of its shutdown process. A thousand
more lines pertaining to its shutdown process are omitted from this post.
Of concern to me are two things:
1) A few lines from the top at 11:01:00,680 containing GIFTS.fromSnooper
and GIFTS.icon show the numbers of journal files that never get cleaned up.
This list of numbers (and undeleted .log files) grows over time. I have 5
topics running through ActiveMQ, but only these two does ActiveMQ ever show
in the log in this way, but I cannot determine what I am doing
wrong/differently in the configuration of these two topics.
2) At 11:01:21,174 an error occurs and a stacktrace is dumped. The error
given is exactly like the ones supposedly fixed by AMQ-4118. I will add
another log snippet showing one of the other errors in a subsequent post.
I have no idea if 1) and 2) are related in any way.
Mark
2013-04-30 11:01:00,657 | DEBUG | Checkpoint started.
2013-04-30 11:01:00,680 | TRACE | Last update: 32:20335126, full gc
candidates set: [3, 5, 10, 26, 27, 28, 29, 30, 31, 32]
2013-04-30 11:01:00,680 | TRACE | gc candidates after tx range:[null, null],
[3, 5, 10, 26, 27, 28, 29, 30, 31]
2013-04-30 11:01:00,680 | TRACE | gc candidates after
dest:1:GIFTS.fromSnooper, [3, 5, 10, 26, 27, 29]
2013-04-30 11:01:00,680 | TRACE | gc candidates after dest:1:GIFTS.icon, [3,
5, 10, 26, 27, 29]
2013-04-30 11:01:00,680 | TRACE | gc candidates after dest:0:ActiveMQ.DLQ,
[]
2013-04-30 11:01:00,680 | TRACE | gc candidates: []
2013-04-30 11:01:00,680 | DEBUG | Checkpoint done.
2013-04-30 11:01:00,917 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:00,917 | DEBUG | WriteChecker 10001 ms elapsed since last
write check.
2013-04-30 11:01:00,917 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44136]
2013-04-30 11:01:00,917 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44135]
2013-04-30 11:01:00,941 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:00,941 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:01,367 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:01,367 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:01,416 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:01,855 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:01,855 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52839]
2013-04-30 11:01:02,178 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:02,223 | DEBUG | 30003 ms elapsed since last read check.
2013-04-30 11:01:02,225 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:02,225 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:02,225 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52840]
2013-04-30 11:01:02,225 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52841]
2013-04-30 11:01:02,446 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:02,446 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34830]
2013-04-30 11:01:02,579 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:02,579 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:03,168 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:03,168 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46369]
2013-04-30 11:01:03,358 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:03,372 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:03,459 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:03,459 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34831]
2013-04-30 11:01:04,279 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:04,397 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:04,527 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:04,527 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44714]
2013-04-30 11:01:04,646 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:05,345 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:05,345 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44138]
2013-04-30 11:01:05,506 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:05,506 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:05,506 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44715]
2013-04-30 11:01:05,665 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:05,701 | DEBUG | Checkpoint started.
2013-04-30 11:01:05,703 | DEBUG | Checkpoint done.
2013-04-30 11:01:06,142 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:06,685 | DEBUG | 30003 ms elapsed since last read check.
2013-04-30 11:01:07,425 | DEBUG | 30001 ms elapsed since last read check.
2013-04-30 11:01:07,507 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:07,511 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:07,511 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:07,511 | DEBUG | tcp:///165.92.64.13:53967@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:07,511 | DEBUG | tcp:///165.92.64.13:53967@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:07,517 | DEBUG | Setting up new connection id:
ID:lx4-tir-48137-1367334067393-1:1, address: tcp://165.92.64.13:53967, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:lx4-tir-48137-1367334067393-1:1, clientId =
ID:lx4-tir-48137-1367334067393-0:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-04-30 11:01:07,525 | DEBUG | localhost adding consumer:
ID:lx4-tir-48137-1367334067393-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:07,525 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:lx4-tir-48137-1367334067393-1:1:-1:1
2013-04-30 11:01:07,561 | DEBUG | commit:
TX:ID:lx4-tir-48137-1367334067393-1:1:1 syncCount: 2
2013-04-30 11:01:07,562 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.toSnooper,endpoint=Producer,clientId=ID_lx4-tir-48137-1367334067393-0_1,producerId=ID_lx4-tir-48137-1367334067393-1_1_1_1
2013-04-30 11:01:07,563 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_lx4-tir-48137-1367334067393-0_1,consumerId=ID_lx4-tir-48137-1367334067393-1_1_-1_1
2013-04-30 11:01:07,563 | DEBUG | localhost removing consumer:
ID:lx4-tir-48137-1367334067393-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:07,563 | DEBUG | remove connection id:
ID:lx4-tir-48137-1367334067393-1:1
2013-04-30 11:01:07,563 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_lx4-tir-48137-1367334067393-0_1
2013-04-30 11:01:07,563 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.13_53967
2013-04-30 11:01:07,564 | DEBUG | Stopping connection:
tcp://165.92.64.13:53967
2013-04-30 11:01:07,564 | DEBUG | Stopping transport
tcp:///165.92.64.13:53967@61616
2013-04-30 11:01:07,564 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@1f832df
2013-04-30 11:01:07,564 | DEBUG | Closed socket
Socket[addr=/165.92.64.13,port=53967,localport=61616]
2013-04-30 11:01:07,564 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@1f832df
2013-04-30 11:01:07,564 | DEBUG | Stopped transport:
tcp://165.92.64.13:53967
2013-04-30 11:01:07,564 | DEBUG | Connection Stopped:
tcp://165.92.64.13:53967
2013-04-30 11:01:07,588 | DEBUG | WriteChecker 10001 ms elapsed since last
write check.
2013-04-30 11:01:07,588 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34826]
2013-04-30 11:01:07,975 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:07,975 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:08,124 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:08,124 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,124 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34827]
2013-04-30 11:01:08,124 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34828]
2013-04-30 11:01:08,562 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,562 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,562 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,562 | DEBUG | Running
WriteCheck[tcp://165.92.64.17:41351]
2013-04-30 11:01:08,562 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44141]
2013-04-30 11:01:08,562 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,562 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46365]
2013-04-30 11:01:08,562 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52843]
2013-04-30 11:01:08,562 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,562 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52844]
2013-04-30 11:01:08,743 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,743 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:08,743 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46367]
2013-04-30 11:01:08,743 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46366]
2013-04-30 11:01:09,583 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:09,583 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44710]
2013-04-30 11:01:09,750 | DEBUG | queue://ActiveMQ.DLQ expiring messages ..
2013-04-30 11:01:09,750 | DEBUG | ActiveMQ.DLQ toPageIn: 200, Inflight: 0,
pagedInMessages.size 683, enqueueCount: 3563, dequeueCount: 0
2013-04-30 11:01:09,752 | DEBUG | queue://ActiveMQ.DLQ expiring messages
done.
2013-04-30 11:01:09,752 | DEBUG | ActiveMQ.DLQ toPageIn: 200, Inflight: 0,
pagedInMessages.size 683, enqueueCount: 3563, dequeueCount: 0
2013-04-30 11:01:10,099 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:10,099 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:10,100 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:10,100 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44711]
2013-04-30 11:01:10,100 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:45396]
2013-04-30 11:01:10,100 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44712]
2013-04-30 11:01:10,492 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:10,492 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44134]
2013-04-30 11:01:10,723 | DEBUG | Checkpoint started.
2013-04-30 11:01:10,745 | DEBUG | Checkpoint done.
2013-04-30 11:01:10,918 | DEBUG | WriteChecker 10001 ms elapsed since last
write check.
2013-04-30 11:01:10,918 | DEBUG | WriteChecker 10001 ms elapsed since last
write check.
2013-04-30 11:01:10,918 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44136]
2013-04-30 11:01:10,918 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44135]
2013-04-30 11:01:11,311 | DEBUG | 30003 ms elapsed since last read check.
2013-04-30 11:01:11,418 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:11,857 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:11,857 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52839]
2013-04-30 11:01:12,180 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:12,227 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:12,227 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:12,227 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52841]
2013-04-30 11:01:12,227 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52840]
2013-04-30 11:01:12,293 | DEBUG | 30001 ms elapsed since last read check.
2013-04-30 11:01:12,448 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:12,448 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34830]
2013-04-30 11:01:12,581 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:12,582 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:13,170 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:13,170 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46369]
2013-04-30 11:01:13,311 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:13,374 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:13,462 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:14,242 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,245 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,245 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,245 | DEBUG | tcp:///165.92.64.108:55455@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:14,245 | DEBUG | tcp:///165.92.64.108:55455@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:14,253 | DEBUG | Setting up new connection id:
ID:xt9-tir-41885-1367334074117-1:1, address: tcp://165.92.64.108:55455,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:xt9-tir-41885-1367334074117-1:1, clientId =
ID:xt9-tir-41885-1367334074117-0:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-04-30 11:01:14,263 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:14,263 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:xt9-tir-41885-1367334074117-1:1:-1:1
2013-04-30 11:01:14,281 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:14,529 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:14,529 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44714]
2013-04-30 11:01:14,811 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,811 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,811 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,811 | DEBUG | tcp:///165.92.64.108:55456@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:14,811 | DEBUG | tcp:///165.92.64.108:55456@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:14,813 | DEBUG | Setting up new connection id:
ID:xt9-tir-41885-1367334074117-3:1, address: tcp://165.92.64.108:55456,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:xt9-tir-41885-1367334074117-3:1, clientId =
ID:xt9-tir-41885-1367334074117-2:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-04-30 11:01:14,814 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-3:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:14,814 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:xt9-tir-41885-1367334074117-3:1:-1:1
2013-04-30 11:01:14,817 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,818 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,818 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:14,818 | DEBUG | tcp:///165.92.64.108:55457@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:14,818 | DEBUG | tcp:///165.92.64.108:55457@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:14,819 | DEBUG | Setting up new connection id:
ID:xt9-tir-41885-1367334074117-5:1, address: tcp://165.92.64.108:55457,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:xt9-tir-41885-1367334074117-5:1, clientId =
ID:xt9-tir-41885-1367334074117-4:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-04-30 11:01:14,820 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-5:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:14,820 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:xt9-tir-41885-1367334074117-5:1:-1:1
2013-04-30 11:01:15,348 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:15,348 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44138]
2013-04-30 11:01:15,508 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:15,508 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:15,765 | DEBUG | Checkpoint started.
2013-04-30 11:01:15,789 | DEBUG | Checkpoint done.
2013-04-30 11:01:17,590 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:17,590 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34826]
2013-04-30 11:01:18,102 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:18,126 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,126 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,126 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34828]
2013-04-30 11:01:18,126 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:34827]
2013-04-30 11:01:18,416 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:18,480 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:18,480 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:18,564 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,564 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,564 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,564 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,564 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,564 | DEBUG | Running
WriteCheck[tcp://165.92.64.17:41351]
2013-04-30 11:01:18,564 | DEBUG | Running
WriteCheck[tcp://165.92.64.15:52843]
2013-04-30 11:01:18,564 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46365]
2013-04-30 11:01:18,745 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,745 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:18,745 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46367]
2013-04-30 11:01:18,745 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:46366]
2013-04-30 11:01:18,963 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:18,963 | DEBUG | 30002 ms elapsed since last read check.
2013-04-30 11:01:19,083 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:19,084 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:19,084 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:19,084 | DEBUG | tcp:///165.92.64.108:55458@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:19,084 | DEBUG | tcp:///165.92.64.108:55458@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:19,085 | DEBUG | Setting up new connection id:
ID:xt9-tir-41885-1367334074117-7:1, address: tcp://165.92.64.108:55458,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:xt9-tir-41885-1367334074117-7:1, clientId = GIFTS.Status.noel@xt9-tir,
clientIp = null, userName = null, password = *****, brokerPath = null,
brokerMasterConnector = false, manageable = true, clientMaster = true,
faultTolerant = false, failoverReconnect = false}
2013-04-30 11:01:19,086 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-7:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:19,086 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:xt9-tir-41885-1367334074117-7:1:-1:1
2013-04-30 11:01:19,110 | DEBUG | Activating
DurableTopicSubscription-GIFTS.Status.noel@xt9-tir:GIFTS.Status,
id=ID:xt9-tir-41885-1367334074117-7:1:1:1, active=false, destinations=1,
total=829, pending=829, dispatched=5, inflight=0, prefetchExtension=0
2013-04-30 11:01:19,116 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Consumer,clientId=GIFTS.Status.noel@xt9-tir,consumerId=Durable(GIFTS.Status.noel@xt9-tir_GIFTS.Status)
2013-04-30 11:01:19,585 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:20,102 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:20,102 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:20,102 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-04-30 11:01:20,102 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:44712]
2013-04-30 11:01:20,102 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:45396]
2013-04-30 11:01:20,135 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:20,135 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:20,135 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:20,135 | DEBUG | tcp:///165.92.64.108:55459@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:20,135 | DEBUG | tcp:///165.92.64.108:55459@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:20,136 | DEBUG | Setting up new connection id:
ID:xt9-tir-41885-1367334074117-9:1, address: tcp://165.92.64.108:55459,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:xt9-tir-41885-1367334074117-9:1, clientId =
LaunchPad.status.noel@xt9-tir, clientIp = null, userName = null, password =
*****, brokerPath = null, brokerMasterConnector = false, manageable = true,
clientMaster = true, faultTolerant = false, failoverReconnect = false}
2013-04-30 11:01:20,137 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-9:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:20,137 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:xt9-tir-41885-1367334074117-9:1:-1:1
2013-04-30 11:01:20,143 | DEBUG | Deactivating keepActive=false,
DurableTopicSubscription-LaunchPad.status.noel@xt9-tir:LaunchPad.status,
id=ID:na_dell7-tir-46032-1367243983617-2443:1:1:1, active=false,
destinations=1, total=829, pending=829, dispatched=5, inflight=0,
prefetchExtension=0
2013-04-30 11:01:20,144 | DEBUG | localhost removing consumer:
ID:na_dell7-tir-46032-1367243983617-2443:1:1:1 for destination:
topic://GIFTS.fromSnooper
2013-04-30 11:01:20,144 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Consumer,clientId=LaunchPad.status.noel@xt9-tir,consumerId=Durable(LaunchPad.status.noel@xt9-tir_LaunchPad.status)
2013-04-30 11:01:20,144 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-9:1:1:1 for destination:
topic://LaunchPad.status
2013-04-30 11:01:20,146 | DEBUG | Error occured while processing sync
command: ConsumerInfo {commandId = 5, responseRequired = true, consumerId =
ID:xt9-tir-41885-1367334074117-9:1:1:1, destination =
topic://LaunchPad.status, prefetchSize = 100, maximumPendingMessageLimit =
0, browser = false, dispatchAsync = true, selector = null, subscriptionName
= LaunchPad.status, noLocal = false, exclusive = false, retroactive = true,
priority = 0, brokerPath = null, optimizedAcknowledge = false, noRangeAcks =
false, additionalPredicate = null}, exception:
java.lang.NullPointerException
java.lang.NullPointerException
2013-04-30 11:01:20,494 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:20,494 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44134]
2013-04-30 11:01:20,809 | DEBUG | Checkpoint started.
2013-04-30 11:01:20,812 | DEBUG | Checkpoint done.
2013-04-30 11:01:20,920 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:20,920 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-04-30 11:01:20,920 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44135]
2013-04-30 11:01:20,920 | DEBUG | Running
WriteCheck[tcp://165.92.64.14:44136]
2013-04-30 11:01:21,153 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:21,153 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:21,153 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-04-30 11:01:21,153 | DEBUG | tcp:///165.92.64.108:55460@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-04-30 11:01:21,153 | DEBUG | tcp:///165.92.64.108:55460@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-04-30 11:01:21,154 | DEBUG | Setting up new connection id:
ID:xt9-tir-41885-1367334074117-11:1, address: tcp://165.92.64.108:55460,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:xt9-tir-41885-1367334074117-11:1, clientId = GIFTS.Stage.noel@xt9-tir,
clientIp = null, userName = null, password = *****, brokerPath = null,
brokerMasterConnector = false, manageable = true, clientMaster = true,
faultTolerant = false, failoverReconnect = false}
2013-04-30 11:01:21,155 | DEBUG | localhost adding consumer:
ID:xt9-tir-41885-1367334074117-11:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,155 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:xt9-tir-41885-1367334074117-11:1:-1:1
2013-04-30 11:01:21,174 | ERROR | KahaDB failed to store to Journal
java.io.EOFException: Chunk stream does not exist, page: 630 is marked free
at
org.apache.activemq.store.kahadb.disk.page.Transaction$2.readPage(Transaction.java:470)
at
org.apache.activemq.store.kahadb.disk.page.Transaction$2.<init>(Transaction.java:447)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.openInputStream(Transaction.java:444)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.load(Transaction.java:420)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.load(Transaction.java:377)
at
org.apache.activemq.store.kahadb.disk.index.BTreeIndex.loadNode(BTreeIndex.java:262)
at
org.apache.activemq.store.kahadb.disk.index.BTreeNode.getChild(BTreeNode.java:225)
at
org.apache.activemq.store.kahadb.disk.index.BTreeNode.remove(BTreeNode.java:283)
at
org.apache.activemq.store.kahadb.disk.index.BTreeIndex.remove(BTreeIndex.java:194)
at
org.apache.activemq.store.kahadb.MessageDatabase.updateIndex(MessageDatabase.java:1374)
at
org.apache.activemq.store.kahadb.MessageDatabase$17.execute(MessageDatabase.java:1115)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:1112)
at
org.apache.activemq.store.kahadb.MessageDatabase$13.visit(MessageDatabase.java:1040)
at
org.apache.activemq.store.kahadb.data.KahaSubscriptionCommand.visit(KahaSubscriptionCommand.java:187)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:1007)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:918)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:900)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.deleteSubscription(KahaDBStore.java:739)
at
org.apache.activemq.store.ProxyTopicMessageStore.deleteSubscription(ProxyTopicMessageStore.java:103)
at
org.apache.activemq.broker.region.Topic.deleteSubscription(Topic.java:197)
at
org.apache.activemq.broker.region.TopicRegion.addConsumer(TopicRegion.java:134)
at
org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:353)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.addConsumer(ManagedRegionBroker.java:229)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:91)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:95)
at
org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:619)
at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:332)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
2013-04-30 11:01:21,174 | INFO | Stopping the broker due to exception,
java.io.EOFException: Chunk stream does not exist, page: 630 is marked free
java.io.EOFException: Chunk stream does not exist, page: 630 is marked free
at
org.apache.activemq.store.kahadb.disk.page.Transaction$2.readPage(Transaction.java:470)
at
org.apache.activemq.store.kahadb.disk.page.Transaction$2.<init>(Transaction.java:447)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.openInputStream(Transaction.java:444)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.load(Transaction.java:420)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.load(Transaction.java:377)
at
org.apache.activemq.store.kahadb.disk.index.BTreeIndex.loadNode(BTreeIndex.java:262)
at
org.apache.activemq.store.kahadb.disk.index.BTreeNode.getChild(BTreeNode.java:225)
at
org.apache.activemq.store.kahadb.disk.index.BTreeNode.remove(BTreeNode.java:283)
at
org.apache.activemq.store.kahadb.disk.index.BTreeIndex.remove(BTreeIndex.java:194)
at
org.apache.activemq.store.kahadb.MessageDatabase.updateIndex(MessageDatabase.java:1374)
at
org.apache.activemq.store.kahadb.MessageDatabase$17.execute(MessageDatabase.java:1115)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:1112)
at
org.apache.activemq.store.kahadb.MessageDatabase$13.visit(MessageDatabase.java:1040)
at
org.apache.activemq.store.kahadb.data.KahaSubscriptionCommand.visit(KahaSubscriptionCommand.java:187)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:1007)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:918)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:900)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.deleteSubscription(KahaDBStore.java:739)
at
org.apache.activemq.store.ProxyTopicMessageStore.deleteSubscription(ProxyTopicMessageStore.java:103)
at
org.apache.activemq.broker.region.Topic.deleteSubscription(Topic.java:197)
at
org.apache.activemq.broker.region.TopicRegion.addConsumer(TopicRegion.java:134)
at
org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:353)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.addConsumer(ManagedRegionBroker.java:229)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:91)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:95)
at
org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:619)
at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:332)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
2013-04-30 11:01:21,175 | DEBUG | Error occured while processing sync
command: ConsumerInfo {commandId = 5, responseRequired = true, consumerId =
ID:xt9-tir-41885-1367334074117-11:1:1:1, destination = topic://GIFTS.icon,
prefetchSize = 1000, maximumPendingMessageLimit = 0, browser = false,
dispatchAsync = true, selector = null, subscriptionName = GIFTS.Stage,
noLocal = false, exclusive = false, retroactive = true, priority = 0,
brokerPath = null, optimizedAcknowledge = false, noRangeAcks = false,
additionalPredicate = null}, exception: java.io.EOFException: Chunk stream
does not exist, page: 630 is marked free
java.io.EOFException: Chunk stream does not exist, page: 630 is marked free
at
org.apache.activemq.store.kahadb.disk.page.Transaction$2.readPage(Transaction.java:470)
at
org.apache.activemq.store.kahadb.disk.page.Transaction$2.<init>(Transaction.java:447)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.openInputStream(Transaction.java:444)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.load(Transaction.java:420)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.load(Transaction.java:377)
at
org.apache.activemq.store.kahadb.disk.index.BTreeIndex.loadNode(BTreeIndex.java:262)
at
org.apache.activemq.store.kahadb.disk.index.BTreeNode.getChild(BTreeNode.java:225)
at
org.apache.activemq.store.kahadb.disk.index.BTreeNode.remove(BTreeNode.java:283)
at
org.apache.activemq.store.kahadb.disk.index.BTreeIndex.remove(BTreeIndex.java:194)
at
org.apache.activemq.store.kahadb.MessageDatabase.updateIndex(MessageDatabase.java:1374)
at
org.apache.activemq.store.kahadb.MessageDatabase$17.execute(MessageDatabase.java:1115)
at
org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:1112)
at
org.apache.activemq.store.kahadb.MessageDatabase$13.visit(MessageDatabase.java:1040)
at
org.apache.activemq.store.kahadb.data.KahaSubscriptionCommand.visit(KahaSubscriptionCommand.java:187)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:1007)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:918)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:900)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.deleteSubscription(KahaDBStore.java:739)
at
org.apache.activemq.store.ProxyTopicMessageStore.deleteSubscription(ProxyTopicMessageStore.java:103)
at
org.apache.activemq.broker.region.Topic.deleteSubscription(Topic.java:197)
at
org.apache.activemq.broker.region.TopicRegion.addConsumer(TopicRegion.java:134)
at
org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:353)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.addConsumer(ManagedRegionBroker.java:229)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:91)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:89)
at
org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:95)
at
org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:619)
at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:332)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
2013-04-30 11:01:21,176 | INFO | Apache ActiveMQ 5.8.0 (localhost,
ID:rp1-tir-41989-1367243906898-0:1) is shutting down
2013-04-30 11:01:21,178 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-39819-1367243908997-0_1
2013-04-30 11:01:21,178 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_57752
2013-04-30 11:01:21,178 | DEBUG | Stopping connection:
tcp://165.92.64.75:57752
2013-04-30 11:01:21,178 | DEBUG | Stopping transport
tcp:///165.92.64.75:57752@61616
2013-04-30 11:01:21,178 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@aa34f5
2013-04-30 11:01:21,178 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=57752,localport=61616]
2013-04-30 11:01:21,178 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@aa34f5
2013-04-30 11:01:21,178 | DEBUG | Stopped transport:
tcp://165.92.64.75:57752
2013-04-30 11:01:21,178 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.75:57752
2013-04-30 11:01:21,178 | DEBUG | remove connection id:
ID:rp1-tir-39819-1367243908997-1:1
2013-04-30 11:01:21,178 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-39819-1367243908997-0_1,consumerId=ID_rp1-tir-39819-1367243908997-1_1_-1_1
2013-04-30 11:01:21,179 | DEBUG | localhost removing consumer:
ID:rp1-tir-39819-1367243908997-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,179 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-39819-1367243908997-0_1,producerId=ID_rp1-tir-39819-1367243908997-1_1_1_1
2013-04-30 11:01:21,179 | DEBUG | Connection Stopped:
tcp://165.92.64.75:57752
2013-04-30 11:01:21,179 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,endpoint=dynamicProducer,clientId=GIFTS.Stage.noel@xt9-tir,producerId=ID_xt9-tir-41885-1367334074117-11_1_1_1
2013-04-30 11:01:21,179 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=Snooper.Status.oper@rp1-tir
2013-04-30 11:01:21,179 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=GIFTS.Stage.noel@xt9-tir,consumerId=ID_xt9-tir-41885-1367334074117-11_1_-1_1
2013-04-30 11:01:21,179 | DEBUG | localhost removing consumer:
ID:xt9-tir-41885-1367334074117-11:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,179 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_57753
2013-04-30 11:01:21,179 | DEBUG | Stopping connection:
tcp://165.92.64.75:57753
2013-04-30 11:01:21,179 | DEBUG | Stopping transport
tcp:///165.92.64.75:57753@61616
2013-04-30 11:01:21,179 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@18bbbf9
2013-04-30 11:01:21,180 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=57753,localport=61616]
2013-04-30 11:01:21,180 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@18bbbf9
2013-04-30 11:01:21,180 | DEBUG | Stopped transport:
tcp://165.92.64.75:57753
2013-04-30 11:01:21,180 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.75:57753
2013-04-30 11:01:21,180 | DEBUG | remove connection id:
ID:rp1-tir-39819-1367243908997-3:1
2013-04-30 11:01:21,180 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.toSnooper,endpoint=Consumer,clientId=Snooper.Status.oper@rp1-tir,consumerId=Durable(Snooper.Status.oper@rp1-tir_Snooper.Status)
2013-04-30 11:01:21,180 | DEBUG | Deactivating keepActive=true,
DurableTopicSubscription-Snooper.Status.oper@rp1-tir:Snooper.Status,
id=ID:rp1-tir-39819-1367243908997-3:1:1:1, active=true, destinations=1,
total=946, pending=0, dispatched=946, inflight=0, prefetchExtension=0
2013-04-30 11:01:21,180 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=Snooper.Status.oper@rp1-tir,consumerId=ID_rp1-tir-39819-1367243908997-3_1_-1_1
2013-04-30 11:01:21,180 | DEBUG | localhost removing consumer:
ID:rp1-tir-39819-1367243908997-3:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,180 | DEBUG | Connection Stopped:
tcp://165.92.64.75:57753
2013-04-30 11:01:21,180 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=Aware.Status.crawford@lx1-tir
2013-04-30 11:01:21,180 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.10_45396
2013-04-30 11:01:21,180 | DEBUG | Stopping connection:
tcp://165.92.64.10:45396
2013-04-30 11:01:21,180 | DEBUG | Stopping transport
tcp:///165.92.64.10:45396@61616
2013-04-30 11:01:21,180 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@16a859c
2013-04-30 11:01:21,180 | DEBUG | Closed socket
Socket[addr=/165.92.64.10,port=45396,localport=61616]
2013-04-30 11:01:21,181 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@16a859c
2013-04-30 11:01:21,181 | DEBUG | Stopped transport:
tcp://165.92.64.10:45396
2013-04-30 11:01:21,181 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.10:45396
2013-04-30 11:01:21,181 | DEBUG | remove connection id:
ID:lx1-tir-43330-1367316241262-3:1
2013-04-30 11:01:21,181 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=Aware.Status.crawford@lx1-tir,consumerId=ID_lx1-tir-43330-1367316241262-3_1_-1_1
2013-04-30 11:01:21,181 | DEBUG | localhost removing consumer:
ID:lx1-tir-43330-1367316241262-3:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,181 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=Aware,endpoint=Consumer,clientId=Aware.Status.crawford@lx1-tir,consumerId=Durable(Aware.Status.crawford@lx1-tir_Aware.Status)
2013-04-30 11:01:21,181 | DEBUG | Deactivating keepActive=true,
DurableTopicSubscription-Aware.Status.crawford@lx1-tir:Aware.Status,
id=ID:lx1-tir-43330-1367316241262-3:1:1:1, active=true, destinations=1,
total=9076, pending=0, dispatched=9255, inflight=0, prefetchExtension=0
2013-04-30 11:01:21,181 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,endpoint=dynamicProducer,clientId=Aware.Status.crawford@lx1-tir,producerId=ID_lx1-tir-43330-1367316241262-3_1_1_1
2013-04-30 11:01:21,181 | DEBUG | Connection Stopped:
tcp://165.92.64.10:45396
2013-04-30 11:01:21,181 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_lx1-tir-56259-1367316944613-0_1
2013-04-30 11:01:21,181 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.10_46365
2013-04-30 11:01:21,181 | DEBUG | Stopping connection:
tcp://165.92.64.10:46365
2013-04-30 11:01:21,181 | DEBUG | Stopping transport
tcp:///165.92.64.10:46365@61616
2013-04-30 11:01:21,181 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@1d9a642
2013-04-30 11:01:21,181 | DEBUG | Closed socket
Socket[addr=/165.92.64.10,port=46365,localport=61616]
2013-04-30 11:01:21,181 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@1d9a642
2013-04-30 11:01:21,181 | DEBUG | Stopped transport:
tcp://165.92.64.10:46365
2013-04-30 11:01:21,181 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.10:46365
2013-04-30 11:01:21,181 | DEBUG | remove connection id:
ID:lx1-tir-56259-1367316944613-1:1
2013-04-30 11:01:21,182 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_lx1-tir-56259-1367316944613-0_1,consumerId=ID_lx1-tir-56259-1367316944613-1_1_-1_1
2013-04-30 11:01:21,182 | DEBUG | localhost removing consumer:
ID:lx1-tir-56259-1367316944613-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,182 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.toSnooper,endpoint=Producer,clientId=ID_lx1-tir-56259-1367316944613-0_1,producerId=ID_lx1-tir-56259-1367316944613-1_1_1_1
2013-04-30 11:01:21,182 | DEBUG | Connection Stopped:
tcp://165.92.64.10:46365
2013-04-30 11:01:21,182 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_lx1-tir-56259-1367316944613-2_1
2013-04-30 11:01:21,182 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.10_46366
2013-04-30 11:01:21,182 | DEBUG | Stopping connection:
tcp://165.92.64.10:46366
2013-04-30 11:01:21,182 | DEBUG | Stopping transport
tcp:///165.92.64.10:46366@61616
2013-04-30 11:01:21,182 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@d8880c
2013-04-30 11:01:21,182 | DEBUG | Closed socket
Socket[addr=/165.92.64.10,port=46366,localport=61616]
2013-04-30 11:01:21,182 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@d8880c
2013-04-30 11:01:21,182 | DEBUG | Stopped transport:
tcp://165.92.64.10:46366
2013-04-30 11:01:21,182 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.10:46366
2013-04-30 11:01:21,182 | DEBUG | remove connection id:
ID:lx1-tir-56259-1367316944613-3:1
2013-04-30 11:01:21,182 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.icon,endpoint=Producer,clientId=ID_lx1-tir-56259-1367316944613-2_1,producerId=ID_lx1-tir-56259-1367316944613-3_1_1_1
2013-04-30 11:01:21,182 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_lx1-tir-56259-1367316944613-2_1,consumerId=ID_lx1-tir-56259-1367316944613-3_1_-1_1
2013-04-30 11:01:21,182 | DEBUG | localhost removing consumer:
ID:lx1-tir-56259-1367316944613-3:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,182 | DEBUG | Connection Stopped:
tcp://165.92.64.10:46366
2013-04-30 11:01:21,183 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_lx1-tir-56259-1367316944613-4_1
2013-04-30 11:01:21,183 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.10_46367
2013-04-30 11:01:21,183 | DEBUG | Stopping connection:
tcp://165.92.64.10:46367
2013-04-30 11:01:21,183 | DEBUG | Stopping transport
tcp:///165.92.64.10:46367@61616
2013-04-30 11:01:21,183 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@1e743a3
2013-04-30 11:01:21,183 | DEBUG | Closed socket
Socket[addr=/165.92.64.10,port=46367,localport=61616]
2013-04-30 11:01:21,183 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@1e743a3
2013-04-30 11:01:21,183 | DEBUG | Stopped transport:
tcp://165.92.64.10:46367
2013-04-30 11:01:21,183 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.10:46367
2013-04-30 11:01:21,183 | DEBUG | remove connection id:
ID:lx1-tir-56259-1367316944613-5:1
2013-04-30 11:01:21,183 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_lx1-tir-56259-1367316944613-4_1,consumerId=ID_lx1-tir-56259-1367316944613-5_1_-1_1
2013-04-30 11:01:21,183 | DEBUG | localhost removing consumer:
ID:lx1-tir-56259-1367316944613-5:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-04-30 11:01:21,183 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=LaunchPad.status,endpoint=Producer,clientId=ID_lx1-tir-56259-1367316944613-4_1,producerId=ID_lx1-tir-56259-1367316944613-5_1_1_1
2013-04-30 11:01:21,183 | DEBUG | Connection Stopped:
tcp://165.92.64.10:46367
2013-04-30 11:01:21,183 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=GIFTS.Status.crawford@lx1-tir
2013-04-30 11:01:21,183 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.10_46368
2013-04-30 11:01:21,183 | DEBUG | Stopping connection:
tcp://165.92.64.10:46368
2013-04-30 11:01:21,183 | DEBUG | Stopping transport
tcp:///165.92.64.10:46368@61616
2013-04-30 11:01:21,183 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@ae2a84
2013-04-30 11:01:21,183 | DEBUG | Closed socket
Socket[addr=/165.92.64.10,port=46368,localport=61616]
2013-04-30 11:01:21,183 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@ae2a84
2013-04-30 11:01:21,183 | DEBUG | Stopped transport:
tcp://165.92.64.10:46368
2013-04-30 11:01:21,183 | DEBUG | Cleaning up connection resources:
tcp://165.92.64.10:46368
2013-04-30 11:01:21,183 | DEBUG | remove connection id:
ID:lx1-tir-56259-1367316944613-7:1
--
View this message in context: http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470p4666653.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Is AMQ-4118 really fixed?? Doubt it...
Posted by fenbers <Ma...@noaa.gov>.
Here is the second log fro May 3 with a different error/stacktrace at
08:00:02,028, but is one mentioned to be fixed in AMQ-4118... This error
did not trigger a self-shutdown of ActiveMQ, but ActiveMQ clients did cease
receiving messages from this broker. Thus, from a client perspective,
ActiveMQ appeared to be hung. Once restarting ActiveMQ, the clients once
again received their messages as normal.
Mark
2013-05-03 07:59:53,529 | DEBUG | Checkpoint started.
2013-05-03 07:59:53,530 | TRACE | Last update: 38:18645505, full gc
candidates set: [1, 2, 4, 10, 18, 20, 25, 29, 33, 34, 37, 38]
2013-05-03 07:59:53,530 | TRACE | gc candidates after tx range:[null, null],
[1, 2, 4, 10, 18, 20, 25, 29, 33, 34, 37]
2013-05-03 07:59:53,530 | TRACE | gc candidates after
dest:1:GIFTS.fromSnooper, [1, 2, 4, 10, 18, 20, 25, 29, 34, 37]
2013-05-03 07:59:53,530 | TRACE | gc candidates after dest:1:GIFTS.icon, [1,
2, 4, 10, 18, 20, 25, 29, 34, 37]
2013-05-03 07:59:53,530 | TRACE | gc candidates after dest:0:ActiveMQ.DLQ,
[34]
2013-05-03 07:59:53,530 | TRACE | gc candidates after
dest:1:LaunchPad.status, []
2013-05-03 07:59:53,530 | TRACE | gc candidates: []
2013-05-03 07:59:53,530 | DEBUG | Checkpoint done.
2013-05-03 07:59:54,973 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:54,973 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55434]
2013-05-03 07:59:55,496 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:55,496 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:55,496 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55436]
2013-05-03 07:59:55,496 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55435]
2013-05-03 07:59:56,370 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-05-03 07:59:56,370 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:46764]
2013-05-03 07:59:57,366 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:57,366 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:49884]
2013-05-03 07:59:57,514 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:57,514 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:46765]
2013-05-03 07:59:58,551 | DEBUG | Checkpoint started.
2013-05-03 07:59:58,552 | DEBUG | Checkpoint done.
2013-05-03 07:59:58,595 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-05-03 07:59:58,595 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:46766]
2013-05-03 07:59:59,544 | DEBUG | 30005 ms elapsed since last read check.
2013-05-03 07:59:59,864 | DEBUG | WriteChecker 10001 ms elapsed since last
write check.
2013-05-03 07:59:59,864 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55438]
2013-05-03 08:00:00,481 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:00,482 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:58049]
2013-05-03 08:00:01,022 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-05-03 08:00:01,022 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55439]
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.37:57958]
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.75:38850]
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.37:57959]
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.75:38849]
2013-05-03 08:00:01,932 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,938 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,938 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,938 | DEBUG | tcp:///165.92.64.31:37879@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:01,938 | DEBUG | tcp:///165.92.64.31:37879@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-05-03 08:00:01,950 | DEBUG | Setting up new connection id:
ID:dell8-tir-49417-1367582401815-1:1, address: tcp://165.92.64.31:37879,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:dell8-tir-49417-1367582401815-1:1, clientId =
ID:dell8-tir-49417-1367582401815-0:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:01,950 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:01,950 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:01,961 | DEBUG | localhost adding consumer:
ID:dell8-tir-49417-1367582401815-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:01,961 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:dell8-tir-49417-1367582401815-1:1:-1:1
2013-05-03 08:00:01,995 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,997 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,997 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,997 | DEBUG | tcp:///165.92.64.8:48597@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:01,997 | DEBUG | tcp:///165.92.64.8:48597@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-05-03 08:00:02,001 | DEBUG | Setting up new connection id:
ID:px2-tir-33688-1367582401885-1:1, address: tcp://165.92.64.8:48597, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:px2-tir-33688-1367582401885-1:1, clientId =
ID:px2-tir-33688-1367582401885-0:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,001 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,001 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,007 | DEBUG | localhost adding consumer:
ID:px2-tir-33688-1367582401885-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,007 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:px2-tir-33688-1367582401885-1:1:-1:1
2013-05-03 08:00:02,008 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,008 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,025 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,025 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:1 syncCount: 2
2013-05-03 08:00:02,026 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,028 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,028 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:2 syncCount: 2
2013-05-03 08:00:02,028 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=765,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,028 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=765,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,029 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,029 | DEBUG | Error occured while processing sync
command: ActiveMQTextMessage {commandId = 1078, responseRequired = true,
messageId = ID:rp1-tir-53724-1367411226416-1:1:1:1:1072, originalDestination
= null, originalTransactionId = null, producerId =
ID:rp1-tir-53724-1367411226416-1:1:1:1, destination =
topic://GIFTS.fromSnooper, transactionId = null, expiration = 1367604000000,
timestamp = 1367582402027, arrival = 0, brokerInTime = 1367582402027,
brokerOutTime = 1367582402026, correlationId = null, replyTo = null,
persistent = true, type = null, priority = 4, groupID = null, groupSequence
= 0, targetConsumerId = null, compressed = false, userID = null, content =
null, marshalledProperties = null, dataStructure = null, redeliveryCounter =
0, size = 1064, properties = null, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = oper@dell8-tir:INITIALIZED:SAGU:oper},
exception: java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
... 27 more
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,030 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,030 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:3 syncCount: 2
2013-05-03 08:00:02,030 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,030 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,031 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,032 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,032 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:4 syncCount: 2
2013-05-03 08:00:02,032 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,034 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,034 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:5 syncCount: 2
2013-05-03 08:00:02,034 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,036 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,036 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:6 syncCount: 2
2013-05-03 08:00:02,037 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,038 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,038 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:7 syncCount: 2
2013-05-03 08:00:02,039 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,043 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-53724-1367411226416-0_1,producerId=ID_rp1-tir-53724-1367411226416-1_1_1_1
2013-05-03 08:00:02,043 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,043 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,044 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-53724-1367411226416-0_1,consumerId=ID_rp1-tir-53724-1367411226416-1_1_-1_1
2013-05-03 08:00:02,044 | DEBUG | localhost removing consumer:
ID:rp1-tir-53724-1367411226416-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,044 | DEBUG | remove connection id:
ID:rp1-tir-53724-1367411226416-1:1
2013-05-03 08:00:02,044 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,044 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,045 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-53724-1367411226416-0_1
2013-05-03 08:00:02,045 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_38849
2013-05-03 08:00:02,045 | DEBUG | Stopping connection:
tcp://165.92.64.75:38849
2013-05-03 08:00:02,045 | DEBUG | Stopping transport
tcp:///165.92.64.75:38849@61616
2013-05-03 08:00:02,045 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@152d5a8
2013-05-03 08:00:02,045 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=38849,localport=61616]
2013-05-03 08:00:02,045 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@152d5a8
2013-05-03 08:00:02,045 | DEBUG | Stopped transport:
tcp://165.92.64.75:38849
2013-05-03 08:00:02,045 | DEBUG | Connection Stopped:
tcp://165.92.64.75:38849
2013-05-03 08:00:02,046 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,046 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:8 syncCount: 2
2013-05-03 08:00:02,049 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,049 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,050 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,050 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,050 | DEBUG | tcp:///165.92.64.75:44666@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,050 | DEBUG | tcp:///165.92.64.75:44666@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,050 | DEBUG | Setting up new connection id:
ID:rp1-tir-53724-1367411226416-5:1, address: tcp://165.92.64.75:44666, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:rp1-tir-53724-1367411226416-5:1, clientId =
ID:rp1-tir-53724-1367411226416-4:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,050 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,050 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,051 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,051 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:9 syncCount: 2
2013-05-03 08:00:02,051 | DEBUG | localhost adding consumer:
ID:rp1-tir-53724-1367411226416-5:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,051 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:rp1-tir-53724-1367411226416-5:1:-1:1
2013-05-03 08:00:02,051 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,053 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,053 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:10 syncCount: 2
2013-05-03 08:00:02,054 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,055 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,055 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=766,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,055 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=766,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,056 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,056 | DEBUG | Error occured while processing sync
command: ActiveMQTextMessage {commandId = 5, responseRequired = true,
messageId = ID:rp1-tir-53724-1367411226416-5:1:1:1:1, originalDestination =
null, originalTransactionId = null, producerId =
ID:rp1-tir-53724-1367411226416-5:1:1:1, destination =
topic://GIFTS.fromSnooper, transactionId = null, expiration = 1367604000000,
timestamp = 1367582402054, arrival = 0, brokerInTime = 1367582402054,
brokerOutTime = 1367582402028, correlationId = null, replyTo = null,
persistent = true, type = null, priority = 4, groupID = null, groupSequence
= 0, targetConsumerId = null, compressed = false, userID = null, content =
null, marshalledProperties = null, dataStructure = null, redeliveryCounter =
0, size = 1064, properties = null, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = oper@dell8-tir:INITIALIZED:SAGL:oper},
exception: java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
... 27 more
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,056 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,056 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:11 syncCount: 2
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-53724-1367411226416-4_1,producerId=ID_rp1-tir-53724-1367411226416-5_1_1_1
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-53724-1367411226416-4_1,consumerId=ID_rp1-tir-53724-1367411226416-5_1_-1_1
2013-05-03 08:00:02,057 | DEBUG | localhost removing consumer:
ID:rp1-tir-53724-1367411226416-5:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,057 | DEBUG | remove connection id:
ID:rp1-tir-53724-1367411226416-5:1
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-53724-1367411226416-4_1
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_44666
2013-05-03 08:00:02,057 | DEBUG | Stopping connection:
tcp://165.92.64.75:44666
2013-05-03 08:00:02,057 | DEBUG | Stopping transport
tcp:///165.92.64.75:44666@61616
2013-05-03 08:00:02,057 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@dd50ca
2013-05-03 08:00:02,058 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=44666,localport=61616]
2013-05-03 08:00:02,058 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@dd50ca
2013-05-03 08:00:02,058 | DEBUG | Stopped transport:
tcp://165.92.64.75:44666
2013-05-03 08:00:02,058 | DEBUG | Connection Stopped:
tcp://165.92.64.75:44666
2013-05-03 08:00:02,058 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,058 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:12 syncCount: 2
2013-05-03 08:00:02,059 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,059 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,060 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,060 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,060 | DEBUG | tcp:///165.92.64.75:44667@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,060 | DEBUG | tcp:///165.92.64.75:44667@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,060 | DEBUG | Setting up new connection id:
ID:rp1-tir-53724-1367411226416-7:1, address: tcp://165.92.64.75:44667, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:rp1-tir-53724-1367411226416-7:1, clientId =
ID:rp1-tir-53724-1367411226416-6:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,060 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,060 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,061 | DEBUG | localhost adding consumer:
ID:rp1-tir-53724-1367411226416-7:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,061 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:rp1-tir-53724-1367411226416-7:1:-1:1
2013-05-03 08:00:02,061 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,061 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:13 syncCount: 2
2013-05-03 08:00:02,061 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,062 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,062 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,063 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,063 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:14 syncCount: 2
2013-05-03 08:00:02,064 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,064 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,065 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=767,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,065 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=767,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,065 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,065 | DEBUG | Error occured while processing sync
command: ActiveMQTextMessage {commandId = 5, responseRequired = true,
messageId = ID:rp1-tir-53724-1367411226416-7:1:1:1:1, originalDestination =
null, originalTransactionId = null, producerId =
ID:rp1-tir-53724-1367411226416-7:1:1:1, destination =
topic://GIFTS.fromSnooper, transactionId = null, expiration = 1367604000000,
timestamp = 1367582402064, arrival = 0, brokerInTime = 1367582402064,
brokerOutTime = 1367582402030, correlationId = null, replyTo = null,
persistent = true, type = null, priority = 4, groupID = null, groupSequence
= 0, targetConsumerId = null, compressed = false, userID = null, content =
null, marshalledProperties = null, dataStructure = null, redeliveryCounter =
0, size = 1064, properties = null, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = oper@dell8-tir:INITIALIZED:SMNU:oper},
exception: java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
... 27 more
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,065 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,065 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:15 syncCount: 2
2013-05-03 08:00:02,066 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-53724-1367411226416-6_1,producerId=ID_rp1-tir-53724-1367411226416-7_1_1_1
2013-05-03 08:00:02,066 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-53724-1367411226416-6_1,consumerId=ID_rp1-tir-53724-1367411226416-7_1_-1_1
2013-05-03 08:00:02,066 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,066 | DEBUG | localhost removing consumer:
ID:rp1-tir-53724-1367411226416-7:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,066 | DEBUG | remove connection id:
ID:rp1-tir-53724-1367411226416-7:1
2013-05-03 08:00:02,066 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,066 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,066 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-53724-1367411226416-6_1
2013-05-03 08:00:02,067 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_44667
2013-05-03 08:00:02,067 | DEBUG | Stopping connection:
tcp://165.92.64.75:44667
2013-05-03 08:00:02,067 | DEBUG | Stopping transport
tcp:///165.92.64.75:44667@61616
2013-05-03 08:00:02,067 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@12e359a
2013-05-03 08:00:02,067 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=44667,localport=61616]
2013-05-03 08:00:02,067 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@12e359a
2013-05-03 08:00:02,067 | DEBUG | Stopped transport:
tcp://165.92.64.75:44667
2013-05-03 08:00:02,067 | DEBUG | Connection Stopped:
tcp://165.92.64.75:44667
2013-05-03 08:00:02,068 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,068 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:16 syncCount: 2
2013-05-03 08:00:02,068 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,068 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,068 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,069 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,069 | DEBUG | tcp:///165.92.64.75:44668@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,069 | DEBUG | tcp:///165.92.64.75:44668@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,069 | DEBUG | Setting up new connection id:
ID:rp1-tir-53724-1367411226416-9:1, address: tcp://165.92.64.75:44668, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:rp1-tir-53724-1367411226416-9:1, clientId =
ID:rp1-tir-53724-1367411226416-8:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,069 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,069 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,070 | DEBUG | localhost adding consumer:
ID:rp1-tir-53724-1367411226416-9:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,070 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,070 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:rp1-tir-53724-1367411226416-9:1:-1:1
2013-05-03 08:00:02,070 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:17 syncCount: 2
2013-05-03 08:00:02,070 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,071 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,071 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,072 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,072 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:18 syncCount: 2
2013-05-03 08:00:02,073 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,073 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,073 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=768,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,073 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=768,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,074 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
--
View this message in context: http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470p4666654.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Is AMQ-4118 really fixed?? Doubt it...
Posted by fenbers <Ma...@noaa.gov>.
I would LOVE to help, but I would have no idea how to replicate the
problem. If I could replicate the problem, I'd know what I needed
to do to solve or work-around it. The tests you pointed me to
probably do eliminate the cause of that issue, but the problem
probably is triggered by other unanticipated factors. Based on the
fact that not all my log files are being cleaned up, I'd venture to
guess my issue is a configuration problem or some obscure faux pas
in my client code.
I'm not sure how to help you help me!
Mark
On 4/30/2013 12:53 PM, ceposta [via
ActiveMQ] wrote:
If you could put together a test we can get to the
bottom of it. Looks like
Gary put together these tests to show AMQ-4118 was solved:
https://fisheye6.atlassian.com/browse/activemq/trunk/activemq-core/src/test/java/org/apache/activemq/usecases/DurableSubsOfflineSelectorConcurrentConsumeIndexUseTest.java?r=1400317
On Tue, Apr 30, 2013 at 9:02 AM, fenbers < [hidden email] >
wrote:
> Regarding https://issues.apache.org/jira/browse/AMQ-4118 ,
the report says
> this issue is fixed in 5.8.0, but I am running 5.8.0 and
still have exactly
> the same 3 stack traces as listed in the URL above.
Moreover, I have
> numbered .log files (journal files) that never get cleaned
up
> automatically.
> These average about every 7th file or so that does not get
removed. TRACE
> log entries indicate that two of the topics (of 5 total
topics) are the
> culprits, but I cannot figure out why. I have been trying
to resolve this
> for a year now!! I've traced my code for the 3 topics that
don't leave
> complaints vs the 2 topics that do leave complaints and I
can't see any
> functional differences in my code.
>
> I'm at a loss! I'm currently running 5.8.0...
>
> Mark
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470.html
> Sent from the ActiveMQ - User mailing list archive at
Nabble.com.
>
--
*Christian Posta*
http://www.christianposta.com/blog
twitter: @christianposta
http://www.christianposta.com/blog
If you reply to this email, your
message will be added to the discussion below:
http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470p4666474.html
To unsubscribe from Is AMQ-4118 really fixed?? Doubt it..., click
here .
NAML
mark_fenbers.vcf (360 bytes) <http://activemq.2283324.n4.nabble.com/attachment/4666477/0/mark_fenbers.vcf>
--
View this message in context: http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470p4666477.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Is AMQ-4118 really fixed?? Doubt it...
Posted by Christian Posta <ch...@gmail.com>.
If you could put together a test we can get to the bottom of it. Looks like
Gary put together these tests to show AMQ-4118 was solved:
https://fisheye6.atlassian.com/browse/activemq/trunk/activemq-core/src/test/java/org/apache/activemq/usecases/DurableSubsOfflineSelectorConcurrentConsumeIndexUseTest.java?r=1400317
On Tue, Apr 30, 2013 at 9:02 AM, fenbers <Ma...@noaa.gov> wrote:
> Regarding https://issues.apache.org/jira/browse/AMQ-4118, the report says
> this issue is fixed in 5.8.0, but I am running 5.8.0 and still have exactly
> the same 3 stack traces as listed in the URL above. Moreover, I have
> numbered .log files (journal files) that never get cleaned up
> automatically.
> These average about every 7th file or so that does not get removed. TRACE
> log entries indicate that two of the topics (of 5 total topics) are the
> culprits, but I cannot figure out why. I have been trying to resolve this
> for a year now!! I've traced my code for the 3 topics that don't leave
> complaints vs the 2 topics that do leave complaints and I can't see any
> functional differences in my code.
>
> I'm at a loss! I'm currently running 5.8.0...
>
> Mark
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
--
*Christian Posta*
http://www.christianposta.com/blog
twitter: @christianposta