2017-06-22 17 views
0

Wir stehen vor einem seltsamen Problem, nachdem wir versucht haben, Spring-Jms-4.0.2 auf 4.3.8 zu aktualisieren und activemq blieb bei 5,13.0.Spring jms 4.3.8 vs 4.0.2 mit activemq 5.13.0 Ausgabe

was wir sehen, ist eine kontinuierliche Schleife entweder auf Frühjahr-jms oder activemq-Seite und CPU konsequent auf etwa 20-40 Bereich, nachdem wir die App in Tomcat gestartet.

Wenn wir zurück gehen und nur Spring-Jms 4.3.8 in lib mit Version 4.0.2 ersetzen, verhält sich alles normal nach dem Start.

Die gleichzeitigen Consumer sind 2 mit Cache-Level für "DefaultMessageListenerContainer" im Frühjahr auf 3 festgelegt.

Hier sind einige Indikatoren:

Wir haben die Debug-Protokollierung für beide spring und activemq aktiviert und was sehen wir im Frühjahr Protokoll sind 3 Zeilen nur unabhängig von Feder jms jar Version.

2017-06-22T12:09:02,928 DEBUG [org.springframework.jms.listener.DefaultMessageListenerContainer] Established shared JMS Connection 
2017-06-22T12:09:02,930 DEBUG [org.springframework.jms.listener.DefaultMessageListenerContainer] Resumed paused task: org.springframework.jms.liste[email protected]bd71008 
2017-06-22T12:09:02,930 DEBUG [org.springframework.jms.listener.DefaultMessageListenerContainer] Resumed paused task: org.springframework.jms.liste[email protected]7814de81 

Aber hier ist der Unterschied zwischen activemq logs

wenn wir verwenden feder jms-4.0.2

2017-06-22 12:00:46,921 | DEBUG | Received WireFormat: WireFormatInfo { version=11, properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true, TightEncodingEnabled=true, MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=30000}, magic=[A,c,t,i,v,e,M,Q]} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,922 | DEBUG | tcp:///127.0.0.1:[email protected] before negotiation: OpenWireFormat{version=11, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=9223372036854775807} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,922 | DEBUG | tcp:///127.0.0.1:[email protected] after negotiation: OpenWireFormat{version=11, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=9223372036854775807} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,927 | DEBUG | Setting up new connection id: ID:39235aa-49503-1498147246722-1:1, address: tcp://127.0.0.1:49504, info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:39235aa-49503-1498147246722-1:1, clientId = ID:39235aa-49503-1498147246722-0:1, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false} | org.apache.activemq.broker.TransportConnection | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,935 | DEBUG | Tomcat01.CE01 adding consumer: ID:39235aa-49503-1498147246722-1:1:-1:1 for destination: ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic | org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,973 | DEBUG | Tomcat01.CE01 adding consumer: ID:39235aa-49503-1498147246722-1:1:2:1 for destination: queue://company.CD.Tomcat01.Repo.Request | org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,976 | DEBUG | queue://company.CD.Tomcat01.Repo.Request add sub: QueueSubscription: consumer=ID:39235aa-49503-1498147246722-1:1:2:1, destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched: 0, inflight: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,976 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=1, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | Queue:company.CD.Tomcat01.Repo.Request 
2017-06-22 12:00:46,976 | DEBUG | Tomcat01.CE01 adding consumer: ID:39235aa-49503-1498147246722-1:1:1:1 for destination: queue://company.CD.Tomcat01.Repo.Request | org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,977 | DEBUG | queue://company.CD.Tomcat01.Repo.Request add sub: QueueSubscription: consumer=ID:39235aa-49503-1498147246722-1:1:1:1, destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched: 0, inflight: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,977 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | Queue:company.CD.Tomcat01.Repo.Request 
2017-06-22 12:00:46,978 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:00:46,978 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:01:04,340 | DEBUG | queue://company.CD.Tomcat01.Repo.Request expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[Tomcat01.CE01] Scheduler 
2017-06-22 12:01:04,342 | DEBUG | queue://company.CD.Tomcat01.Repo.Request expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[Tomcat01.CE01] Scheduler 
2017-06-22 12:01:04,342 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | Queue:company.CD.Tomcat01.Repo.Request 

