JBoss Distribute Cache's error?

[savagearts]

Hi All:
I encountered an error when i used JBoss' tree cache.
There are two servers in the cluster.
When a node is started. the second node show following messages:
1 [MessageDispatcher up processing thread] ERROR org.jboss.cache.TreeCache -
failed setting transient state

java.lang.NullPointerException
 at org.jboss.cache.eviction.LRUPolicy.nodeAdded(LRUPolicy.java:53)
 at org.jboss.cache.eviction.LRUPolicy.nodeCreated(LRUPolicy.java:92)
 at org.jboss.cache.TreeCache.notifyNodeCreated(TreeCache.java:3449)
 at org.jboss.cache.TreeCache.notifyAllNodesCreated(TreeCache.java:3501)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor._setState(TreeCache.
java:3012)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor.setState(TreeCache.j
ava:2954)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.passUp(MessageDi
spatcher.java:613)
 at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:3
31)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUp(Message
Dispatcher.java:720)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.access$300(Messa
geDispatcher.java:553)
 at org.jgroups.blocks.MessageDispatcher$1.run(MessageDispatcher.java:689
)
 at java.lang.Thread.run(Thread.java:534)

What's wrong with jboss cache? or There are some wrong with my configurations?

[savagearts]

51130 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl - new_view=[s66:43651|7] [s66:43651, s58:41282]
51131 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS - [local_addr=s58:41282] view is [s66:43651|7] [s66:43651, s58:41282]
51138 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - stable task started; num_gossip_runs=3, max_gossip_runs=3
51140 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - VIEW_CHANGE received: [s66:43651, s58:41282]
51143 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to s66:43651 (src=s58:41282), headers are {FD_SOCK=GET_CACHE, mbr=s58:41282, UDP=[UDP:group_addr=MyCluster]}
51147 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast) 262 bytes from /172.19.66.66:43652 (size=262 bytes)
51159 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.8:7600, src: s66:43651 (2 headers), size = 0 bytes], headers are {FD_SOCK=GET_CACHE_RSP, cache={s66:43651=s66:10000}, UDP=[UDP:group_addr=MyCluster]}
51164 [DownHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - GET_STATE: asking s66:43651 for state
51164 [DownHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - passing down a SUSPEND_STABLE event
51166 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - viewAccepted(): new members: [s66:43651, s58:41282]
51167 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - got cache from s66:43651: cache is {s66:43651=s66:10000}
51167 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - hdr=I_HAVE_SOCK, mbr=s58:41282, sock_addr=s58:10000
51169 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK - pinger_thread started
51169 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK - determinePingDest()=s66:43651, pingable_mbrs=[s66:43651, s58:41282]
51172 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK - ping_dest=s66:43651, ping_sock=Socket[addr=s66/172.19.66.66,port=10000,localport=40408], cache={s66:43651=s66:10000}
51173 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to 228.8.8.8:7600 (src=s58:41282), headers are {FD_SOCK=I_HAVE_SOCK, mbr=s58:41282, sock_addr=s58:10000, UDP=[UDP:group_addr=MyCluster]}
51174 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast) 181 bytes from /172.19.66.58:41283 (size=181 bytes)
51176 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.8:7600, src: s58:41282 (2 headers), size = 0 bytes], headers are {FD_SOCK=I_HAVE_SOCK, mbr=s58:41282, sock_addr=s58:10000, UDP=[UDP:group_addr=MyCluster]}
51177 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - i-have-sock: s58:41282 --> s58:10000 (cache is {s66:43651=s66:10000, s58:41282=s58:10000})
51225 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS - changed role to org.jgroups.protocols.pbcast.ParticipantGmsImpl
51225 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS - s58:41282 became participant
51227 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - suspending message garbage collection
51234 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - stable task started; num_gossip_runs=3, max_gossip_runs=3
51234 [DownHandler (GMS)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] --> DATA(s66:43651: #98, first=false)
51235 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to s66:43651 (src=s58:41282), headers are {UNICAST=[UNICAST: DATA, seqno=98], STATE_TRANSFER=[StateHeader: type=STATE_REQ, sender=s58:41282 id=#1, UDP=[UDP:group_addr=MyCluster]}
51242 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - received (ucast) 106 bytes from /172.19.66.66:43651
51243 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - message is [dst: s58:41282, src: s66:43651 (2 headers), size = 0 bytes], headers are {UNICAST=[UNICAST: DATA_ACK, seqno=98], UDP=[UDP:group_addr=MyCluster]}
51244 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] <-- ACK(s66:43651: #98)
51246 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - received (ucast) 1085 bytes from /172.19.66.66:43651
51249 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - message is [dst: s58:41282, src: s66:43651 (3 headers), size = 675 bytes], headers are {UNICAST=[UNICAST: DATA, seqno=5], STATE_TRANSFER=[StateHeader: type=STATE_RSP, sender=s66:43651 id=#0, digest=[s66:43651: [0 : 31, s58:41282: [0 : 0], UDP=[UDP:group_addr=MyCluster]}
51250 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] --> ACK(s66:43651: #5)
51251 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] <-- DATA(s66:43651: #5, first=false
51252 [UpHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - passing down a RESUME_STABLE event
51252 [UpHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - received state, size=675 bytes. Time=86 milliseconds
51253 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - received the state (size=675 bytes)
51264 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - transient state: 623 bytes
51265 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setting transient state
51292 [ServerSocketHandler thread] DEBUG org.jgroups.protocols.FD_SOCK - accepted connection from /172.19.66.66:46178
51306 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to s66:43651 (src=s58:41282), headers are {UNICAST=[UNICAST: DATA_ACK, seqno=5], UDP=[UDP:group_addr=MyCluster]}
51372 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - locking the old tree
51391 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - resuming message garbage collection
51448 [MessageDispatcher up processing thread] DEBUG org.jboss.cache.Node - acquired WL: fqn=/, owner=<s58:41282>:2, lock=write owner=<s58:41282>:2
51449 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setState(): locking the old tree was successful
51449 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setting the transient state was successful
51450 [MessageDispatcher up processing thread] DEBUG org.jboss.cache.eviction.LRUPolicy - nodeAdded(): fqn- /
51456 [MessageDispatcher up processing thread] ERROR org.jboss.cache.TreeCache - failed setting transient state
java.lang.NullPointerException
 at org.jboss.cache.eviction.LRUPolicy.nodeAdded(LRUPolicy.java:53)
 at org.jboss.cache.eviction.LRUPolicy.nodeCreated(LRUPolicy.java:92)
 at org.jboss.cache.TreeCache.notifyNodeCreated(TreeCache.java:3449)
 at org.jboss.cache.TreeCache.notifyAllNodesCreated(TreeCache.java:3501)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor._setState(TreeCache.java:3012)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor.setState(TreeCache.java:2954)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.passUp(MessageDispatcher.java:613)
 at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:331)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUp(MessageDispatcher.java:720)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.access$300(MessageDispatcher.java:553)
 at org.jgroups.blocks.MessageDispatcher$1.run(MessageDispatcher.java:689)
 at java.lang.Thread.run(Thread.java:534)
51460 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - forcing release of all locks in old tree
51461 [main] INFO org.jboss.cache.TreeCache TreeCache - state was retrieved successfully (in 315 milliseconds
51461 [main] INFO org.jboss.cache.eviction.LRUPolicy TreeCache - Starting eviction policy using the provider: org.jboss.cache.eviction.LRUPolicy
51469 [main] DEBUG org.jboss.cache.eviction.LRUPolicy TreeCache - parseConfig: name -- /_default_ maxNodes -- 5000 timeToIdleSeconds -- 1000
51469 [main] DEBUG org.jboss.cache.eviction.LRUPolicy TreeCache - parseConfig: name -- /com/utstar/csc/cas maxNodes -- 1000 timeToIdleSeconds -- 100
51516 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - createRegion(): creating region for fqn- /_default_
51522 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - getRegions(): size of region 0
51531 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - createRegion(): creating region for fqn- /com/utstar/csc/cas
51532 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - getRegions(): size of region 1
51539 [main] INFO org.jboss.cache.eviction.LRUPolicy TreeCache - Starting a eviction timer with wake up interval of (secs) 5
51545 [main] DEBUG org.jboss.cache.TreeCache - Started TreeCache

[savagearts]

Is the log tracing set to DEBUG? E.g., org.jboss.cache?

It will help me to debug this problem.

Thanks,

-Ben

[ben.wang]

Which version of JBossCache you are using? The latest one is 1.1. If this is the one you are using, please post a test case.

Thanks,

-Ben

[savagearts]

I'm currently using JBoss cache 1.1 .

I'll post my configuration tomorrow and more detail informations.

[savagearts]

The message of First Node:
-------------------------------------------------------
GMS: address is s66:43103
-------------------------------------------------------


The message of Second Node:

-------------------------------------------------------
GMS: address is s58:40892
-------------------------------------------------------
49533 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - viewAccepted(): new members: [s66:43103, s58:408
92]
49743 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - received the state (size=337 bytes)
49754 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - transient state: 285 bytes
49754 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setting transient state
49815 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - locking the old tree
49905 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setState(): locking the old tree was successful
49905 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setting the transient state was successful
49912 [MessageDispatcher up processing thread] ERROR org.jboss.cache.TreeCache - failed setting transient state
java.lang.NullPointerException
 at org.jboss.cache.eviction.LRUPolicy.nodeAdded(LRUPolicy.java:53)
 at org.jboss.cache.eviction.LRUPolicy.nodeCreated(LRUPolicy.java:92)
 at org.jboss.cache.TreeCache.notifyNodeCreated(TreeCache.java:3449)
 at org.jboss.cache.TreeCache.notifyAllNodesCreated(TreeCache.java:3501)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor._setState(TreeCache.java:3012)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor.setState(TreeCache.java:2954)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.passUp(MessageDispatcher.java:613)
 at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:331)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUp(MessageDispatcher.java:720)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.access$300(MessageDispatcher.java:553)
 at org.jgroups.blocks.MessageDispatcher$1.run(MessageDispatcher.java:689)
 at java.lang.Thread.run(Thread.java:534)
49916 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - forcing release of all locks in old tree
49917 [main] INFO org.jboss.cache.TreeCache TreeCache - state was retrieved successfully (in 397 milliseconds
49918 [main] INFO org.jboss.cache.eviction.LRUPolicy TreeCache - Starting eviction policy using the provider: org.jboss.cache.evi
ction.LRUPolicy
49990 [main] INFO org.jboss.cache.eviction.LRUPolicy TreeCache - Starting a eviction timer with wake up interval of (secs) 5

[savagearts]

My configuration:

<?xml version="1.0" encoding="UTF-8"?>

<server>

 <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/>

 <!-- ==================================================================== -->
 <!-- Defines TreeCache configuration -->
 <!-- ==================================================================== -->

 <mbean code="org.jboss.cache.TreeCache"
 name="jboss.cache:service=TreeCache">

 <depends>jboss:service=Naming</depends>
 <depends>jboss:service=TransactionManager</depends>

 <!--
 Configure the TransactionManager
 -->
 <!--<attribute name="TransactionManagerLookupClass">org.jboss.cache.DummyTransactionManagerLookup</attribute>-->
 <attribute name="TransactionManagerLookupClass">com.utstar.csc.cas.util.cache.impl.JOTMTransactionLookup</attribute>
 <!--
 Isolation level : SERIALIZABLE
 REPEATABLE_READ (default)
 READ_COMMITTED
 READ_UNCOMMITTED
 NONE
 -->
 <attribute name="IsolationLevel">REPEATABLE_READ</attribute>

 <!--
 Valid modes are LOCAL, REPL_ASYNC and REPL_SYNC
 -->
 <attribute name="CacheMode">REPL_SYNC</attribute>

 <!--
 Just used for async repl: use a replication queue
 -->
 <attribute name="UseReplQueue">false</attribute>

 <!--
 Replication interval for replication queue (in ms)
 -->
 <attribute name="ReplQueueInterval">0</attribute>

 <!--
 Max number of elements which trigger replication
 -->
 <attribute name="ReplQueueMaxElements">0</attribute>

 <!-- Name of cluster. Needs to be the same for all clusters, in order
 to find each other
 -->
 <attribute name="ClusterName">TreeCache-Cluster</attribute>

 <!--
 Whether or not to fetch state on joining a cluster
 -->
 <attribute name="FetchStateOnStartup">true</attribute>

 <!--
 The max amount of time (in milliseconds) we wait until the
 initial state (ie. the contents of the cache) are retrieved from
 existing members in a clustered environment
 -->
 <attribute name="InitialStateRetrievalTimeout">5000</attribute>

 <!--
 Number of milliseconds to wait until all responses for a
 synchronous call have been received.
 -->
 <attribute name="SyncReplTimeout">10000</attribute>

 <!-- Max number of milliseconds to wait for a lock acquisition -->
 <attribute name="LockAcquisitionTimeout">15000</attribute>

 <!-- Name of the eviction policy class. -->
 <attribute name="EvictionPolicyClass">org.jboss.cache.eviction.LRUPolicy</attribute>
 <!-- Specific eviction policy configurations. This is LRU -->
 <attribute name="EvictionPolicyConfig">
 <config>
 <attribute name="wakeUpIntervalSeconds">5</attribute>
 <!-- Cache wide default -->
 <region name="/_default_">
 <attribute name="maxNodes">5000</attribute>
 <attribute name="timeToIdleSeconds">1000</attribute>
 </region>
 <!--region name="/org/jboss/data">
 <attribute name="maxNodes">5000</attribute>
 <attribute name="timeToIdleSeconds">1000</attribute>
 </region-->
 <region name="/com/utstar/csc/cas">
 <attribute name="maxNodes">1000</attribute>
 <attribute name="timeToIdleSeconds">100</attribute>
 </region>
 </config>
 </attribute>
 </mbean>


 <attribute name="ClusterConfig">
 <config>
 <UDP bind_addr="192.168.0.1"
 ip_mcast="true"
 loopback="false"/>
 <PING timeout="2000"
 num_initial_members="3"
 up_thread="false"
 down_thread="false"/>
 <FD_SOCK/>
 <pbcast.NAKACK gc_lag="50"
 retransmit_timeout="600,1200,2400,4800"
 max_xmit_size="8192"
 up_thread="false" down_thread="false"/>
 <UNICAST timeout="600,1200,2400"
 window_size="100"
 min_threshold="10"
 down_thread="false"/>
 <pbcast.STABLE desired_avg_gossip="20000"
 up_thread="false"
 down_thread="false"/>
 <FRAG frag_size="8192"
 down_thread="false"
 up_thread="false"/>
 <pbcast.GMS join_timeout="5000"
 join_retry_timeout="2000"
 shun="true" print_local_addr="true"/>
 <pbcast.STATE_TRANSFER up_thread="true"
 down_thread="true"/>
 </config>
 </attribute>

 <!-- Uncomment to get a graphical view of the TreeCache MBean above -->
 <!-- <mbean code="org.jboss.cache.TreeCacheView" name="jboss.cache:service=TreeCacheView">-->
 <!-- <depends>jboss.cache:service=TreeCache</depends>-->
 <!-- <attribute name="CacheService">jboss.cache:service=TreeCache</attribute>-->
 <!-- </mbean>-->


</server>

[ben.wang]

Is the log tracing set to DEBUG? E.g., org.jboss.cache?

It will help me to debug this problem.

Thanks,

-Ben

[savagearts]

51130 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl - new_view=[s66:43651|7] [s66:43651, s58:41282]
51131 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS - [local_addr=s58:41282] view is [s66:43651|7] [s66:43651, s58:41282]
51138 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - stable task started; num_gossip_runs=3, max_gossip_runs=3
51140 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - VIEW_CHANGE received: [s66:43651, s58:41282]
51143 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to s66:43651 (src=s58:41282), headers are {FD_SOCK=GET_CACHE, mbr=s58:41282, UDP=[UDP:group_addr=MyCluster]}
51147 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast) 262 bytes from /172.19.66.66:43652 (size=262 bytes)
51159 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.8:7600, src: s66:43651 (2 headers), size = 0 bytes], headers are {FD_SOCK=GET_CACHE_RSP, cache={s66:43651=s66:10000}, UDP=[UDP:group_addr=MyCluster]}
51164 [DownHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - GET_STATE: asking s66:43651 for state
51164 [DownHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - passing down a SUSPEND_STABLE event
51166 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - viewAccepted(): new members: [s66:43651, s58:41282]
51167 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - got cache from s66:43651: cache is {s66:43651=s66:10000}
51167 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - hdr=I_HAVE_SOCK, mbr=s58:41282, sock_addr=s58:10000
51169 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK - pinger_thread started
51169 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK - determinePingDest()=s66:43651, pingable_mbrs=[s66:43651, s58:41282]
51172 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK - ping_dest=s66:43651, ping_sock=Socket[addr=s66/172.19.66.66,port=10000,localport=40408], cache={s66:43651=s66:10000}
51173 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to 228.8.8.8:7600 (src=s58:41282), headers are {FD_SOCK=I_HAVE_SOCK, mbr=s58:41282, sock_addr=s58:10000, UDP=[UDP:group_addr=MyCluster]}
51174 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast) 181 bytes from /172.19.66.58:41283 (size=181 bytes)
51176 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.8:7600, src: s58:41282 (2 headers), size = 0 bytes], headers are {FD_SOCK=I_HAVE_SOCK, mbr=s58:41282, sock_addr=s58:10000, UDP=[UDP:group_addr=MyCluster]}
51177 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK - i-have-sock: s58:41282 --> s58:10000 (cache is {s66:43651=s66:10000, s58:41282=s58:10000})
51225 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS - changed role to org.jgroups.protocols.pbcast.ParticipantGmsImpl
51225 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS - s58:41282 became participant
51227 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - suspending message garbage collection
51234 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - stable task started; num_gossip_runs=3, max_gossip_runs=3
51234 [DownHandler (GMS)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] --> DATA(s66:43651: #98, first=false)
51235 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to s66:43651 (src=s58:41282), headers are {UNICAST=[UNICAST: DATA, seqno=98], STATE_TRANSFER=[StateHeader: type=STATE_REQ, sender=s58:41282 id=#1, UDP=[UDP:group_addr=MyCluster]}
51242 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - received (ucast) 106 bytes from /172.19.66.66:43651
51243 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - message is [dst: s58:41282, src: s66:43651 (2 headers), size = 0 bytes], headers are {UNICAST=[UNICAST: DATA_ACK, seqno=98], UDP=[UDP:group_addr=MyCluster]}
51244 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] <-- ACK(s66:43651: #98)
51246 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - received (ucast) 1085 bytes from /172.19.66.66:43651
51249 [UDP.UcastReceiverThread] DEBUG org.jgroups.protocols.UDP - message is [dst: s58:41282, src: s66:43651 (3 headers), size = 675 bytes], headers are {UNICAST=[UNICAST: DATA, seqno=5], STATE_TRANSFER=[StateHeader: type=STATE_RSP, sender=s66:43651 id=#0, digest=[s66:43651: [0 : 31, s58:41282: [0 : 0], UDP=[UDP:group_addr=MyCluster]}
51250 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] --> ACK(s66:43651: #5)
51251 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.UNICAST - [s58:41282] <-- DATA(s66:43651: #5, first=false
51252 [UpHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - passing down a RESUME_STABLE event
51252 [UpHandler (STATE_TRANSFER)] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - received state, size=675 bytes. Time=86 milliseconds
51253 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - received the state (size=675 bytes)
51264 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - transient state: 623 bytes
51265 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setting transient state
51292 [ServerSocketHandler thread] DEBUG org.jgroups.protocols.FD_SOCK - accepted connection from /172.19.66.66:46178
51306 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending message to s66:43651 (src=s58:41282), headers are {UNICAST=[UNICAST: DATA_ACK, seqno=5], UDP=[UDP:group_addr=MyCluster]}
51372 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - locking the old tree
51391 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.STABLE - resuming message garbage collection
51448 [MessageDispatcher up processing thread] DEBUG org.jboss.cache.Node - acquired WL: fqn=/, owner=<s58:41282>:2, lock=write owner=<s58:41282>:2
51449 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setState(): locking the old tree was successful
51449 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - setting the transient state was successful
51450 [MessageDispatcher up processing thread] DEBUG org.jboss.cache.eviction.LRUPolicy - nodeAdded(): fqn- /
51456 [MessageDispatcher up processing thread] ERROR org.jboss.cache.TreeCache - failed setting transient state
java.lang.NullPointerException
 at org.jboss.cache.eviction.LRUPolicy.nodeAdded(LRUPolicy.java:53)
 at org.jboss.cache.eviction.LRUPolicy.nodeCreated(LRUPolicy.java:92)
 at org.jboss.cache.TreeCache.notifyNodeCreated(TreeCache.java:3449)
 at org.jboss.cache.TreeCache.notifyAllNodesCreated(TreeCache.java:3501)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor._setState(TreeCache.java:3012)
 at org.jboss.cache.TreeCache$MessageListenerAdaptor.setState(TreeCache.java:2954)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.passUp(MessageDispatcher.java:613)
 at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:331)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUp(MessageDispatcher.java:720)
 at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.access$300(MessageDispatcher.java:553)
 at org.jgroups.blocks.MessageDispatcher$1.run(MessageDispatcher.java:689)
 at java.lang.Thread.run(Thread.java:534)
51460 [MessageDispatcher up processing thread] INFO org.jboss.cache.TreeCache - forcing release of all locks in old tree
51461 [main] INFO org.jboss.cache.TreeCache TreeCache - state was retrieved successfully (in 315 milliseconds
51461 [main] INFO org.jboss.cache.eviction.LRUPolicy TreeCache - Starting eviction policy using the provider: org.jboss.cache.eviction.LRUPolicy
51469 [main] DEBUG org.jboss.cache.eviction.LRUPolicy TreeCache - parseConfig: name -- /_default_ maxNodes -- 5000 timeToIdleSeconds -- 1000
51469 [main] DEBUG org.jboss.cache.eviction.LRUPolicy TreeCache - parseConfig: name -- /com/utstar/csc/cas maxNodes -- 1000 timeToIdleSeconds -- 100
51516 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - createRegion(): creating region for fqn- /_default_
51522 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - getRegions(): size of region 0
51531 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - createRegion(): creating region for fqn- /com/utstar/csc/cas
51532 [main] DEBUG org.jboss.cache.eviction.RegionManager TreeCache - getRegions(): size of region 1
51539 [main] INFO org.jboss.cache.eviction.LRUPolicy TreeCache - Starting a eviction timer with wake up interval of (secs) 5
51545 [main] DEBUG org.jboss.cache.TreeCache - Started TreeCache

[savagearts]

BTW: Although the second node contains error,But the replication still works well. And i found the Evicate Timer does not work!

[ben.wang]

This is weird. The second cache is doing state transfer during which to register "/" in the evition queue. LRUPolicy code should skip this one but it didn't and therefore NPE.

I simply can't re-produce it from my setup. Can you zip your test case and send it to [e-mail]?

Thanks,

-Ben

[savagearts]

Hi Ben,Please check your mail.

[norbert]

the NPE is due to regionManager being null in LRUPolicy.nodeAdded(Fqn):

 public void nodeAdded(Fqn fqn)
 {
 if(fqn.equals(ROOT))
 return;
 if(log_.isDebugEnabled())
 log_.debug("nodeAdded(): fqn- " + fqn);
 Region region = regionManager_.getRegion(fqn.toString()); <-- this line!
 region.setAddedNode(fqn);
 }

I wonder how this is supposed to work at all:

in TreeCache.startService() the Cache is populated by calling fetchStateOnStartup() before the EvictionPolicy is going to be initialized (by notifyCacheStarted() a few lines later...). Despite the fact it's surprising that fqn.equals(ROOT) apparently evaluates to true, the LRUPolicy just cannot populate it's regions as long it hasn't seen it's config yet...

to workaround the NPE you can set FetchStateOnStartup to false and call TreeCache.fetchState() after having called TreeCache.start();

[ben.wang]

Hmmn, this is a problem in 1.1 release after re-factoring then. Previously in 1.02, the event nofitication happens before the state transfer.

I will fix this.

Thanks for the effort,

-Ben

[dres1011]

Hey guys,

Just wanted to add that we are receiving this error as well. It only ocurrs when to nodes are started on the same machine with the same multicast address.

Is this even possible? I know I haven't read enough of the docs yet. But is the only way to have 2 nodes in the same multicast group on the same box is to have 2 nics with the bind_addr set to the ip of a different nic for each node?