Loading...

Details

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 11.0.0.CR1
Affects Version/s: 11.0.0.Dev04, 10.1.6.Final
Component/s: Hot Rod, Multimap
Labels:
- testsuite_stability

Sprint:
DataGrid Sprint #42
Git Pull Request:
https://github.com/infinispan/infinispan/pull/8208, https://github.com/infinispan/infinispan/pull/8383

Description

The Hot Rod server includes metadata information with the GET_MULTIMAP_WITH_METADATA_REQUEST response even if the status is KEY_DOES_NOT_EXIST_STATUS, but the client does not expect any other information after the header, so it tries to read the metadata information as the start of a new response and fails:

08:50:15,468 TRACE (testng-Test:[]) [Codec] [] Wrote header for messageId=47333 to PooledUnsafeDirectByteBuf(ridx: 0, widx: 14, cap: 19). Operation code: 0x69(GET_MULTIMAP_WITH_METADATA_REQUEST). Flags: 0x1. Topology id: -1
08:50:15,468 TRACE (HotRod-Test-ServerIO-2061-1:[]) [Encoder2x] Write topology response header with no change
08:50:15,468 TRACE (Test-Client-Async-454-1:[]) [Codec] Received response for messageId=47333
08:50:15,468 TRACE (Test-Client-Async-454-1:[]) [HeaderDecoder] Decoding header for GetKeyWithMetadataMultimapOperation{(default), key=[B0x4A016B, flags=1, connection=127.0.0.1/127.0.0.1:38741} on [id: 0x36567c12, L:/127.0.0.1:36216 - R:127.0.0.1/127.0.0.1:38741]
08:50:15,468 TRACE (Test-Client-Async-454-1:[]) [HeaderDecoder] Decoding payload for GetKeyWithMetadataMultimapOperation{(default), key=[B0x4A016B, flags=1, connection=127.0.0.1/127.0.0.1:38741} on [id: 0x36567c12, L:/127.0.0.1:36216 - R:127.0.0.1/127.0.0.1:38741]
08:50:15,468 TRACE (Test-Client-Async-454-1:[]) [Codec] Socket dump: A1E5F102\j020003FFFFFFFFFFFFFFFF00
08:50:15,468 TRACE (Test-Client-Async-454-1:[]) [RetryOnFailureOperation] (1) GetKeyWithMetadataMultimapOperation{(default), key=[B0x4A016B, flags=1, connection=127.0.0.1/127.0.0.1:38741} Requesting [id: 0x36567c12, L:/127.0.0.1:36216 - R:127.0.0.1/127.0.0.1:38741] close due to exception
org.infinispan.client.hotrod.exceptions.InvalidResponseException: ISPN004003: Invalid magic number. Expected 0xa1 and received 0x3
	at org.infinispan.client.hotrod.impl.protocol.Codec20.readMessageId(Codec20.java:147) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.HeaderDecoder.decode(HeaderDecoder.java:86) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.HintedReplayingDecoder.callDecode(HintedReplayingDecoder.java:94) ~[classes/:?]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) ~[netty-codec-4.1.45.Final.jar:4.1.45.Final]

Because the client can't parse the remaining buffer as a response, it tries to close the connection, but sometimes even closing throws an AssertionError, causing random failures in test RemoteMultimapCacheAPITest.testGetWithMetadataNotExist:

08:50:15,469 TRACE (Test-Client-Async-454-1:[]) [ChannelRecord] Closing channel [id: 0x36567c12, L:/127.0.0.1:36216 ! R:127.0.0.1/127.0.0.1:38741]
08:50:15,469 TRACE (testng-Test:[]) [ChannelFactory] Releasing channel [id: 0x36567c12, L:/127.0.0.1:36216 ! R:127.0.0.1/127.0.0.1:38741]
08:50:15,469 TRACE (testng-Test:[]) [ChannelPool] Requesting [id: 0x36567c12, L:/127.0.0.1:36216 ! R:127.0.0.1/127.0.0.1:38741] close due to exception
java.lang.AssertionError: Error releasing [id: 0x36567c12, L:/127.0.0.1:36216 ! R:127.0.0.1/127.0.0.1:38741]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.release(ChannelPool.java:168) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelRecord.release(ChannelRecord.java:77) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.releaseChannel(ChannelFactory.java:312) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.operations.HotRodOperation.releaseChannel(HotRodOperation.java:103) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.invoke(RetryOnFailureOperation.java:80) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.activateChannel(ChannelPool.java:215) [classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.acquire(ChannelPool.java:84) [classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:262) [classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:300) [classes/:?]
	at org.infinispan.client.hotrod.impl.operations.AbstractKeyOperation.fetchChannelAndInvoke(AbstractKeyOperation.java:41) [classes/:?]
	at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:62) [classes/:?]
	at org.infinispan.client.hotrod.impl.multimap.RemoteMultimapCacheImpl.getWithMetadata(RemoteMultimapCacheImpl.java:106) [classes/:?]
	at org.infinispan.client.hotrod.RemoteMultimapCacheAPITest.testGetWithMetadataNotExist(RemoteMultimapCacheAPITest.java:59) [test-classes/:?]
08:50:15,479 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.client.hotrod.RemoteMultimapCacheAPITest.testGetWithMetadataNotExist
java.lang.AssertionError: Error releasing [id: 0x36567c12, L:/127.0.0.1:36216 ! R:127.0.0.1/127.0.0.1:38741]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.release(ChannelPool.java:168) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelRecord.release(ChannelRecord.java:77) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.releaseChannel(ChannelFactory.java:312) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.operations.HotRodOperation.releaseChannel(HotRodOperation.java:103) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.invoke(RetryOnFailureOperation.java:80) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.activateChannel(ChannelPool.java:215) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.acquire(ChannelPool.java:84) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:262) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:300) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.operations.AbstractKeyOperation.fetchChannelAndInvoke(AbstractKeyOperation.java:41) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:62) ~[classes/:?]
	at org.infinispan.client.hotrod.impl.multimap.RemoteMultimapCacheImpl.getWithMetadata(RemoteMultimapCacheImpl.java:106) ~[classes/:?]
	at org.infinispan.client.hotrod.RemoteMultimapCacheAPITest.testGetWithMetadataNotExist(RemoteMultimapCacheAPITest.java:59) ~[test-classes/:?]

Attachments

Issue Links

is related to

ISPN-12596 Hotrod client tries to read one byte to much when Multimap returns KeyDoesNotExist

Closed

relates to

ISPN-11631 Hot Rod protocol documentation is missing multimap operations

New

ISPN-12598 Hot Rod java client retries too many times

Closed

Server and client get out of sync after multimap get with metadata operation

Details

Description

Attachments

Issue Links

Activity

People

Dates