Mailing-List: contact users-help@activemq.apache.org; run by ezmlm
Precedence: bulk
Reply-To: users@activemq.apache.org
Date: Tue, 1 Aug 2017 03:43:44 -0700 (PDT)
From: vdmitriev <allati.g@gmail.com>
To: users@activemq.apache.org
Message-ID: <1501584224567-4729109.post@n4.nabble.com>
Subject: AMQ 5.11.1, NPE in KahaAddMessageCommand.getMessage() (JIT
 suspected)
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Transfer-Encoding: 7bit
archived-at: Tue, 01 Aug 2017 10:44:18 -0000

Hello!

We are running AMQ 5.11.1 on AIX 7.1 with IBM J9 7.0 [1] and have
intermittent problem with messages delivery. Everything works fine,
consumers are connected to AMQ, but suddenly server stops delivering
messages and starts to log this stacktrace.

2017-08-01 01:53:12,913 | ERROR |
org.apache.activemq.broker.region.cursors.QueueStorePrefetch@442b1805:xxx,batchResetNeeded=false,size=3,cacheEnabled=false,maxBatchSize:3,hasSpace:true,pendingCachedIds.size:0,lastSyncCachedId:null,lastSyncCachedId-seq:null,lastAsyncCachedId:null,lastAsyncCachedId-seq:null,store=permits:10000,sd=nextSeq:84,lastRet:MessageOrderCursor:[def:81,
low:0, high:0],pending:0 - Failed to fill batch |
org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ
Broker[xxx] Scheduler
java.lang.NullPointerException
        at
org.apache.activemq.store.kahadb.data.KahaAddMessageCommandBase.getMessage(KahaAddMessageCommand.java:397)[activemq-kahadb-store-5.11.1.jar:5.11.1]
        at
org.apache.activemq.store.kahadb.data.KahaAddMessageCommand.getMessage(KahaAddMessageCommand.java:7)[activemq-kahadb-store-5.11.1.jar:5.11.1]
        at
org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:1131)[activemq-kahadb-store-5.11.1.jar:5.11.1]
        at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:595)[activemq-kahadb-store-5.11.1.jar:5.11.1]
        at
org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)[activemq-kahadb-store-5.11.1.jar:5.11.1]
        at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:584)[activemq-kahadb-store-5.11.1.jar:5.11.1]
        at
org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:106)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:109)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:381)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:142)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:159)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1897)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:2119)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.Queue.doBrowse(Queue.java:1116)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.Queue.expireMessages(Queue.java:909)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.Queue.access$100(Queue.java:100)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.broker.region.Queue$2.run(Queue.java:144)[activemq-broker-5.11.1.jar:5.11.1]
        at
org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)[activemq-client-5.11.1.jar:5.11.1]
        at java.util.TimerThread.mainLoop(Timer.java:566)[:1.7.0]
        at java.util.TimerThread.run(Timer.java:516)[:1.7.0]

I checked the sources (and decompiled binaries from the server just to be
sure) and see no valid reason for JVM to throw NPE at
KahaAddMessageCommand.java:397: "this" mustn't be null and unboxing is not
happening there. I suspect that JIT optimizations are messing the code, but
before following this bumpy trail, I wanted to check with AMQ community.
Maybe I'm missing something and JVM is behaving correctly? Maybe AMQ is
modifying itself somehow at runtime and KahaAddMessageCommand.java:397
starts to point to different sections of code?

[1]
java version "1.7.0"
Java(TM) SE Runtime Environment (build pap6470sr6fp1-20140108_01(SR6 FP1))
IBM J9 VM (build 2.6, JRE 1.7.0 AIX ppc64-64 Compressed References
20140106_181350 (JIT enabled, AOT enabled)
J9VM - R26_Java726_SR6_20140106_1601_B181350
JIT  - r11.b05_20131003_47443.02
GC   - R26_Java726_SR6_20140106_1601_B181350_CMPRSS
J9CL - 20140106_181350)
JCL - 20140103_01 based on Oracle 7u51-b11


~Regards
Vadim


--
View this message in context: http://activemq.2283324.n4.nabble.com/AMQ-5-11-1-NPE-in-KahaAddMessageCommand-getMessage-JIT-suspected-tp4729109.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.