Loading...

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 11.0.0.Final
Affects Version/s: 11.0.0.Final, 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

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/:?]

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

Closed

ISPN-12598 Hot Rod java client retries too many times

Closed

Details

Description

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates

PagerDuty