Und wenn wir feder jms-4.3.8 Upgrade verwendet oder .9

2017-06-22 12:09:03,037 | DEBUG | Received WireFormat: WireFormatInfo { version=11, properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true, TightEncodingEnabled=true, MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=30000}, magic=[A,c,t,i,v,e,M,Q]} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,037 | DEBUG | tcp:///127.0.0.1:[email protected] before negotiation: OpenWireFormat{version=11, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=9223372036854775807} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,038 | DEBUG | tcp:///127.0.0.1:[email protected] after negotiation: OpenWireFormat{version=11, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=9223372036854775807} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,043 | DEBUG | Setting up new connection id: ID:39235aa-49635-1498147742821-1:1, address: tcp://127.0.0.1:49636, info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId = ID:39235aa-49635-1498147742821-1:1, clientId = ID:39235aa-49635-1498147742821-0:1, clientIp = null, userName = null, password = *****, brokerPath = null, brokerMasterConnector = false, manageable = true, clientMaster = true, faultTolerant = true, failoverReconnect = false} | org.apache.activemq.broker.TransportConnection | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,051 | DEBUG | Tomcat01.CE01 adding consumer: ID:39235aa-49635-1498147742821-1:1:-1:1 for destination: ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic | org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,092 | DEBUG | Tomcat01.CE01 adding consumer: ID:39235aa-49635-1498147742821-1:1:2:1 for destination: queue://company.CD.Tomcat01.Repo.Request | org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,095 | DEBUG | queue://company.CD.Tomcat01.Repo.Request add sub: QueueSubscription: consumer=ID:39235aa-49635-1498147742821-1:1:2:1, destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched: 0, inflight: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,095 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=1, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | Queue:company.CD.Tomcat01.Repo.Request 
2017-06-22 12:09:03,096 | DEBUG | Tomcat01.CE01 adding consumer: ID:39235aa-49635-1498147742821-1:1:1:1 for destination: queue://company.CD.Tomcat01.Repo.Request | org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,096 | DEBUG | queue://company.CD.Tomcat01.Repo.Request add sub: QueueSubscription: consumer=ID:39235aa-49635-1498147742821-1:1:1:1, destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched: 0, inflight: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,097 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | Queue:company.CD.Tomcat01.Repo.Request 
2017-06-22 12:09:03,097 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,105 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,114 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,114 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,114 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,114 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,115 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 
2017-06-22 12:09:03,115 | DEBUG | queue://company.CD.Tomcat01.Repo.Request, subscriptions=2, memory=0%, size=0, pending=0 toPageIn: 0, Inflight: 0, pagedInMessages.size 0, pagedInPendingDispatch.size 0, enqueueCount: 0, dequeueCount: 0, memUsage:0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: tcp:///127.0.0.1:[email protected] 

Wenn wir die Differenz zwischen zwei activemq Logs schauen,

012.351.

es zeigt, dass die Warteschlange Abonnements Zeile oder zweimal nur einmal gedruckt wird und dann nach einer Pause von 30 Sekunden die Ablaufzeit Tritte in und Kreis weiter

Aber in der 2. log der Ablauf nie tritt in und Warteschlange Abonnement Zeile wird jede ms gedruckt und Protokolle gehen in wenigen Minuten in GB, also irgendeine Art von Schleife.

Wir versuchen, dies zu debuggen, aber wenn jemand eine Idee oder einen Vorschlag hat, bitte geben Sie es durch.

danke.

Antwort

1

Gefunden das Problem, die aktualisierte Version 4.3.8 hat jetzt 0 für receivetimeout statt früher -1 zum Warten, bis es eine neue Nachricht erhält, die wir verwendet hatten und warum es versuchte, die Nachricht vom Broker zu erhalten (activemq) in einer Schleife und bombardierte sie mit solchen Aufrufen, die die anhaltende CPU-Auslastung verursachten.

Code-Snippet aus der JmsDestinationAccessor-Klasse.

protected Message receiveFromConsumer(MessageConsumer consumer, long timeout) throws JMSException { 
    if (timeout > 0) { 
     return consumer.receive(timeout); 
    } 
    else if (timeout < 0) { 
     return consumer.receiveNoWait(); 
    } 
    else { 
     return consumer.receive(); 
    } 
} 
Verwandte Themen