-
1. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
manik Jul 20, 2006 2:56 PM (in response to bpapez)Hi,
This has to do with the new marshaller in 1.4.0 not recognising an object that has been serialised as a part of an RPC call and not being able to unmarshal it.
Could you post some more logs - say the last 20 lines or so before this happened? Also, could you describe what was going on at the time, if you can accurately recreate it?
Cheers,
Manik -
2. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
carlabramsson Aug 30, 2006 5:13 AM (in response to bpapez)Hello!
I started to see this in our logs to. We are using 1.4.0SP1 and JGroups 2.2.9.3.
Isolated the error and it seems like when you put a String with a length larger than 32767 this error occurs. The number in the error message is the byte of the the first char in the string. I get Unknown Magic Number 97 when using a string that has a 'a' as the first char and 60 when it's a '<'.
I wrote a testcase on this and i can recreate the error everytime. The testcase is only using jars from the 1.4.0SP1 dist-lib (wich includes JGroups 2.2.9.2) and a unmodified (besides mcast_addr and mcast_port) replAsync-service.xml from the dist.
The testcase sets up two instances and first tries to put a string with the length of 32768 wich fails. Then it tries to put a string with the length of 32767 wich works OK.
32768 / 4 = the FRAG frag_size in the config. Tried to double this value but no luck....
Is this a bug or a limit in the replication?
29626 [main] INFO com.hm.caab.treecachestandalone.TestTreeCache - Length of string is 32768
29626 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (10.60.15.101:4389) call on method [_put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true)]
29907 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true)
30157 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT for owner Thread[main,5,main]
30157 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects
30157 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects, caller=Thread[main,5,main], lock=
30172 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
30172 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects/com
30172 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com, caller=Thread[main,5,main], lock=
30172 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
30172 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects/com/hm
30172 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm, caller=Thread[main,5,main], lock=
30172 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
30172 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects/com/hm/caab
30172 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab, caller=Thread[main,5,main], lock=
30172 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
30172 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects/com/hm/caab/treecachestandalone
30172 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab/treecachestandalone, caller=Thread[main,5,main], lock=
30172 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab/treecachestandalone, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
30188 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache
30188 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache, caller=Thread[main,5,main], lock=
30188 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
30188 [main] DEBUG org.jboss.cache.Node - created child: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT
30188 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, caller=Thread[main,5,main], lock=
30188 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
30188 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true) on cache.
30454 [main] DEBUG org.jboss.cache.TreeCache - _put(null, "/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT", ES_ES_HTML, aa[removed long aaaa-string in log here...])
30719 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], write owner=Thread[main,5,main]]}
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT: write owner=Thread[main,5,main]
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab/treecachestandalone/TestTreeCache: read owners=[Thread[main,5,main]]
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab/treecachestandalone: read owners=[Thread[main,5,main]]
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab: read owners=[Thread[main,5,main]]
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm: read owners=[Thread[main,5,main]]
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com: read owners=[Thread[main,5,main]]
30735 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects: read owners=[Thread[main,5,main]]
30735 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx crud meth
30735 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true), members=[10.60.15.101:4389, 10.60.15.101:4393], mode=REPL_ASYNC, exclude_self=true, timeout=20000
31032 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call _put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true) to recipient list null
31297 [main] DEBUG org.jboss.cache.TreeCache - callRemoteMethods(): valid members are [10.60.15.101:4393] method: _replicate(_put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true))
31579 [main] DEBUG org.jgroups.blocks.RpcDispatcher - dests=[10.60.15.101:4393], method_call=_replicate(_put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true)), mode=6, timeout=20000
31860 [main] DEBUG org.jboss.cache.marshall.TreeCacheMarshaller140 - Marshalling object _replicate(_put(null, /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, aa[removed long aaaa-string in log here...], true))
32157 [main] DEBUG org.jgroups.blocks.RpcDispatcher - real_dests=[10.60.15.101:4393]
32172 [main] DEBUG org.jgroups.blocks.GroupRequest - sending request (id=1156927873256)
32172 [DownHandler (GMS)] DEBUG org.jgroups.protocols.FRAG - message size is 32990, will fragment (frag_size=16384)
32172 [main] DEBUG org.jgroups.blocks.GroupRequest - received all responses: [GroupRequest:
req_id=1156927873256
caller=10.60.15.101:4389
10.60.15.101:4393: sender=10.60.15.101:4393, retval=null, received=false, suspected=false
request_msg: [dst: , src: (1 headers), size = 32913 bytes]
rsp_mode: GET_NONE
done: false
timeout: 20000
expected_mbrs: 0
]
32172 [DownHandler (GMS)] DEBUG org.jgroups.protocols.FRAG - fragmenting packet to <all members> (size=65836) into 3 fragment(s) [frag_size=16384]
32172 [main] DEBUG org.jgroups.blocks.RpcDispatcher - responses: [sender=10.60.15.101:4393, retval=null, received=false, suspected=false]
32172 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.NAKACK - sending msg #3
32172 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=[]
32188 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (10.60.15.101:4389) call on method [_get(/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, true)]
32188 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.NAKACK - sending msg #4
32188 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.NAKACK - sending msg #5
32188 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _get(/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, true)
32188 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending msg to null (src=10.60.15.101:4389), headers are {NAKACK=[MSG, seqno=3], FRAG=[id=1, frag_id=0, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32188 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT for owner Thread[main,5,main]
32188 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast)16485 bytes from 10.60.15.101:4390
32188 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast)16485 bytes from 10.60.15.101:4390
32188 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending msg to null (src=10.60.15.101:4389), headers are {NAKACK=[MSG, seqno=4], FRAG=[id=1, frag_id=1, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32188 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.9:45570, src: 10.60.15.101:4389 (3 headers), size = 16384 bytes], headers are {NAKACK=[MSG, seqno=3], FRAG=[id=1, frag_id=0, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32188 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.9:45570, src: 10.60.15.101:4389 (3 headers), size = 16384 bytes], headers are {NAKACK=[MSG, seqno=3], FRAG=[id=1, frag_id=0, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32188 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects, caller=Thread[main,5,main], lock=
32204 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.pbcast.NAKACK - 10.60.15.101:4389] received 10.60.15.101:4389#3
32204 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.pbcast.NAKACK - 10.60.15.101:4393] received 10.60.15.101:4389#3
32204 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast)16485 bytes from 10.60.15.101:4390
32204 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast)16485 bytes from 10.60.15.101:4390
32204 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32204 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.9:45570, src: 10.60.15.101:4389 (3 headers), size = 16384 bytes], headers are {NAKACK=[MSG, seqno=4], FRAG=[id=1, frag_id=1, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32204 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP - sending msg to null (src=10.60.15.101:4389), headers are {NAKACK=[MSG, seqno=5], FRAG=[id=1, frag_id=2, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32204 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.9:45570, src: 10.60.15.101:4389 (3 headers), size = 16384 bytes], headers are {NAKACK=[MSG, seqno=4], FRAG=[id=1, frag_id=1, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32219 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com, caller=Thread[main,5,main], lock=
32219 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.pbcast.NAKACK - 10.60.15.101:4393] received 10.60.15.101:4389#4
32219 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.pbcast.NAKACK - 10.60.15.101:4389] received 10.60.15.101:4389#4
32219 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast)323 bytes from 10.60.15.101:4390
32219 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - received (mcast)323 bytes from 10.60.15.101:4390
32219 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32219 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.9:45570, src: 10.60.15.101:4389 (3 headers), size = 222 bytes], headers are {NAKACK=[MSG, seqno=5], FRAG=[id=1, frag_id=2, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32219 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP - message is [dst: 228.8.8.9:45570, src: 10.60.15.101:4389 (3 headers), size = 222 bytes], headers are {NAKACK=[MSG, seqno=5], FRAG=[id=1, frag_id=2, num_frags=3], UDP=[channel_name=TreeCache-Cluster]}
32235 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.pbcast.NAKACK - 10.60.15.101:4393] received 10.60.15.101:4389#5
32235 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.pbcast.NAKACK - 10.60.15.101:4389] received 10.60.15.101:4389#5
32235 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm, caller=Thread[main,5,main], lock=
32235 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.FRAG - assembled_msg is [dst: , src: (1 headers), size = 32913 bytes]
32235 [UpHandler (UNICAST)] DEBUG org.jgroups.protocols.FRAG - assembled_msg is [dst: , src: (1 headers), size = 32913 bytes]
32235 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32235 [UpHandler (STATE_TRANSFER)] DEBUG org.jgroups.blocks.RequestCorrelator - discarded request from 10.60.15.101:4389 as we are not part of destination list (local_addr=10.60.15.101:4389, hdr=[Header: name=MessageDispatcher, type=REQ, id=1156927873256, rsp_expected=false], dest_mbrs=[10.60.15.101:4393])
32235 [UpHandler (STATE_TRANSFER)] DEBUG org.jgroups.blocks.RequestCorrelator - calling (org.jgroups.blocks.RpcDispatcher) with request 1156927873256
32266 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab, caller=Thread[main,5,main], lock=
32266 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32266 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab/treecachestandalone, caller=Thread[main,5,main], lock=
32266 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab/treecachestandalone, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32266 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache, caller=Thread[main,5,main], lock=
32266 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=7 isLong=false
32266 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32266 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=3 isLong=false
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32282 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, caller=Thread[main,5,main], lock=
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=2 isLong=false
32282 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=4 isLong=false
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=19 isLong=false
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=13 isLong=false
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32282 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _get(/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT, ES_ES_HTML, true) on cache.
32282 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=9 isLong=false
32297 [main] DEBUG org.jboss.cache.TreeCache - _get("/objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT", ES_ES_HTML, "true")
32297 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]]]}
32297 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32297 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab/treecachestandalone/TestTreeCache/XMLOUTPUT: read owners=[Thread[main,5,main]]
32297 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=10 isLong=false
32297 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - readString::pulling data to Buffer at pos 0 size= 0
32297 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab/treecachestandalone/TestTreeCache: read owners=[Thread[main,5,main]]
32297 [UpHandler (STATE_TRANSFER)] DEBUG org.jboss.serial.util.StringUtil - Reading string with utfSize=-32768 isLong=false
32297 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab/treecachestandalone: read owners=[Thread[main,5,main]]
10:51:13,397 ERROR [TreeCacheMarshaller140] Unknown Magic Number 97
32313 [UpHandler (STATE_TRANSFER)] ERROR org.jboss.cache.marshall.TreeCacheMarshaller140 - Unknown Magic Number 97
32313 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm/caab: read owners=[Thread[main,5,main]]
10:51:13,397 INFO [VersionAwareMarshaller] Caught exception unmarshalling stream with specific versioned marshaller class org.jboss.cache.marshall.TreeCacheMarshaller140. Attempting to try again with legacy marshaller class org.jboss.cache.marshall.LegacyTreeCacheMarshaller
32313 [UpHandler (STATE_TRANSFER)] INFO org.jboss.cache.marshall.VersionAwareMarshaller - Caught exception unmarshalling stream with specific versioned marshaller class org.jboss.cache.marshall.TreeCacheMarshaller140. Attempting to try again with legacy marshaller class org.jboss.cache.marshall.LegacyTreeCacheMarshaller
32313 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com/hm: read owners=[Thread[main,5,main]]
10:51:13,397 ERROR [RpcDispatcher] exception=java.io.StreamCorruptedException: invalid stream header
32313 [UpHandler (STATE_TRANSFER)] ERROR org.jgroups.blocks.RpcDispatcher - exception=java.io.StreamCorruptedException: invalid stream header
32313 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects/com: read owners=[Thread[main,5,main]]
32329 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /objects: read owners=[Thread[main,5,main]]
32329 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx and non crud meth -
3. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
belaban Aug 30, 2006 5:28 AM (in response to bpapez)I fixed a problem with FRAG in 2.3 (http://jira.jboss.com/jira/browse/JGRP-215), can you either upgrade to 2.3 or use FRAG2 instead of FRAG, to see whether this is a JGroups problem ? If the problem disappears with 2.3, then it was a JGroups problem, otherwise it might be a problem with the JBossCache Marshaller.
-
4. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
carlabramsson Aug 30, 2006 5:57 AM (in response to bpapez)Tried with JGroups 2.3SP1 and FRAG2 (also with 2.3SP1) but no luck....
11:54:43,182 INFO [TestTreeCache] ------------------ Running testPutToBigString -------------------------
11:54:47,026 INFO [TestTreeCache] Length of string is 32768
11:54:47,073 INFO [TestTreeCache] Sleeping for 2000 millis...
11:54:47,104 ERROR [TreeCacheMarshaller140] Unknown Magic Number 97
11:54:47,104 INFO [VersionAwareMarshaller] Caught exception unmarshalling stream with specific versioned marshaller class org.jboss.cache.marshall.TreeCacheMarshaller140. Attempting to try again with legacy marshaller class org.jboss.cache.marshall.LegacyTreeCacheMarshaller
11:54:47,104 ERROR [RpcDispatcher] exception marshalling object
java.io.StreamCorruptedException: invalid stream header
at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:753)
at java.io.ObjectInputStream.(ObjectInputStream.java:268)
at org.jboss.invocation.MarshalledValueInputStream.(MarshalledValueInputStream.java:60)
at org.jboss.cache.marshall.VersionAwareMarshaller.objectFromByteBuffer(VersionAwareMarshaller.java:184)
at org.jgroups.blocks.RpcDispatcher.handle(RpcDispatcher.java:215)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:597)
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:497)
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:320)
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:722)
at org.jgroups.JChannel.up(JChannel.java:1034)
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:377)
at org.jgroups.stack.ProtocolStack.receiveUpEvent(ProtocolStack.java:393)
at org.jgroups.stack.Protocol.passUp(Protocol.java:538)
at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:149)
at org.jgroups.stack.UpHandler.run(Protocol.java:60) -
5. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
manik Aug 30, 2006 6:01 AM (in response to bpapez)Ok, let me take a look at this.
Have you been able to boil this down to a simple unit test? -
6. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
carlabramsson Aug 30, 2006 6:09 AM (in response to bpapez)Jupp. Here:
package com.hm.caab.treecachestandalone; import junit.framework.Test; import junit.framework.TestCase; import junit.framework.TestSuite; import org.apache.log4j.BasicConfigurator; import org.apache.log4j.Logger; import org.jboss.cache.Fqn; import org.jboss.cache.PropertyConfigurator; import org.jboss.cache.TreeCache; /** * Tests put with a large string * <p/> * Date: 2006-aug-29 * * @author Carl Abramsson / H&M */ public class TestTreeCache extends TestCase { protected static Logger log = Logger.getLogger(TestTreeCache.class.getName()); static { //String resource = "/log4j.xml"; //URL configFileResource = TestTreeCache.class.getResource(resource); //DOMConfigurator.configure(configFileResource.getFile()); BasicConfigurator.configure(); } TreeCache treeCache1 = null; TreeCache treeCache2 = null; private static final String CONFIG_FILE = "replAsync-service.xml"; protected void setUp() throws Exception { super.setUp(); log.info("------------------ set up start -------------------------"); // Cache 1 treeCache1 = new TreeCache(); PropertyConfigurator config1 = new PropertyConfigurator(); config1.configure(treeCache1, CONFIG_FILE); // Load config file from classpath treeCache1.startService(); sleepThread((long) 10000); // Cache 2 treeCache2 = new TreeCache(); PropertyConfigurator config2 = new PropertyConfigurator(); config2.configure(treeCache2, CONFIG_FILE); // Load config file from classpath treeCache2.startService(); sleepThread((long) 10000); log.info("------------------ set up finished -------------------------"); } protected void tearDown() throws Exception { log.info("------------------ tear down start -------------------------"); sleepThread((long) 1000); super.tearDown(); if (treeCache1 != null) { log.info(treeCache1); treeCache1.stopService(); treeCache1.destroyService(); treeCache1 = null; } if (treeCache2 != null) { log.info(treeCache2); treeCache2.stopService(); treeCache2.destroyService(); treeCache2 = null; } sleepThread((long) 10); log.info("------------------ tear down finito -------------------------"); } public void testPutToBigString() throws Exception { log.info("------------------ Running testPutToBigString -------------------------"); String region = "XMLOUTPUT"; String currentKey = "ES_ES_HTML"; Object fromCache; Fqn fqn = createFqn(TestTreeCache.class, region); String aString = createString(32768); log.info("Length of string is " + aString.length()); treeCache1.put(fqn, currentKey, aString); // Check cache1 fromCache = treeCache1.get(fqn, currentKey); assertNotNull(fromCache); assertEquals(fromCache, aString); sleepThread(2000); // Check cache2 fromCache = treeCache2.get(fqn, currentKey); assertNotNull(fromCache); assertEquals(fromCache, aString); log.info("------------------ finished testPutToBigString -------------------------"); } public void testPutString() throws Exception { log.info("------------------ Running testPutString -------------------------"); String region = "XMLOUTPUT"; String currentKey = "ES_ES_HTML"; Object fromCache; Fqn fqn = createFqn(TestTreeCache.class, region); String aString = createString(32767); treeCache1.put(fqn, currentKey, aString); // Check cache1 fromCache = treeCache1.get(fqn, currentKey); assertNotNull(fromCache); assertEquals(fromCache, aString); sleepThread(2000); // Check cache2 fromCache = treeCache2.get(fqn, currentKey); assertNotNull(fromCache); assertEquals(fromCache, aString); log.info("------------------ finished testPutString -------------------------"); } private String createString(int length) { String theString = ""; while (theString.length() < length) { theString = theString + "a"; } return theString; } protected Fqn createFqn(Class c, String region) { return Fqn.fromString("/objects" + Fqn.SEPARATOR + c.getName().replaceAll("\\.", "/") + Fqn.SEPARATOR + region); } /** * Puts the current thread to sleep for the desired number of ms, suppressing * any exceptions. * * @param sleeptime number of ms to sleep */ protected static void sleepThread(long sleeptime) { log.info("Sleeping for " + sleeptime + " millis..."); try { Thread.sleep(sleeptime); } catch (InterruptedException ie) { } log.info("Exiting sleep...."); } public static Test suite() { return new TestSuite(TestTreeCache.class); } }
And the config:<?xml version="1.0" encoding="UTF-8"?> <!-- ===================================================================== --> <!-- --> <!-- Sample TreeCache Service Configuration --> <!-- --> <!-- ===================================================================== --> <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> <!-- Isolation level : SERIALIZABLE REPEATABLE_READ (default) READ_COMMITTED READ_UNCOMMITTED NONE --> <attribute name="IsolationLevel">REPEATABLE_READ</attribute> <!-- Valid modes are LOCAL REPL_ASYNC REPL_SYNC INVALIDATION_ASYNC INVALIDATION_SYNC --> <attribute name="CacheMode">REPL_ASYNC</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> <!-- JGroups protocol stack properties. Can also be a URL, e.g. file:/home/bela/default.xml <attribute name="ClusterProperties"></attribute> --> <attribute name="ClusterConfig"> <config> <!-- UDP: if you have a multihomed machine, set the bind_addr attribute to the appropriate NIC IP address --> <!-- UDP: On Windows machines, because of the media sense feature being broken with multicast (even after disabling media sense) set the loopback attribute to true --> <UDP mcast_addr="228.8.8.9" mcast_port="45570" ip_ttl="64" ip_mcast="true" mcast_send_buf_size="150000" mcast_recv_buf_size="80000" ucast_send_buf_size="150000" ucast_recv_buf_size="80000" loopback="false"/> <PING timeout="2000" num_initial_members="3" up_thread="false" down_thread="false"/> <MERGE2 min_interval="10000" max_interval="20000"/> <!-- <FD shun="true" up_thread="true" down_thread="true" />--> <FD_SOCK/> <VERIFY_SUSPECT timeout="1500" up_thread="false" down_thread="false"/> <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> <!-- Whether or not to fetch state on joining a cluster NOTE this used to be called FetchStateOnStartup and has been renamed to be more descriptive. --> <attribute name="FetchInMemoryState">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">20000</attribute> <!-- Number of milliseconds to wait until all responses for a synchronous call have been received. --> <attribute name="SyncReplTimeout">20000</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"></attribute> <!-- Indicate whether to use region based marshalling or not. Set this to true if you are running under a scoped class loader, e.g., inside an application server. Default is "false". --> <attribute name="UseRegionBasedMarshalling">false</attribute> </mbean> <!-- 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>
-
7. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
manik Aug 30, 2006 6:34 AM (in response to bpapez)Thanks.
Ok, I see it - I've added a similar test to my test suite now.
See http://jira.jboss.com/jira/browse/JBCACHE-756
Cheers,
Manik -
8. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
carlabramsson Aug 30, 2006 7:41 AM (in response to bpapez)Cool.
Yeeah, did just see that there´s a 1.4.0SP2 planned now with "my" two bugs. Thanks! :-D -
9. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
belaban Aug 30, 2006 8:02 AM (in response to bpapez)Manik, please let me know if this turns out to be a JGroups problem, so I could look at it.
Cheers. -
10. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
manik Aug 30, 2006 8:22 AM (in response to bpapez)Bela, looks like a JBC problem.
Strings are written to the stream using the marshaller using ObjectOutputStream.writeUTF() - which has this limitation:
http://java.sun.com/j2se/1.5.0/docs/api/java/io/DataOutput.html#writeUTF(java.lang.String)
According to the documentation, this limits string lengths to 65535 bytes.
Carl, are you using multi-byte Strings (accents, etc)? 32767 characters x 2 bytes per char = 65534 bytes. 32768 characters (at 2 bytes per char) will cross this limit and you will see an overflow.
The fix to this problem would be NOT to use writeUTF() but to serialize the Strings themselves onto the stream, but this is less efficient. -
11. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
belaban Aug 30, 2006 8:28 AM (in response to bpapez)OK, ic
-
12. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
manik Sep 12, 2006 12:48 PM (in response to bpapez)This may just be a problem with jboss-serialization.jar and nothing to do with JBoss Cache at all. Clebert's investigating the potential problem with jboss-serialization.
http://jira.jboss.com/jira/browse/JBSER-89
FYI, JBoss Cache 1.4.0.GA and 1.4.0.SP1 both ship with jboss-serialization-1.0.1.GA. The potential upside is that if it is a bug in jboss-serialization, fixing the issue will just be upgrading the one jar, and it should be backward-compatible with JBoss Cache 1.4.0.XX. -
13. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
clebert.suconic Sep 19, 2006 1:28 PM (in response to bpapez)
The fix to this problem would be NOT to use writeUTF() but to serialize the Strings themselves onto the stream, but this is less efficient.
I don't think this would change the performance at al.
Strings are specially treated on Java Serialization. The routine for serializing strings is basically the same as writeUTF, but considering also long buffers.
I just had to support the same thing on JBoss Serialization.
I had a bug which I'm fixing right now. I'm writing a short, and reading back the same short but instead of using readUnsignedShort I was using readShort what would truncate the size of any string between 0xefff and 0xffff bytes (because of the sign bit)
Clebert -
14. Re: [TreeCacheMarshaller140] Unknown Magic Number 49
manik Sep 26, 2006 10:25 AM (in response to bpapez)yes, basically once we pinpointed that this was because of JBSER-89, my comments re: writeUTF is irrelevant.