0

我在使用 JDK8 的 IBM Liberty 应用服务器上运行的 Java 应用程序中使用 Infinispan HOTROD。

HOTROD客户端（lib 12.1.11.Final-redhat-00001版本）通过`实现

org.infinispan.jcache.remote.JCachingProvider：

@PostConstruct
private void setUp() {
      LOGGER.info("START [setUp] CACHE");
     
      File conf = new File(System.getenv("CLIENT_HOTROD_FILE_PATH"));
     
      URI uri = conf.toURI();
    
      // Retrieve the system wide cache manager via org.infinispan.jcache.remote.JCachingProvider
      javax.cache.CacheManager cacheManager = Caching.getCachingProvider("org.infinispan.jcache.remote.JCachingProvider")
            .getCacheManager(uri, this.getClass().getClassLoader(), null);
      
      this.cache = cacheManager.getCache(DATAGRIDKEY);
     
      LOGGER.info("END [setUp] cache " + this.cache.getName() );
  }

HOT-ROD客户端配置文件：

infinispan.client.hotrod.server_list=server1.x.xx.xxx:11222;server2.x.xx.xxx:11222;server3..x.xx.xxx:11222;server4..x.xx.xxx:11222
infinispan.client.hotrod.auth_username=user-app
infinispan.client.hotrod.auth_password=password
infinispan.client.hotrod.auth_realm=default
infinispan.client.hotrod.sasl_mechanism=SCRAM-SHA-512
infinispan.client.hotrod.client_intelligence=HASH_DISTRIBUTION_AWARE

可用的 HOT-ROD 客户端配置属性

否则配置服务器REDHAT Data Grid（8.2.3版本）如下：

{
  "distributed-cache": {
    "mode": "ASYNC",
    "remote-timeout": 17500,
    "state-transfer": {
      "timeout": 60000
    },
    "encoding": {
      "key": {
        "media-type": "text/plain"
      },
      "value": {
        "media-type": "application/x-protostream"
      }
    },
    "locking": {
      "concurrency-level": 1000,
      "acquire-timeout": 15000,
      "striping": false
    },
    "statistics": true
  }
}

有时当应用程序对日志应用程序端有一些请求时，会发生 java.net.SocketTimeoutException: GetOperation 问题，如下面的堆栈跟踪：

[2/15/22 17:24:39:445 CET] 00000573 HOTROD W org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation handleException ISPN004098: Closing connection [id: 0x9a1a8fb2, L:/10.0.20.160:55295 ! R:10.0.18.97/10.0.18.97:11222] due to transport error java.net.SocketTimeoutException: GetOperation{Cache-Name-Test, key=[B0x4A6C636F6D2E6475636174692E77612E..[110], flags=1, connection=10.0.18.97/10.0.18.97:11222} timed out after 60000 ms
at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:185)
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.lang.Thread.run(Thread.java:822)

当应用程序收到大量 GET KEY 请求时，此问题更为频繁，但有时在非大量加载请求期间会出现此问题。

你能知道如何解决这个问题吗？你知道有什么建议吗？

谢谢

4

2 回答 2

0

我尝试编辑客户端配置 HOT-ROD 以了解客户端的行为，下面我想总结一下新的配置更改：

infinispan.client.hotrod.server_list=server1:11222;server2:11222;server3:11222;server4:11222
infinispan.client.hotrod.auth_username=user-app
infinispan.client.hotrod.auth_password=password
infinispan.client.hotrod.auth_realm=default
infinispan.client.hotrod.sasl_mechanism=SCRAM-SHA-512

infinispan.client.hotrod.socket_timeout=15000
infinispan.client.hotrod.connect_timeout=60000
infinispan.client.hotrod.max_retries=5

# Connection pool
infinispan.client.hotrod.connection_pool.max_active=50
infinispan.client.hotrod.connection_pool.exhausted_action=WAIT
infinispan.client.hotrod.connection_pool.max_wait=20000
infinispan.client.hotrod.connection_pool.min_idle=10
#default is 1800000
infinispan.client.hotrod.connection_pool.min_evictable_idle_time=600000
infinispan.client.hotrod.connection_pool.max_pending_requests=846

我注意到infinispan.client.hotrod.socket_timeout=15000 毫秒的变化。Whatching 应用程序日志文件我看到了同样的错误，但目前，而不是 60000 毫秒，是 socketTimeoutException 到 15000 毫秒。使用新设置，即使记录了异常，线程请求也会成功完成线程请求。

我想理解到池中有时似乎有连接死亡，客户端搜索并尝试另一个连接到池中重试 GetOperation。

正如在org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation类代码中写入库热棒：

/**
 * Base class for all the operations that need retry logic: if the operation fails due to connection problems, try with
 * another available connection.
 *
 * @author Mircea.Markus@jboss.com
 * @since 4.1
 */

简而言之，我需要保持连接到池中的活动连接，我不知道哪个是 Data Grid 客户端 HOT-ROD 的属性。下一步我想尝试设置infinispan.client.hotrod.tcp_keep_alive=true 以测试行为是否改变，之后我将更新帖子。

于 2022-02-17T11:18:29.287 回答
0

考虑到重试操作和超时之间的合理权衡，我尝试更改一些配置属性。

HOT-ROD 客户端配置：

infinispan.client.hotrod.server_list=server1:11222;server2:11222;server3:11222;server4:11222
infinispan.client.hotrod.auth_username=app-user
infinispan.client.hotrod.auth_password=password
infinispan.client.hotrod.auth_realm=default
infinispan.client.hotrod.sasl_mechanism=SCRAM-SHA-512


infinispan.client.hotrod.socket_timeout=5000
infinispan.client.hotrod.connect_timeout=20000
infinispan.client.hotrod.max_retries=5

# Connection pool
infinispan.client.hotrod.connection_pool.max_active=100
infinispan.client.hotrod.connection_pool.exhausted_action=WAIT
infinispan.client.hotrod.connection_pool.max_wait=20000
infinispan.client.hotrod.connection_pool.min_idle=50
#default is 1800000
infinispan.client.hotrod.connection_pool.min_evictable_idle_time=600000
infinispan.client.hotrod.connection_pool.max_pending_requests=846

infinispan.client.hotrod.client_intelligence=HASH_DISTRIBUTION_AWARE
infinispan.client.hotrod.force_return_values=false

#default is false
infinispan.client.hotrod.tcp_keep_alive=true

所做的更改是：

  • infinispan.client.hotrod.socket_timeout减少到 5000ms
  • infinispan.client.hotrod.connection_pool.min_idle增加到 50
  • infinispan.client.hotrod.connect_timeout减少到 20000ms
  • infinispan.client.hotrod.max_retries 减少到 5
  • infinispan.client.hotrod.connection_pool.max_active增加到 100

在 QA 环境和日志应用程序中测试，我可以说 HOT-ROD 客户端在获得 4 RetryOnFailureOperations 后很少

java.net.SocketTimeoutException: GetOperation`timed out after 5000 ms

