[JBoss JIRA] (ISPN-9853) JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
by Martin Ross (Jira)
[ https://issues.jboss.org/browse/ISPN-9853?page=com.atlassian.jira.plugin.... ]
Martin Ross commented on ISPN-9853:
-----------------------------------
That sounds reasonable. This is really a show stopper for us from a reliability and performance. Anyone who uses a replicated cache expecting hashmap like performance is going to be frustrated since it isn't intuitive behavior imho.
Can we define a null expiry policy or disable it?
Is there a way to work around this since it doesn't sound like a minor change that would be in 9.x?
> JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
> ---------------------------------------------------------------------------------------------
>
> Key: ISPN-9853
> URL: https://issues.jboss.org/browse/ISPN-9853
> Project: Infinispan
> Issue Type: Bug
> Components: JCache
> Affects Versions: 9.4.5.Final
> Reporter: Martin Ross
> Priority: Major
> Labels: Performance
>
> While investigating slow read performance using JSR107 JCache on a embedded replicated cache configuration I think I have discovered a performance bug. Local reads were taking 1ms+ despite the fact that the data was successfully replicated into local cache. This problem only applies to 9.x as JCache was refactored heavily for 9.x to use functions. 8.x does not have this problem and we had to back level to this version.
> Calling JCache.get() on a key that has already been cached locally always results in a RPC call to the owning node.
> From JCache.java
> private final ReadWriteMap<K, V> rwMap;
> ...
> @Override
> public V get(final K key) {
> checkNotClosed();
> checkNotNull(key, "key");
> try {
> return readMap().eval(key, new ReadWithExpiry<>()).join();
> } catch (CompletionException e) {
> throw Exceptions.launderException(e);
> } catch (org.infinispan.commons.CacheException e) {
> throw Exceptions.launderException(e);
> }
> }
> ...
> private ReadWriteMap<K, V> readMap() {
> return configuration.isReadThrough() ? this.rwMap : rwMapSkipCacheLoad;
> }
> It looks like the ReadWriteMap and ReadWriteKeyCommand is causing the function to assumed to be having a side effect and causing BaseDistributionInterceptor.handleNonTxWriteCommand to be triggered.
> I have included the Yourkit profiler call stack below of our production instance showing the write.
> Call Tree Time (ms) Avg. Time (ms) Count Level
> PostController.java:139 org.infinispan.jcache.embedded.JCache.get(Object) 73072 22 3315 6
> JCache.java:186 org.infinispan.functional.impl.ReadWriteMapImpl.eval(Object, Function) 48409 14 3315 7
> ReadWriteMapImpl.java:56 org.infinispan.functional.impl.AbstractFunctionalMap.invokeAsync(InvocationContext, VisitableCommand) 36277 10 3319 8
> AbstractFunctionalMap.java:127 org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(InvocationContext, VisitableCommand) 36265 10 3319 9
> AsyncInterceptorChainImpl.java:234 org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(InvocationContext, VisitableCommand) 36257 10 3319 10
> DDAsyncInterceptor.java:50 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 36236 10 3319 11
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 36228 10 3319 12
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 36161 10 3319 13
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 36039 10 3319 14
> BaseAsyncInterceptor.java:56 org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContext, VisitableCommand) 36032 10 3319 15
> InvocationContextInterceptor.java:90 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(InvocationContext, VisitableCommand, InvocationExceptionFunction) 36013 10 3319 16
> BaseAsyncInterceptor.java:123 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35720 10 3319 17
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35714 10 3319 18
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 35687 10 3319 19
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 35645 10 3319 20
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35565 10 3319 21
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35433 10 3319 22
> CacheMgmtInterceptor.java:351 org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStatisticsReadWrite(InvocationContext, AbstractDataCommand) 35388 10 3319 23
> CacheMgmtInterceptor.java:327 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(InvocationContext, VisitableCommand, InvocationSuccessFunction) 35282 10 3319 24
> BaseAsyncInterceptor.java:74 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35098 10 3319 25
> ReadWriteKeyCommand.java:113 org.infinispan.statetransfer.StateTransferInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35090 10 3319 26
> StateTransferInterceptor.java:162 org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(InvocationContext, WriteCommand) 35009 10 3319 27
> StateTransferInterceptor.java:252 org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(InvocationContext, WriteCommand) 34987 10 3319 28
> StateTransferInterceptor.java:309 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(InvocationContext, VisitableCommand, InvocationFinallyFunction) 34919 10 3319 29
> BaseAsyncInterceptor.java:183 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34819 10 3319 30
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34781 10 3319 31
> AbstractLockingInterceptor.java:188 org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(InvocationContext, DataWriteCommand) 34749 10 3319 32
> NonTransactionalLockingInterceptor.java:40 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(InvocationContext, DataWriteCommand) 34624 10 3319 33
> AbstractLockingInterceptor.java:122 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 34048 10 3215 34
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34043 10 3215 35
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34036 10 3215 36
> EntryWrappingInterceptor.java:494 org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(InvocationContext, DataWriteCommand) 32977 10 3215 37
> EntryWrappingInterceptor.java:672 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(InvocationContext, VisitableCommand, InvocationSuccessAction) 32894 10 3215 38
> BaseAsyncInterceptor.java:98 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 32696 10 3215 39
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.distribution.NonTxDistributionInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 32688 10 3215 40
> NonTxDistributionInterceptor.java:142 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.handleNonTxWriteCommand(InvocationContext, AbstractDataWriteCommand) 32679 10 3215 41
> BaseDistributionInterceptor.java:270 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.invokeRemotely(InvocationContext, DataWriteCommand, Address) 32248 10 3215 42
> BaseDistributionInterceptor.java:896 org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(Address, ReplicableCommand, ResponseCollector, RpcOptions) 28258 8 3215 43
> RpcManagerImpl.java:147 org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(Address, ReplicableCommand, ResponseCollector, DeliverOrder, long, TimeUnit) 26454 8 3215 44
> JGroupsTransport.java:828 org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(Address, ReplicableCommand, long, DeliverOrder, boolean, boolean, boolean) 23983 7 3215 45
> JGroupsTransport.java:995 org.infinispan.remoting.transport.jgroups.JGroupsTransport.send(Message) 13824 4 3214 46
> I think this can be fixed by using ReadOnly map somehow? I am happy to make the fix but I
> would need some guidance here.
--
This message was sent by Atlassian Jira
(v7.12.1#712002)
7 years
[JBoss JIRA] (ISPN-9853) JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
by Radim Vansa (Jira)
[ https://issues.jboss.org/browse/ISPN-9853?page=com.atlassian.jira.plugin.... ]
Radim Vansa edited comment on ISPN-9853 at 1/8/19 7:31 AM:
-----------------------------------------------------------
Your analysis is correct. When the node is not the primary owner, despite not really writing anything (I guess you don't have ExpiryPolicy set) the operation is routed through primary owner as it *could* trigger update/removal. And I understand the problem, reading from replicated cache should not invoke any remote operations.
Ideally, we would call {{ExpiryPolicy.getExpiryForAccess}} on originator before we invoke the read, and call simple `infinispanCache.get()` if it does not require us to update the TTL. Regrettably the JCache TCK mandates that it's invoked once if and only if the entry is in the cache, and we can't know that ahead in the general (non-repl) case (without fetching the entry remotely). Previous version of JCache did not care about concurrency too much.
As a solution we could do a local-mode read if this node is a backup owner, invoke the ExpiryPolicy and if TTL is not updated, return the value, otherwise execute another operation that won't call ExpiryPolicy anymore. There's a problem with these two steps not being atomic - another write could be applied in the meantime and we have to combine the lifespan updates. The entry could be even removed and in that case we were not supposed to call ExpiryPolicy at all; JCache TCK does not test concurrency though so we wouldn't fail there.
was (Author: rvansa):
Your analysis is correct. When the node is not the primary owner, despite not really writing anything (I guess you don't have ExpiryPolicy set) the operation is routed through primary owner as it *could* trigger update/removal. And I understand the problem, reading from replicated cache should not invoke any remote operations.
Ideally, we would call {{ExpiryPolicy.getExpiryForAccess}} on originator before we invoke the read, and call simple `infinispanCache.get()` if it does not require us to update the TTL. Regrettably the JCache TCK mandates that it's invoked once if and only if the entry is in the cache, and we can't know that ahead (without fetching the entry remotely).
As a solution we could do a local-mode read if this node is a backup owner, invoke the ExpiryPolicy and if TTL is not updated, return the value, otherwise execute another operation that won't call ExpiryPolicy anymore. There's a problem with these two steps not being atomic - another write could be applied in the meantime and we have to combine the lifespan updates. The entry could be even removed and in that case we were not supposed to call ExpiryPolicy at all; JCache TCK does not test concurrency though so we wouldn't fail there.
> JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
> ---------------------------------------------------------------------------------------------
>
> Key: ISPN-9853
> URL: https://issues.jboss.org/browse/ISPN-9853
> Project: Infinispan
> Issue Type: Bug
> Components: JCache
> Affects Versions: 9.4.5.Final
> Reporter: Martin Ross
> Priority: Major
> Labels: Performance
>
> While investigating slow read performance using JSR107 JCache on a embedded replicated cache configuration I think I have discovered a performance bug. Local reads were taking 1ms+ despite the fact that the data was successfully replicated into local cache. This problem only applies to 9.x as JCache was refactored heavily for 9.x to use functions. 8.x does not have this problem and we had to back level to this version.
> Calling JCache.get() on a key that has already been cached locally always results in a RPC call to the owning node.
> From JCache.java
> private final ReadWriteMap<K, V> rwMap;
> ...
> @Override
> public V get(final K key) {
> checkNotClosed();
> checkNotNull(key, "key");
> try {
> return readMap().eval(key, new ReadWithExpiry<>()).join();
> } catch (CompletionException e) {
> throw Exceptions.launderException(e);
> } catch (org.infinispan.commons.CacheException e) {
> throw Exceptions.launderException(e);
> }
> }
> ...
> private ReadWriteMap<K, V> readMap() {
> return configuration.isReadThrough() ? this.rwMap : rwMapSkipCacheLoad;
> }
> It looks like the ReadWriteMap and ReadWriteKeyCommand is causing the function to assumed to be having a side effect and causing BaseDistributionInterceptor.handleNonTxWriteCommand to be triggered.
> I have included the Yourkit profiler call stack below of our production instance showing the write.
> Call Tree Time (ms) Avg. Time (ms) Count Level
> PostController.java:139 org.infinispan.jcache.embedded.JCache.get(Object) 73072 22 3315 6
> JCache.java:186 org.infinispan.functional.impl.ReadWriteMapImpl.eval(Object, Function) 48409 14 3315 7
> ReadWriteMapImpl.java:56 org.infinispan.functional.impl.AbstractFunctionalMap.invokeAsync(InvocationContext, VisitableCommand) 36277 10 3319 8
> AbstractFunctionalMap.java:127 org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(InvocationContext, VisitableCommand) 36265 10 3319 9
> AsyncInterceptorChainImpl.java:234 org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(InvocationContext, VisitableCommand) 36257 10 3319 10
> DDAsyncInterceptor.java:50 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 36236 10 3319 11
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 36228 10 3319 12
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 36161 10 3319 13
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 36039 10 3319 14
> BaseAsyncInterceptor.java:56 org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContext, VisitableCommand) 36032 10 3319 15
> InvocationContextInterceptor.java:90 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(InvocationContext, VisitableCommand, InvocationExceptionFunction) 36013 10 3319 16
> BaseAsyncInterceptor.java:123 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35720 10 3319 17
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35714 10 3319 18
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 35687 10 3319 19
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 35645 10 3319 20
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35565 10 3319 21
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35433 10 3319 22
> CacheMgmtInterceptor.java:351 org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStatisticsReadWrite(InvocationContext, AbstractDataCommand) 35388 10 3319 23
> CacheMgmtInterceptor.java:327 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(InvocationContext, VisitableCommand, InvocationSuccessFunction) 35282 10 3319 24
> BaseAsyncInterceptor.java:74 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35098 10 3319 25
> ReadWriteKeyCommand.java:113 org.infinispan.statetransfer.StateTransferInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35090 10 3319 26
> StateTransferInterceptor.java:162 org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(InvocationContext, WriteCommand) 35009 10 3319 27
> StateTransferInterceptor.java:252 org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(InvocationContext, WriteCommand) 34987 10 3319 28
> StateTransferInterceptor.java:309 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(InvocationContext, VisitableCommand, InvocationFinallyFunction) 34919 10 3319 29
> BaseAsyncInterceptor.java:183 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34819 10 3319 30
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34781 10 3319 31
> AbstractLockingInterceptor.java:188 org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(InvocationContext, DataWriteCommand) 34749 10 3319 32
> NonTransactionalLockingInterceptor.java:40 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(InvocationContext, DataWriteCommand) 34624 10 3319 33
> AbstractLockingInterceptor.java:122 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 34048 10 3215 34
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34043 10 3215 35
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34036 10 3215 36
> EntryWrappingInterceptor.java:494 org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(InvocationContext, DataWriteCommand) 32977 10 3215 37
> EntryWrappingInterceptor.java:672 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(InvocationContext, VisitableCommand, InvocationSuccessAction) 32894 10 3215 38
> BaseAsyncInterceptor.java:98 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 32696 10 3215 39
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.distribution.NonTxDistributionInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 32688 10 3215 40
> NonTxDistributionInterceptor.java:142 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.handleNonTxWriteCommand(InvocationContext, AbstractDataWriteCommand) 32679 10 3215 41
> BaseDistributionInterceptor.java:270 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.invokeRemotely(InvocationContext, DataWriteCommand, Address) 32248 10 3215 42
> BaseDistributionInterceptor.java:896 org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(Address, ReplicableCommand, ResponseCollector, RpcOptions) 28258 8 3215 43
> RpcManagerImpl.java:147 org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(Address, ReplicableCommand, ResponseCollector, DeliverOrder, long, TimeUnit) 26454 8 3215 44
> JGroupsTransport.java:828 org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(Address, ReplicableCommand, long, DeliverOrder, boolean, boolean, boolean) 23983 7 3215 45
> JGroupsTransport.java:995 org.infinispan.remoting.transport.jgroups.JGroupsTransport.send(Message) 13824 4 3214 46
> I think this can be fixed by using ReadOnly map somehow? I am happy to make the fix but I
> would need some guidance here.
--
This message was sent by Atlassian Jira
(v7.12.1#712002)
7 years
[JBoss JIRA] (ISPN-9853) JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
by Radim Vansa (Jira)
[ https://issues.jboss.org/browse/ISPN-9853?page=com.atlassian.jira.plugin.... ]
Radim Vansa edited comment on ISPN-9853 at 1/8/19 7:30 AM:
-----------------------------------------------------------
Your analysis is correct. When the node is not the primary owner, despite not really writing anything (I guess you don't have ExpiryPolicy set) the operation is routed through primary owner as it *could* trigger update/removal. And I understand the problem, reading from replicated cache should not invoke any remote operations.
Ideally, we would call {{ExpiryPolicy.getExpiryForAccess}} on originator before we invoke the read, and call simple `infinispanCache.get()` if it does not require us to update the TTL. Regrettably the JCache TCK mandates that it's invoked once if and only if the entry is in the cache, and we can't know that ahead (without fetching the entry remotely).
As a solution we could do a local-mode read if this node is a backup owner, invoke the ExpiryPolicy and if TTL is not updated, return the value, otherwise execute another operation that won't call ExpiryPolicy anymore. There's a problem with these two steps not being atomic - another write could be applied in the meantime and we have to combine the lifespan updates. The entry could be even removed and in that case we were not supposed to call ExpiryPolicy at all; JCache TCK does not test concurrency though so we wouldn't fail there.
was (Author: rvansa):
Your analysis is correct. When the node is not the primary owner, despite not really writing anything (I guess you don't have ExpiryPolicy set) the operation is routed through primary owner as it *could* trigger removal. And I understand the problem, reading from replicated cache should not invoke any remote operations.
Ideally, we would call {{ExpiryPolicy.getExpiryForAccess}} on originator before we invoke the read, and call simple `infinispanCache.get()` if it does not require us to update the TTL. Regrettably the JCache TCK mandates that it's invoked once if and only if the entry is in the cache, and we can't know that ahead (without fetching the entry remotely).
As a solution we could do a local-mode read if this node is a backup owner, invoke the ExpiryPolicy and if TTL is not updated, return the value, otherwise execute another operation that won't call ExpiryPolicy anymore. There's a problem with these two steps not being atomic - another write could be applied in the meantime and we have to combine the lifespan updates. The entry could be even removed and in that case we were not supposed to call ExpiryPolicy at all; JCache TCK does not test concurrency though so we wouldn't fail there.
> JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
> ---------------------------------------------------------------------------------------------
>
> Key: ISPN-9853
> URL: https://issues.jboss.org/browse/ISPN-9853
> Project: Infinispan
> Issue Type: Bug
> Components: JCache
> Affects Versions: 9.4.5.Final
> Reporter: Martin Ross
> Priority: Major
> Labels: Performance
>
> While investigating slow read performance using JSR107 JCache on a embedded replicated cache configuration I think I have discovered a performance bug. Local reads were taking 1ms+ despite the fact that the data was successfully replicated into local cache. This problem only applies to 9.x as JCache was refactored heavily for 9.x to use functions. 8.x does not have this problem and we had to back level to this version.
> Calling JCache.get() on a key that has already been cached locally always results in a RPC call to the owning node.
> From JCache.java
> private final ReadWriteMap<K, V> rwMap;
> ...
> @Override
> public V get(final K key) {
> checkNotClosed();
> checkNotNull(key, "key");
> try {
> return readMap().eval(key, new ReadWithExpiry<>()).join();
> } catch (CompletionException e) {
> throw Exceptions.launderException(e);
> } catch (org.infinispan.commons.CacheException e) {
> throw Exceptions.launderException(e);
> }
> }
> ...
> private ReadWriteMap<K, V> readMap() {
> return configuration.isReadThrough() ? this.rwMap : rwMapSkipCacheLoad;
> }
> It looks like the ReadWriteMap and ReadWriteKeyCommand is causing the function to assumed to be having a side effect and causing BaseDistributionInterceptor.handleNonTxWriteCommand to be triggered.
> I have included the Yourkit profiler call stack below of our production instance showing the write.
> Call Tree Time (ms) Avg. Time (ms) Count Level
> PostController.java:139 org.infinispan.jcache.embedded.JCache.get(Object) 73072 22 3315 6
> JCache.java:186 org.infinispan.functional.impl.ReadWriteMapImpl.eval(Object, Function) 48409 14 3315 7
> ReadWriteMapImpl.java:56 org.infinispan.functional.impl.AbstractFunctionalMap.invokeAsync(InvocationContext, VisitableCommand) 36277 10 3319 8
> AbstractFunctionalMap.java:127 org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(InvocationContext, VisitableCommand) 36265 10 3319 9
> AsyncInterceptorChainImpl.java:234 org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(InvocationContext, VisitableCommand) 36257 10 3319 10
> DDAsyncInterceptor.java:50 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 36236 10 3319 11
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 36228 10 3319 12
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 36161 10 3319 13
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 36039 10 3319 14
> BaseAsyncInterceptor.java:56 org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContext, VisitableCommand) 36032 10 3319 15
> InvocationContextInterceptor.java:90 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(InvocationContext, VisitableCommand, InvocationExceptionFunction) 36013 10 3319 16
> BaseAsyncInterceptor.java:123 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35720 10 3319 17
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35714 10 3319 18
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 35687 10 3319 19
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 35645 10 3319 20
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35565 10 3319 21
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35433 10 3319 22
> CacheMgmtInterceptor.java:351 org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStatisticsReadWrite(InvocationContext, AbstractDataCommand) 35388 10 3319 23
> CacheMgmtInterceptor.java:327 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(InvocationContext, VisitableCommand, InvocationSuccessFunction) 35282 10 3319 24
> BaseAsyncInterceptor.java:74 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35098 10 3319 25
> ReadWriteKeyCommand.java:113 org.infinispan.statetransfer.StateTransferInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35090 10 3319 26
> StateTransferInterceptor.java:162 org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(InvocationContext, WriteCommand) 35009 10 3319 27
> StateTransferInterceptor.java:252 org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(InvocationContext, WriteCommand) 34987 10 3319 28
> StateTransferInterceptor.java:309 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(InvocationContext, VisitableCommand, InvocationFinallyFunction) 34919 10 3319 29
> BaseAsyncInterceptor.java:183 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34819 10 3319 30
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34781 10 3319 31
> AbstractLockingInterceptor.java:188 org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(InvocationContext, DataWriteCommand) 34749 10 3319 32
> NonTransactionalLockingInterceptor.java:40 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(InvocationContext, DataWriteCommand) 34624 10 3319 33
> AbstractLockingInterceptor.java:122 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 34048 10 3215 34
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34043 10 3215 35
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34036 10 3215 36
> EntryWrappingInterceptor.java:494 org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(InvocationContext, DataWriteCommand) 32977 10 3215 37
> EntryWrappingInterceptor.java:672 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(InvocationContext, VisitableCommand, InvocationSuccessAction) 32894 10 3215 38
> BaseAsyncInterceptor.java:98 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 32696 10 3215 39
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.distribution.NonTxDistributionInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 32688 10 3215 40
> NonTxDistributionInterceptor.java:142 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.handleNonTxWriteCommand(InvocationContext, AbstractDataWriteCommand) 32679 10 3215 41
> BaseDistributionInterceptor.java:270 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.invokeRemotely(InvocationContext, DataWriteCommand, Address) 32248 10 3215 42
> BaseDistributionInterceptor.java:896 org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(Address, ReplicableCommand, ResponseCollector, RpcOptions) 28258 8 3215 43
> RpcManagerImpl.java:147 org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(Address, ReplicableCommand, ResponseCollector, DeliverOrder, long, TimeUnit) 26454 8 3215 44
> JGroupsTransport.java:828 org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(Address, ReplicableCommand, long, DeliverOrder, boolean, boolean, boolean) 23983 7 3215 45
> JGroupsTransport.java:995 org.infinispan.remoting.transport.jgroups.JGroupsTransport.send(Message) 13824 4 3214 46
> I think this can be fixed by using ReadOnly map somehow? I am happy to make the fix but I
> would need some guidance here.
--
This message was sent by Atlassian Jira
(v7.12.1#712002)
7 years
[JBoss JIRA] (ISPN-9853) JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
by Radim Vansa (Jira)
[ https://issues.jboss.org/browse/ISPN-9853?page=com.atlassian.jira.plugin.... ]
Radim Vansa commented on ISPN-9853:
-----------------------------------
Your analysis is correct. When the node is not the primary owner, despite not really writing anything (I guess you don't have ExpiryPolicy set) the operation is routed through primary owner as it *could* trigger removal. And I understand the problem, reading from replicated cache should not invoke any remote operations.
Ideally, we would call {{ExpiryPolicy.getExpiryForAccess}} on originator before we invoke the read, and call simple `infinispanCache.get()` if it does not require us to update the TTL. Regrettably the JCache TCK mandates that it's invoked once if and only if the entry is in the cache, and we can't know that ahead (without fetching the entry remotely).
As a solution we could do a local-mode read if this node is a backup owner, invoke the ExpiryPolicy and if TTL is not updated, return the value, otherwise execute another operation that won't call ExpiryPolicy anymore. There's a problem with these two steps not being atomic - another write could be applied in the meantime and we have to combine the lifespan updates. The entry could be even removed and in that case we were not supposed to call ExpiryPolicy at all; JCache TCK does not test concurrency though so we wouldn't fail there.
> JSR107 JCache makes null write remote call for get() operation from 9.x with replicated cache
> ---------------------------------------------------------------------------------------------
>
> Key: ISPN-9853
> URL: https://issues.jboss.org/browse/ISPN-9853
> Project: Infinispan
> Issue Type: Bug
> Components: JCache
> Affects Versions: 9.4.5.Final
> Reporter: Martin Ross
> Priority: Major
> Labels: Performance
>
> While investigating slow read performance using JSR107 JCache on a embedded replicated cache configuration I think I have discovered a performance bug. Local reads were taking 1ms+ despite the fact that the data was successfully replicated into local cache. This problem only applies to 9.x as JCache was refactored heavily for 9.x to use functions. 8.x does not have this problem and we had to back level to this version.
> Calling JCache.get() on a key that has already been cached locally always results in a RPC call to the owning node.
> From JCache.java
> private final ReadWriteMap<K, V> rwMap;
> ...
> @Override
> public V get(final K key) {
> checkNotClosed();
> checkNotNull(key, "key");
> try {
> return readMap().eval(key, new ReadWithExpiry<>()).join();
> } catch (CompletionException e) {
> throw Exceptions.launderException(e);
> } catch (org.infinispan.commons.CacheException e) {
> throw Exceptions.launderException(e);
> }
> }
> ...
> private ReadWriteMap<K, V> readMap() {
> return configuration.isReadThrough() ? this.rwMap : rwMapSkipCacheLoad;
> }
> It looks like the ReadWriteMap and ReadWriteKeyCommand is causing the function to assumed to be having a side effect and causing BaseDistributionInterceptor.handleNonTxWriteCommand to be triggered.
> I have included the Yourkit profiler call stack below of our production instance showing the write.
> Call Tree Time (ms) Avg. Time (ms) Count Level
> PostController.java:139 org.infinispan.jcache.embedded.JCache.get(Object) 73072 22 3315 6
> JCache.java:186 org.infinispan.functional.impl.ReadWriteMapImpl.eval(Object, Function) 48409 14 3315 7
> ReadWriteMapImpl.java:56 org.infinispan.functional.impl.AbstractFunctionalMap.invokeAsync(InvocationContext, VisitableCommand) 36277 10 3319 8
> AbstractFunctionalMap.java:127 org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(InvocationContext, VisitableCommand) 36265 10 3319 9
> AsyncInterceptorChainImpl.java:234 org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(InvocationContext, VisitableCommand) 36257 10 3319 10
> DDAsyncInterceptor.java:50 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 36236 10 3319 11
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 36228 10 3319 12
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 36161 10 3319 13
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 36039 10 3319 14
> BaseAsyncInterceptor.java:56 org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContext, VisitableCommand) 36032 10 3319 15
> InvocationContextInterceptor.java:90 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(InvocationContext, VisitableCommand, InvocationExceptionFunction) 36013 10 3319 16
> BaseAsyncInterceptor.java:123 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35720 10 3319 17
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.DDAsyncInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35714 10 3319 18
> DDAsyncInterceptor.java:207 org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(InvocationContext, VisitableCommand) 35687 10 3319 19
> DDAsyncInterceptor.java:54 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 35645 10 3319 20
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35565 10 3319 21
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35433 10 3319 22
> CacheMgmtInterceptor.java:351 org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStatisticsReadWrite(InvocationContext, AbstractDataCommand) 35388 10 3319 23
> CacheMgmtInterceptor.java:327 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(InvocationContext, VisitableCommand, InvocationSuccessFunction) 35282 10 3319 24
> BaseAsyncInterceptor.java:74 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 35098 10 3319 25
> ReadWriteKeyCommand.java:113 org.infinispan.statetransfer.StateTransferInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 35090 10 3319 26
> StateTransferInterceptor.java:162 org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(InvocationContext, WriteCommand) 35009 10 3319 27
> StateTransferInterceptor.java:252 org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(InvocationContext, WriteCommand) 34987 10 3319 28
> StateTransferInterceptor.java:309 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(InvocationContext, VisitableCommand, InvocationFinallyFunction) 34919 10 3319 29
> BaseAsyncInterceptor.java:183 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34819 10 3319 30
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34781 10 3319 31
> AbstractLockingInterceptor.java:188 org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(InvocationContext, DataWriteCommand) 34749 10 3319 32
> NonTransactionalLockingInterceptor.java:40 org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(InvocationContext, DataWriteCommand) 34624 10 3319 33
> AbstractLockingInterceptor.java:122 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(InvocationContext, VisitableCommand) 34048 10 3215 34
> BaseAsyncInterceptor.java:54 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 34043 10 3215 35
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 34036 10 3215 36
> EntryWrappingInterceptor.java:494 org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(InvocationContext, DataWriteCommand) 32977 10 3215 37
> EntryWrappingInterceptor.java:672 org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(InvocationContext, VisitableCommand, InvocationSuccessAction) 32894 10 3215 38
> BaseAsyncInterceptor.java:98 org.infinispan.commands.functional.ReadWriteKeyCommand.acceptVisitor(InvocationContext, Visitor) 32696 10 3215 39
> ReadWriteKeyCommand.java:113 org.infinispan.interceptors.distribution.NonTxDistributionInterceptor.visitReadWriteKeyCommand(InvocationContext, ReadWriteKeyCommand) 32688 10 3215 40
> NonTxDistributionInterceptor.java:142 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.handleNonTxWriteCommand(InvocationContext, AbstractDataWriteCommand) 32679 10 3215 41
> BaseDistributionInterceptor.java:270 org.infinispan.interceptors.distribution.BaseDistributionInterceptor.invokeRemotely(InvocationContext, DataWriteCommand, Address) 32248 10 3215 42
> BaseDistributionInterceptor.java:896 org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(Address, ReplicableCommand, ResponseCollector, RpcOptions) 28258 8 3215 43
> RpcManagerImpl.java:147 org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(Address, ReplicableCommand, ResponseCollector, DeliverOrder, long, TimeUnit) 26454 8 3215 44
> JGroupsTransport.java:828 org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(Address, ReplicableCommand, long, DeliverOrder, boolean, boolean, boolean) 23983 7 3215 45
> JGroupsTransport.java:995 org.infinispan.remoting.transport.jgroups.JGroupsTransport.send(Message) 13824 4 3214 46
> I think this can be fixed by using ReadOnly map somehow? I am happy to make the fix but I
> would need some guidance here.
--
This message was sent by Atlassian Jira
(v7.12.1#712002)
7 years