大body压测，CPU不高，大量CLOSE_WAIT

fengfu222 commented 8 months ago

使用5台机器构成mqtt集群，机器配置均为128G 内存 32核CPU，局域网环境，网络资源足够，使用28万连接的200B payload，7万连接100K的payload，大小包均为每5秒发送一次数据，持续运行30分钟后，服务器出现大量CLOSE_WAIT tcp连接，客户端也无法连接mqtt，整体过程负载不高只使用了1/3的负载。配置参数在下面有，我们期望压测将CPU打上去，是集群能够承受更多的大payload连接。

PUB Client :

MQTT Connection:
- Clean Session: true
MQTT Pub:
- Topic: 100个topic
- QoS: 0
- Retain: false SUB Client 无SUB

Logs 无错误日志

HOST

CPU: 16
Memory: 32G
Number: 7

OS(please complete the following information):

OS: centos 7
Kernel Version [e.g. 5.6]
- Kernel Specific Settings: [e.g. TCP, FD, etc]

JVM:

Version: 17
Arguments: java -Xms32042m -Xmx64084m -XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=500m -XX:MaxDirectMemorySize=40318643400 -server -XX:MaxInlineLevel=15 -Djava.awt.headless=true -XX:+UnlockExperimentalVMOptions -XX:+UnlockDiagnosticVMOptions -XX:+UseZGC -XX:ZAllocationSpikeTolerance=5 -Xlog:async -Xlog:gc:file=/data2/bifromq-2.0.1/bin/../logs/gc-%t.log:time,tid,tags:filecount=5,filesize=50m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data2/bifromq-2.0.1/bin/../logs -Dinbox_store_range_voter_count=5 -Ddist_worker_range_voter_count=5 -Dretain_store_range_voter_count=5 -cp /data2/bifromq-2.0.1/bin/../lib/* -DLOG_DIR=/data2/bifromq-2.0.1/bin/../logs -DCONF_DIR=/data2/bifromq-2.0.1/bin/../conf -DDATA_DIR=/data2/bifromq-2.0.1/bin/../data -DBIND_ADDR=10.89.144.26 -Dlogback.configurationFile=/data2/bifromq-2.0.1/bin/../conf/logback.xml -Dpf4j.pluginsDir=/data2/bifromq-2.0.1/bin/../plugins com.baidu.bifromq.starter.StandaloneStarter -c /data2/bifromq-2.0.1/bin/../conf/standalone.yml

BifroMQ

Version: bifromq-2.0.1
Non-Default Configuration:

mqttServerConfig: tcpListener: port: 1883 connTimeoutSec: 5 maxConnPerSec: 3000 defaultKeepAliveSec: 60

tlsListener: enable: true host: port: 8883 sslConfig: certFile: server.crt keyFile: server_pkcs8.key trustCertsFile: root.crt clientAuth: REQUIRE rpcClientConfig: workerThreads: 100

rpcServerConfig: workerThreads: 100

baseKVRpcServerConfig: workerThreads: 100

stateStoreConfig: queryThreads: 100 bgWorkerThreads: 100 tickerThreads: 10 distWorkerConfig: queryPipelinePerStore: 10000 compactWALThreshold: 5000 inboxStoreConfig: queryPipelinePerStore: 10000

Additional context 集群为5台

popduke commented 8 months ago

1，Server启动时会在info.log里输出全量的设置，能否提供一下? 2，有没有尝试过压测单节点的情况？ 3，把logback.xml里的DemoEventLogger调整成debug，看下event.log压测过程中连接断开的原因是什么?

fengfu222 commented 8 months ago

1，Server启动时会在info.log里输出全量的设置，能否提供一下? 2，有没有尝试过压测单节点的情况？ 3，把logback.xml里的DemoEventLogger调整成debug，看下event.log压测过程中连接断开的原因是什么?

1 --- bootstrap: true clusterConfig: env: "Test" host: "10.89.144.26" port: 8899 seedEndpoints: "10.89.144.129:8899,10.89.144.26:8899,10.89.144.62:8899,10.89.144.69:8899,10.89.144.121:8899" mqttServerConfig: connTimeoutSec: 5 maxConnPerSec: 3000 maxDisconnPerSec: 1000 maxMsgByteSize: 262144 maxResendTimes: 5 maxConnBandwidth: 524288 defaultKeepAliveSec: 60 qos2ConfirmWindowSec: 5 bossELGThreads: 1 workerELGThreads: 16 tcpListener: enable: true host: "0.0.0.0" port: 1883 tlsListener: enable: true host: "0.0.0.0" port: 8883 sslConfig: certFile: "server.crt" keyFile: "server_pkcs8.key" trustCertsFile: "root.crt" clientAuth: "REQUIRE" wsListener: enable: true host: "0.0.0.0" port: 8080 wsPath: "/mqtt" wssListener: enable: false host: "0.0.0.0" port: 8443 wsPath: "/mqtt" rpcClientConfig: workerThreads: 100 rpcServerConfig: host: "10.89.144.26" port: 0 workerThreads: 100 baseKVRpcServerConfig: port: 0 stateStoreConfig: queryThreads: 100 tickerThreads: 10 bgWorkerThreads: 100 distWorkerConfig: queryPipelinePerStore: 10000 compactWALThreshold: 5000 dataEngineConfig: type: "rocksdb" dataPathRoot: "" manualCompaction: false compactMinTombstoneKeys: 200000 compactMinTombstoneRanges: 100000 compactTombstoneRatio: 0.3 asyncWALFlush: false fsyncWAL: false walEngineConfig: type: "rocksdb" dataPathRoot: "" manualCompaction: true compactMinTombstoneKeys: 2500 compactMinTombstoneRanges: 2 compactTombstoneRatio: 0.3 asyncWALFlush: false fsyncWAL: false balanceConfig: scheduleIntervalInMs: 5000 balancers:

"com.baidu.bifromq.dist.worker.balance.ReplicaCntBalancerFactory" inboxStoreConfig: queryPipelinePerStore: 10000 compactWALThreshold: 2500 gcIntervalSeconds: 600 purgeDelaySeconds: 180 dataEngineConfig: type: "rocksdb" dataPathRoot: "" manualCompaction: false compactMinTombstoneKeys: 200000 compactMinTombstoneRanges: 100000 compactTombstoneRatio: 0.3 asyncWALFlush: false fsyncWAL: false walEngineConfig: type: "rocksdb" dataPathRoot: "" manualCompaction: true compactMinTombstoneKeys: 2500 compactMinTombstoneRanges: 2 compactTombstoneRatio: 0.3 asyncWALFlush: false fsyncWAL: false balanceConfig: scheduleIntervalInMs: 5000 balancers:
"com.baidu.bifromq.inbox.store.balance.ReplicaCntBalancerFactory"
"com.baidu.bifromq.inbox.store.balance.RangeSplitBalancerFactory"
"com.baidu.bifromq.inbox.store.balance.RangeLeaderBalancerFactory" retainStoreConfig: queryPipelinePerStore: 100 compactWALThreshold: 2500 gcIntervalSeconds: 600 dataEngineConfig: type: "rocksdb" dataPathRoot: "" manualCompaction: false compactMinTombstoneKeys: 200000 compactMinTombstoneRanges: 100000 compactTombstoneRatio: 0.3 asyncWALFlush: false fsyncWAL: false walEngineConfig: type: "rocksdb" dataPathRoot: "" manualCompaction: true compactMinTombstoneKeys: 5000 compactMinTombstoneRanges: 2 compactTombstoneRatio: 0.3 asyncWALFlush: false fsyncWAL: false balanceConfig: scheduleIntervalInMs: 5000 balancers:
"com.baidu.bifromq.retain.store.balance.ReplicaCntBalancerFactory" apiServerConfig: enable: true httpPort: 8091 apiBossThreads: 1 apiWorkerThreads: 2 httpsListenerConfig: enable: false port: 8090

2 单节点压测我们用的是小body，可以满足要求

3 bifromq1 bifromq2 bifromq3

fengfu222 commented 8 months ago

1，Server启动时会在info.log里输出全量的设置，能否提供一下? 2，有没有尝试过压测单节点的情况？ 3，把logback.xml里的DemoEventLogger调整成debug，看下event.log压测过程中连接断开的原因是什么?

我们中间试过一次，配置 dist和inbox的dataEngine为memory，CPU是可以打上去的，而且能够支撑我们的压测完成，集群一直都很正常。

stateStoreConfig: distWorkerConfig: dataEngineConfig: type: memory inboxStoreConfig: dataEngineConfig: type: memory

mafei6827 commented 8 months ago

尝试压测了一下这个场景用例，压测了两个小时没复现此问题。从描述来看，大量CLOSE_WAIT像是客户端最终异常断开，然后未完成tcp断开的完整握手动作，导致服务端残存了大量的CLOSE_WAIT连接。

fengfu222 commented 8 months ago

尝试压测了一下这个场景用例，压测了两个小时没复现此问题。从描述来看，大量CLOSE_WAIT像是客户端最终异常断开，然后未完成tcp断开的完整握手动作，导致服务端残存了大量的CLOSE_WAIT连接。

出现大量的CLOSE_WAIT 只是现象，分析是因为bifromq服务卡死，导致客户端请求无法响应，所以才会出现大量的CLOSE_WAIT,此时使用mqtt client连接也无法连接上服务。我们的困惑是在于，我的资源都没有到瓶颈，为啥使用RocksDB 无法支持我的压测，我们这里进行了多次压测，只要是使用RocksDB作为存储引擎，一般几分钟后，就会导致服务不可用。memory引擎则没有这个问题。我们还试过将Rocksdb的数据写入到tmpfs，也不行。我们只配置 walEngineConfig: type: "memory" 测试也是不行，只有 dataEngineConfig: type: "memory" 才能支撑我的测试

popduke commented 8 months ago

cleansession=true qos0，消息链路上不会涉及rocksdb的io。bifromq会输出jvm的metrics，可以看下heap和direct buffer的使用情况。

fengfu222 commented 8 months ago

cleansession=true qos0，消息链路上不会涉及rocksdb的io。bifromq会输出jvm的metrics，可以看下heap和direct buffer的使用情况。

我们检查了GC，没看到什么问题。开启监控后有个rocksdb的指标感觉耗时比较高

basekv_le_rocksdb_flush_time_seconds_count{env="Test",kvspace="111877626712162304_0",storeId="a79ce47a-e01f-4db5-9651-fb4b3f7b3659",type="wal",} 168.0

basekv_le_rocksdb_flush_time_seconds_sum{env="Test",kvspace="111877626712162304_0",storeId="a79ce47a-e01f-4db5-9651-fb4b3f7b3659",type="wal",} 5.7988E-5

basekv_le_rocksdb_flush_time_seconds_count{env="Test",kvspace="111877626717339649_0",storeId="79675d6a-a7e9-4a52-9f8b-b659b58b9533",type="wal",} 488610.0

basekv_le_rocksdb_flush_time_seconds_sum{env="Test",kvspace="111877626717339649_0",storeId="79675d6a-a7e9-4a52-9f8b-b659b58b9533",type="wal",} 0.029379993

basekv_le_rocksdb_flush_time_seconds_count{env="Test",kvspace="111877626699644928_0",storeId="18207f92-f591-49a1-9887-ab30549816a0",type="wal",} 7.0

basekv_le_rocksdb_flush_time_seconds_sum{env="Test",kvspace="111877626699644928_0",storeId="18207f92-f591-49a1-9887-ab30549816a0",type="wal",} 1.0189E-5

popduke commented 8 months ago

三个kvspace的flush耗时都是1微妙左右，为什么认为很高？

fengfu222 commented 8 months ago

三个kvspace的flush耗时都是1微妙左右，为什么认为很高？

我们刚开始的压测是在没有sub的情况下，纯发送数据到服务器，CPU负载只有1/3，但是如果我们开启了消费模式，CPU负载就会升到2/3了，如果35万个请求全部发送40K的包，很快就会挂掉。所以我们在想是不是对于发送请求，在调用链上存在限制CPU使用的配置?

fengfu222 commented 8 months ago

尝试压测了一下这个场景用例，压测了两个小时没复现此问题。从描述来看，大量CLOSE_WAIT像是客户端最终异常断开，然后未完成tcp断开的完整握手动作，导致服务端残存了大量的CLOSE_WAIT连接。

你们的压测场景是什么？能否贴一下你们的bifromq的配置？

popduke commented 8 months ago

https://bifromq.io/docs/test_report/test_report/

fengfu222 commented 8 months ago

https://bifromq.io/docs/test_report/test_report/

你这个链接的场景的payload都是小body体，只有几百个字节，我们使用40K的payload，CPU打不上去，很快就挂了，小body体我们也没有问题。我的问题就是使用40K大payload压测的时候，发现32核的CPU，bifromq只能使用三分之一左右，然后集群很快就会被打挂，如何调整参数，都没法让bifromq的CPU使用率上去，使用内存存储就可以将集群CPU打上去。

popduke commented 8 months ago

可以把com.baidu.bifromq.mqtt.handler的debug日志打开，看下压测过程中连接断开的具体原因是什么？

fengfu222 commented 8 months ago

可以把com.baidu.bifromq.mqtt.handler的debug日志打开，看下压测过程中连接断开的具体原因是什么？

error 提示 deliver error

popduke commented 7 months ago

不是event.log里的内容。logback里给 com.baidu.bifromq.mqtt.handler配置个debug logger，看下输出的内容是否有异常抛出。

bifromqio / bifromq

大body压测，CPU不高，大量CLOSE_WAIT #58