发生在updateTopologyInfo动作客户端 HOT-ROD 端。这个 HOT-ROD 客户端策略似乎只有从异步线程生成的日志在后台运行以检查套接字是否仍然存在。

[2/23/22 9:06:12:923 CET] 000001ab HOTROD        W org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation handleException ISPN004098: Closing connection [id: 0xa5345361, L:/10.0.20.160
:44021 - R:10.0.18.102/10.0.18.102:11222] due to transport error
                                 java.net.SocketTimeoutException: GetOperation{MY-CACHE, key=[B0x4A4B636F6D2E6475636174692E77612E..[77], flags=1, connection=10.0.18.102/10.0.18.102:11222} timed out a
fter 5000 ms
        at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:185)
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(Thread.java:822)

[2/23/22 9:06:17:924 CET] 000001a5 HOTROD        W org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation handleException ISPN004098: Closing connection [id: 0x54dacb9b, L:/10.0.20.160:42115 - R:10.0.18.97/10.0.18.97:11222] due to transport error
                                 java.net.SocketTimeoutException: GetOperation{MY-CACHE, key=[B0x4A4B636F6D2E6475636174692E77612E..[77], flags=1, connection=10.0.18.97/10.0.18.97:11222} timed out after 5000 ms
        at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:185)
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(Thread.java:822)

