activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Rajib Rashid (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-3906) repeated error message regarding chunk stream logged
Date Tue, 13 Nov 2012 03:31:13 GMT

    [ https://issues.apache.org/jira/browse/AMQ-3906?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13495896#comment-13495896
] 

Rajib Rashid commented on AMQ-3906:
-----------------------------------

on a fresh install with only one client communicating with the server, the issue shows up
almost instantaneously. using the server configuration previously attached and kahadb directory
cleared (so that the database is initialized fresh) here are the startup log messages:

{noformat}
2012-11-12 16:43:54,493 o.a.a.x.XBeanBrokerFactory$1[main]: (INFO) Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@1d8d39f:
startup date [Mon Nov 12 16:43:54 PST 2012]; root of context hierarchy
2012-11-12 16:43:55,460 o.a.a.s.k.p.PListStore[main]: (INFO) PListStore:[/usr/local/emerald/apps/activemq/data/ZyrionMessageBus/tmp_storage
] started
2012-11-12 16:43:55,460 o.a.a.b.BrokerService[main]: (INFO) Using Persistence Adapter: KahaDBPersistenceAdapter[/usr/local/emerald/apps/activemq/data/kahadb]
2012-11-12 16:43:55,764 o.a.a.s.k.MessageDatabase[main]: (INFO) KahaDB is version 4
2012-11-12 16:43:55,793 o.a.a.s.k.MessageDatabase[main]: (INFO) Recovering from the journal
...
2012-11-12 16:43:55,793 o.a.a.s.k.MessageDatabase[main]: (INFO) Recovery replayed 1 operations
from the journal in 0.013 seconds.
2012-11-12 16:43:55,805 o.a.a.b.BrokerService[main]: (INFO) ActiveMQ 5.6.0 JMS Message Broker
(ZyrionMessageBus) is starting
2012-11-12 16:43:55,805 o.a.a.b.BrokerService[main]: (INFO) For help or more information please
see: http://activemq.apache.org/
2012-11-12 16:43:56,010 o.a.a.t.TransportServerThreadSupport[main]: (INFO) Listening for connections
at: nio://dev-runtime.enigma.local:7653?useQueueForAccept=false&wireFormat.stackTraceEnabled=false&wireFormat.cacheEnabled=false
2012-11-12 16:43:56,010 o.a.a.b.TransportConnector[main]: (INFO) Connector openwire Started
2012-11-12 16:43:56,012 o.a.a.b.BrokerService[main]: (INFO) ActiveMQ JMS Message Broker (ZyrionMessageBus,
ID:dev-runtime.enigma.local-40393-1352767435812-0:1) started
{noformat}

next the client is started so that it attaches to several topics. once the client application
is terminated (TERM/KILL signal), the next time the client starts following error is logged:

