Bug 751774

Summary: HotRod client throwing InvalidResponseException:: Invalid magic number. Expected 0xa1 and received 0x85
Product: [JBoss] JBoss Data Grid 6 Reporter: Martin Gencur <mgencur>
Component: InfinispanAssignee: Tristan Tarrant <ttarrant>
Status: CLOSED NEXTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: unspecified    
Version: unspecifiedCC: galder.zamarreno, jdg-bugs, msurtani
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-11-25 14:18:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Attachments:
Description Flags
Server TRACE log
none
HotRod client exception
none
Sample config file hotrod-endpoint example for standalone ispn none

Description Martin Gencur 2011-11-07 14:29:47 UTC 
Description of problem:

There's a problem with communication between HotRod client and server. The client throws the following exception (whole exception attached):

testPathAndRelativeToAttributes(org.jboss.test.datagrid.cachestore.FileCacheStoreTest)  Time elapsed: 0.24 sec  <<< ERROR!
org.infinispan.client.hotrod.exceptions.InvalidResponseException:: Invalid magic number. Expected 0xa1 and received 0x85
	at org.infinispan.client.hotrod.impl.operations.HotRodOperation.readHeaderAndValidate(HotRodOperation.java:116)
	at org.infinispan.client.hotrod.impl.operations.AbstractKeyValueOperation.sendPutOperation(AbstractKeyValueOperation.java:70)
	at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:49)
	at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:64)
	at org.infinispan.client.hotrod.impl.RemoteCacheImpl.put(RemoteCacheImpl.java:203)
	at org.infinispan.CacheSupport.put(CacheSupport.java:51)
	at org.jboss.test.datagrid.cachestore.FileCacheStoreTest.testPathAndRelativeToAttributes(FileCacheStoreTest.java:68) ....


Version-Release number of selected component (if applicable):

EDG snapshot (head=3edb796, contains JBoss AS 7.1.0.Alpha2-SNAPSHOT and snapshot of Infinispan from Nov 4 which is  > 5.1.0.BETA3 and < 5.1.0.BETA4)

How reproducible:

Run the following test from EDG functional testsuite: https://svn.devel.redhat.com/repos/jboss-qa/edg/edg-functional-tests/trunk/file-cache-store by "mvn clean verify -Dnode0.edghome=/tmp/edg-snapshot-dir"

Additional info:

The whole client exception and server side TRACE log attached.
Comment 1 Martin Gencur 2011-11-07 14:30:40 UTC 
Created attachment 532052 [details]
Server TRACE log
Comment 2 Martin Gencur 2011-11-07 14:32:57 UTC 
This is probably related to https://issues.jboss.org/browse/ISPN-1506 so Galder should now more what's going on.
Comment 3 Martin Gencur 2011-11-07 14:33:59 UTC 
Created attachment 532053 [details]
HotRod client exception
Comment 4 Manik Surtani 2011-11-10 11:44:46 UTC 
ISPN-1506 is now closed and released in Infinispan 5.1.0.BETA4.  Could you pls test this again?
Comment 5 Martin Gencur 2011-11-10 13:04:47 UTC 
I tried a combination of HotRod client 5.1.0.BETA4 and EDG snapshot with Infinispan 5.1.0.BETA4 and the bug is still there.
Comment 6 Manik Surtani 2011-11-10 14:11:48 UTC 
Does this mean that ISPN-1506 isn't fixed, or does this mean that this bug isn't related to ISPN-1506 after all?
Comment 7 Martin Gencur 2011-11-10 14:46:43 UTC 
Hmm, I was not able to reproduce the bug with standalone infinispan 5.1.0.BETA4. I used my sample application to verify this: https://github.com/mgencur/edg-examples/tree/master/endpoints/hotrod-endpoint (there's a readme file in the location about how to run it)

With EDG containing Infinispan 5.1.0.BETA4 I was getting the exception while with standalone infinispan I was not. I'll attach the config file for standalone infinspan (a config file for EDG is available directly in that example).
Comment 8 Martin Gencur 2011-11-10 14:49:04 UTC 
Created attachment 532852 [details]
Sample config file hotrod-endpoint example for standalone ispn
Comment 9 Galder Zamarreño 2011-11-10 15:44:18 UTC 
Why isn't there a link to this Bugzilla issue in JIRA? 

Martin, if it's not working, it'd be very helpful to produce logs with TRACE on org.infinispan on both the client and the server, that might help speed up resolution :)
Comment 10 Martin Gencur 2011-11-10 15:50:45 UTC 
The TRACE log from server is already attached, I'll provide also client TRACE log
Comment 11 Galder Zamarreño 2011-11-10 15:58:29 UTC 
Also, I'm a bit surprised that these examples, and other tests/examples/...etc, are not included in the EDG codebase (https://github.com/infinispan/edg) as test or integrations tests that are run when EDG builds. This would reduce the turnaround time fixing issues like this.
Comment 12 Galder Zamarreño 2011-11-10 15:59:33 UTC 
Martin, I meant TRACE logs having tested with BETA4 which is supposed to have fixed the issue :)
Comment 13 Galder Zamarreño 2011-11-10 16:22:59 UTC 
Whenever there're messages like this, it's normally cos the server did not finish reading the request in an odd way. This is exceptional circumstances and the actual issue is in the server.log:

17:13:35,468 WARNING [org.jboss.netty.channel.DefaultChannelPipeline] (HotRodServerWorker-2-1) An exception was thrown by a user handler while handling an exception event ([id: 0x02916ab8, /127.0.0.1:58211 => /127.0.0.1:11222] EXCEPTION: java.lang.IllegalAccessError: tried to access class org.jboss.netty.handler.codec.replay.UnsafeDynamicChannelBuffer from class org.jboss.netty.handler.codec.replay.CustomReplayingDecoder): java.lang.NullPointerException
	at org.jboss.netty.handler.codec.replay.CustomReplayingDecoder.slimDownBuffer(CustomReplayingDecoder.java:178) [infinispan-server-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]

I actually spotted this already last week (http://community.jboss.org/message/634090) and I asked the guy to open a JIRA but don't think this was done, and being in the middle of JUDCon, forgot about it.

The weird thing is the IllegalAccessError that did not appear in the forums.

I'll address this asap. Thanks
Comment 14 Galder Zamarreño 2011-11-10 17:08:19 UTC 
The root cause is https://issues.jboss.org/browse/ISPN-1520 - This affects all Netty based Infinispan servers
Comment 15 Galder Zamarreño 2011-11-11 13:16:19 UTC 
Root cause fixed, alongside providing more meaningful errors to clients in these situations. Pull request sent and issue should be fixed in BETA5.
Comment 16 Martin Gencur 2011-11-11 13:28:16 UTC 
Excelent. I'll try with BETA5 when it's released.