[2/23/22 9:06:22:925 CET] 000001a5 HOTROD        W org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation handleException ISPN004098: Closing connection [id: 0xe3e6fd98, L:/10.0.20.160:43629 - R:10.0.18.101/10.0.18.101:11222] due to transport error
                                 java.net.SocketTimeoutException: GetOperation{MY-CACHE, key=[B0x4A4B636F6D2E6475636174692E77612E..[77], flags=1, connection=10.0.18.101/10.0.18.101:11222} timed out after 5000 ms
                                     at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:185)
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(Thread.java:822)

[2/23/22 9:06:27:926 CET] 000001ab HOTROD        W org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation handleException ISPN004098: Closing connection [id: 0x52a4bd4a, L:/10.0.20.160:32912 - R:10.0.18.96/10.0.18.96:11222] due to transport error
                                 java.net.SocketTimeoutException: GetOperation{MY-CACHE, key=[B0x4A4B636F6D2E6475636174692E77612E..[77], flags=1, connection=10.0.18.96/10.0.18.96:11222} timed out after 5000 ms
        at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:185)
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(Thread.java:822)

[2/23/22 9:06:27:927 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(server4:11222), adding to the pool.
[2/23/22 9:06:27:927 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(server2:11222), adding to the pool.
[2/23/22 9:06:27:928 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(server3:11222), adding to the pool.
[2/23/22 9:06:27:928 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(server1:11222), adding to the pool.
[2/23/22 9:06:27:928 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.101:11222), removing from the pool.
[2/23/22 9:06:27:928 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.102:11222), removing from the pool.
[2/23/22 9:06:27:928 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.96:11222), removing from the pool.
[2/23/22 9:06:27:929 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.97:11222), removing from the pool.
[2/23/22 9:06:27:929 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.101:11222), removing from the pool.
[2/23/22 9:06:27:929 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.102:11222), removing from the pool.
[2/23/22 9:06:27:929 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.96:11222), removing from the pool.
[2/23/22 9:06:27:929 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(10.0.18.97:11222), removing from the pool.
[2/23/22 9:06:28:059 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.protocol.Codec20 readNewTopologyAndHash ISPN004006: Server sent new topology view (id=108, age=0) containing 4 addresses: [10.0.18.101:11222, 10.0.18.102:11222, 10.0.18.96:11222, 10.0.18.97:11222]
[2/23/22 9:06:28:060 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(10.0.18.101:11222), adding to the pool.
[2/23/22 9:06:28:062 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(10.0.18.102:11222), adding to the pool.
[2/23/22 9:06:28:063 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(10.0.18.96:11222), adding to the pool.
[2/23/22 9:06:28:065 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory updateTopologyInfo ISPN004014: New server added(10.0.18.97:11222), adding to the pool.
[2/23/22 9:06:28:082 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(server4:11222), removing from the pool.
[2/23/22 9:06:28:083 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(server2:11222), removing from the pool.
[2/23/22 9:06:28:083 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(server3:11222), removing from the pool.
[2/23/22 9:06:28:083 CET] 000001ab HOTROD        I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory closeChannelPools ISPN004016: Server not in cluster anymore(server1:11222), removing from the pool.
16576429:[2/23/22 9:06:33:056 CET] 000001ab HOTROD        W org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation handleException ISPN004098: Closing connection [id: 0x4299851e, L:/10.0.20.160:45567 ! R:server4/10.0.18.102:11222] due to transport error
16576703-                                 java.net.SocketTimeoutException: GetOperation{MY-CACHE, key=[B0x4A4B636F6D2E6475636174692E77612E..[77], flags=1, connection=server4/10.0.18.102:11222} timed out after 5000 ms
16576925-       at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:185)
16577020-       at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
16577090-       at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
16577173-       at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
16577268-       at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
16577371-       at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
16577442-       at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
16577539-       at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
16577617-       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
16577701-       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
16577785-       at java.lang.Thread.run(Thread.java:822)

笔记

HOTROD 字后的字符表示 LOG 级别

例子：

[2/23/22 9:06:28:083 CET] 000001ab HOTROD I org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory

  • 我 = 信息
  • W = 警告
  • D = 调试
  • E = 错误
于 2022-02-23T09:15:34.397 回答