{noformat}
2012-11-12 16:45:01,016 o.a.a.b.r.Topic[ActiveMQ Broker[ZyrionMessageBus] Scheduler]: (WARN)
Failed to browse Topic: netvigil_DGERequestTopic
java.io.EOFException: Chunk stream does not exist, page: 23 is marked free
	at org.apache.kahadb.page.Transaction$2.readPage(Transaction.java:460) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction$2.<init>(Transaction.java:437) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.openInputStream(Transaction.java:434) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.load(Transaction.java:410) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.load(Transaction.java:367) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:232) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.MessageDatabase$MessageOrderIndex$MessageOrderIterator.<init>(MessageDatabase.java:2714)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.MessageDatabase$MessageOrderIndex.iterator(MessageDatabase.java:2696)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$3.execute(KahaDBStore.java:525)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.execute(Transaction.java:769) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recover(KahaDBStore.java:521)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.ProxyTopicMessageStore.recover(ProxyTopicMessageStore.java:62)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.broker.region.Topic.doBrowse(Topic.java:559) [activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.broker.region.Topic.access$100(Topic.java:62) [activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.broker.region.Topic$6.run(Topic.java:684) [activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33) [activemq-core-5.6.0.jar:5.6.0]
	at java.util.TimerThread.mainLoop(Timer.java:512) [na:1.6.0_18]
	at java.util.TimerThread.run(Timer.java:462) [na:1.6.0_18]
2012-11-12 16:45:31,012 o.a.a.b.r.Topic[ActiveMQ Broker[ZyrionMessageBus] Scheduler]: (WARN)
Failed to browse Topic: netvigil_DGERequestTopic
java.io.EOFException: Chunk stream does not exist, page: 23 is marked free
	at org.apache.kahadb.page.Transaction$2.readPage(Transaction.java:460) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction$2.<init>(Transaction.java:437) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.openInputStream(Transaction.java:434) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.load(Transaction.java:410) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.load(Transaction.java:367) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:232) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.MessageDatabase$MessageOrderIndex$MessageOrderIterator.<init>(MessageDatabase.java:2714)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.MessageDatabase$MessageOrderIndex.iterator(MessageDatabase.java:2696)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$3.execute(KahaDBStore.java:525)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.kahadb.page.Transaction.execute(Transaction.java:769) ~[kahadb-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recover(KahaDBStore.java:521)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.store.ProxyTopicMessageStore.recover(ProxyTopicMessageStore.java:62)
~[activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.broker.region.Topic.doBrowse(Topic.java:559) [activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.broker.region.Topic.access$100(Topic.java:62) [activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.broker.region.Topic$6.run(Topic.java:684) [activemq-core-5.6.0.jar:5.6.0]
	at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33) [activemq-core-5.6.0.jar:5.6.0]
	at java.util.TimerThread.mainLoop(Timer.java:512) [na:1.6.0_18]
	at java.util.TimerThread.run(Timer.java:462) [na:1.6.0_18]
{noformat}

i'm also attaching the contents of kahadb directory in case it helps. i have to say that it's
becoming increasingly difficult to use activemq in production environment. this issue was
reported with 5.6.0 less than 6 months ago. as a solution, i was asked to run 5.7 snapshot
will continued to exhibit the problem. now that 5.7.0 is has been released (and presumably
the "stable" release), i have to again resort to using the 5.8 snapshot release. had it not
been for the automatic expiration of idle consumers, we would have stuck to 5.3.2 or 5.5.

                
> repeated error message regarding chunk stream logged
> ----------------------------------------------------
>
>                 Key: AMQ-3906
>                 URL: https://issues.apache.org/jira/browse/AMQ-3906
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.6.0
>         Environment: ActiveMQ 5.6.0 running on Linux FC10 x86
>            Reporter: Rajib Rashid
>         Attachments: activemq.xml, kahadb.zip
>
>
> after running normally for ~24 hours, warning messages/errors like below are logged every
30 seconds:
> {code}
> 2012-06-27 14:33:31,532 org.apache.activemq.broker.region.Topic[ActiveMQ Broker[ZyrionMessageBus]
Scheduler]: (WARN) Failed to browse Topic: remoteUpdateP2PTopic
> java.io.EOFException: Chunk stream does not exist, page: 50 is marked free
>         at org.apache.kahadb.page.Transaction$2.readPage(Transaction.java:460)
>         at org.apache.kahadb.page.Transaction$2.<init>(Transaction.java:437)
>         at org.apache.kahadb.page.Transaction.openInputStream(Transaction.java:434)
>         at org.apache.kahadb.page.Transaction.load(Transaction.java:410)
>         at org.apache.kahadb.page.Transaction.load(Transaction.java:367)
>         at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262)
>         at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174)
>         at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:232)
>         at org.apache.activemq.store.kahadb.MessageDatabase$MessageOrderIndex$MessageOrderIterator.<init>(MessageDatabase.java:2714)
>         at org.apache.activemq.store.kahadb.MessageDatabase$MessageOrderIndex.iterator(MessageDatabase.java:2696)
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$3.execute(KahaDBStore.java:525)
>         at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recover(KahaDBStore.java:521)
>         at org.apache.activemq.store.ProxyTopicMessageStore.recover(ProxyTopicMessageStore.java:62)
>         at org.apache.activemq.broker.region.Topic.doBrowse(Topic.java:559)
>         at org.apache.activemq.broker.region.Topic.access$100(Topic.java:62)
>         at org.apache.activemq.broker.region.Topic$6.run(Topic.java:684)
>         at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
>         at java.util.TimerThread.mainLoop(Timer.java:512)
>         at java.util.TimerThread.run(Timer.java:462)
> {code}
> since then the warning has been logged 6000+ times. not sure if this is due to the fact
that we have enabled expiration of queued messages for offline subscribers.
> {code}
> % ls -l apps/activemq/data/kahadb/
> total 32068
> -rw-r--r-- 1 root root 33030144 2012-06-29 14:44 db-14.log
> -rw-r--r-- 1 root root   339968 2012-06-29 14:44 db.data
> -rw-r--r-- 1 root root   196984 2012-06-29 14:44 db.redo
> -rw-r--r-- 1 root root        0 2012-06-26 16:40 lock
> {code}

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message