2.1.5 升级 git release 2.1.7-rc1 升级中
集群刚承接少部分业务，集群负载比较低，数据的写入方式为RoutineLoad 和 StramLoad
doris-meta验证没有问题
BE节点升级没有问题
A B C为待升级的FE节点，其中A为 master 节点。
先升级B 到2.1.7，记录为B'，此时集群稳定
再升级C 到C’，此时集群稳定
升级A到A'时，B'被选为新Master，此时B在运行一段时间后（3~5s）Crash，之后C’选为新Master，运行一段时间（3~5s）后Crash。
FE全部回退到2.1.5，集群恢复。
Master Crash前的日志
2024-11-07 18:54:08,272 INFO (mysql-nio-pool-10|768) [Database.checkReplicaQuota():356] database[senior_analysis] replica quota: left number: 1073729311 / total: 1073741824
2024-11-07 18:54:08,272 INFO (mysql-nio-pool-10|768) [InternalCatalog.createTable():1165] create table[dwd_jzww_mini_program_user_chat_suggest_first_data_temp] which already exists
2024-11-07 18:54:08,283 INFO (mysql-nio-pool-10|768) [StmtExecutor.handleQueryStmt():1727] Query 811f30dc45014fd3-8f93d5950edfbf21 finished
2024-11-07 18:54:08,319 INFO (mysql-nio-pool-10|768) [InternalCatalog.createPartitionWithIndices():2106] succeed in creating partition[135622568-dwd_jzww_mini_program_user_chat_suggest_first_data_temp], table : [30217761-dwd_jzww_mini_program_user_chat_suggest_first_data_temp]
2024-11-07 18:54:08,323 INFO (mysql-nio-pool-10|768) [EditLog.logTruncateTable():1607] log truncate table, logId:58252372, infos: TruncateTableInfo{dbId=328259, db='senior_analysis', tblId=30217761, table='dwd_jzww_mini_program_user_chat_suggest_first_data_temp', isEntireTable=true, rawSql='', partitions_size=1}
2024-11-07 18:54:08,368 WARN (mysql-nio-pool-10|768) [StatisticsCache.invalidateStats():260] Failed to sync invalidate to follower: TNetworkAddress(hostname:B', port:9020)
org.apache.thrift.transport.TTransportException: Socket is closed by peer.
at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:184) ~[libthrift-0.16.0.jar:0.16.0]
at org.apache.thrift.transport.TTransport.readAll(TTransport.java:109) ~[libthrift-0.16.0.jar:0.16.0]
at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:464) ~[libthrift-0.16.0.jar:0.16.0]
at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:362) ~[libthrift-0.16.0.jar:0.16.0]
at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:245) ~[libthrift-0.16.0.jar:0.16.0]
at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:77) ~[libthrift-0.16.0.jar:0.16.0]
at org.apache.doris.thrift.FrontendService$Client.recvInvalidateStatsCache(FrontendService.java:1506) ~[fe-common-1.2-SNAPSHOT.jar:1.2-SNAPSHOT]
at org.apache.doris.thrift.FrontendService$Client.invalidateStatsCache(FrontendService.java:1493) ~[fe-common-1.2-SNAPSHOT.jar:1.2-SNAPSHOT]
at org.apache.doris.statistics.StatisticsCache.invalidateStats(StatisticsCache.java:258) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.statistics.AnalysisManager.invalidateRemoteStats(AnalysisManager.java:740) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.statistics.AnalysisManager.dropStats(AnalysisManager.java:660) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.datasource.InternalCatalog.truncateTable(InternalCatalog.java:3464) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.catalog.Env.truncateTable(Env.java:5504) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.DdlExecutor.execute(DdlExecutor.java:274) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.handleDdlStmt(StmtExecutor.java:2822) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.executeByLegacy(StmtExecutor.java:984) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:598) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:521) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.executeQuery(ConnectProcessor.java:323) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.handleQuery(ConnectProcessor.java:206) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.handleQuery(MysqlConnectProcessor.java:272) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.dispatch(MysqlConnectProcessor.java:300) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.processOnce(MysqlConnectProcessor.java:358) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_331]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_331]
at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_331]
2024-11-07 18:54:08,369 WARN (mysql-nio-pool-10|768) [AnalysisManager.invalidateRemoteStats():744] Failed to invalidate all remote stats by rpc for table 30217761, use edit log.
2024-11-07 18:54:08,392 ERROR (mysql-nio-pool-10|768) [EditLog.logEdit():1270] BDBJE stats : FeederManager: A feeder is a replication stream connection between a master and replica nodes.
nFeedersCreated=4
nFeedersShutdown=0
replica95DelayMsMap=
replica99DelayMsMap=
replicaAvgDelayMsMap=
replicaDelayMap=fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0=0;fe_a8abad4b_5319_4389_bac5_66a4370021d0=0
replicaLastCommitTimestampMap=fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0=1,730,976,847,003;fe_a8abad4b_5319_4389_bac5_66a4370021d0=1,730,976,847,003
replicaLastCommitVLSNMap=fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0=116,529,586;fe_a8abad4b_5319_4389_bac5_66a4370021d0=116,529,586
replicaMaxDelayMsMap=fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0=6,040;fe_a8abad4b_5319_4389_bac5_66a4370021d0=6,040
replicaVLSNLagMap=fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0=0;fe_a8abad4b_5319_4389_bac5_66a4370021d0=0
replicaVLSNRateMap=fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0=210;fe_a8abad4b_5319_4389_bac5_66a4370021d0=199
FeederTxns: FeederTxns statistics
ackWaitMS=880
lastCommitTimestamp=1,730,976,848,321
lastCommitVLSN=116,529,592
totalTxnMS=984
txnsAcked=100
txnsNotAcked=0
vlsnRate=252
Replay: The Replay unit applies the incoming replication stream at a Replica. These stats show the load the Replica incurs when processing updates.
elapsedTxn95Ms=1
elapsedTxn99Ms=2
elapsedTxnAvgMs=0
elapsedTxnMaxMs=208
latestCommitLagMs=4
maxCommitProcessingNanos=208,429,111
minCommitProcessingNanos=7,087
nAborts=0
nCommitAcks=1,374
nCommitNoSyncs=713
nCommitSyncs=1,374
nCommitWriteNoSyncs=0
nCommits=2,087
nGroupCommitMaxExceeded=0
nGroupCommitTimeouts=0
nGroupCommitTxns=0
nGroupCommits=0
nLNs=2,085
nMessageQueueOverflows=0
nNameLNs=1
outputQueue95DelayMs=unknown
outputQueue99DelayMs=unknown
outputQueueAvgDelayMs=unknown
outputQueueMaxDelayMs=NONE
replayQueue95DelayMs=2
replayQueue99DelayMs=11
replayQueueAvgDelayMs=2
replayQueueMaxDelayMs=208
totalCommitProcessingNanos=814,823,106
ConsistencyTracker: Statistics on the delays experienced by read requests at the replica in order to conform to the specified ReplicaConsistencyPolicy.
nLagConsistencyWaitMS=0
nLagConsistencyWaits=0
nVLSNConsistencyWaitMS=119
nVLSNConsistencyWaits=1
BinaryProtocol: Network traffic due to the replication stream.
bytesReadPerSecond=32,176
bytesWrittenPerSecond=54,653,005
messagesReadPerSecond=29
messagesWrittenPerSecond=33,284
nAckMessages=1,324
nBytesRead=4,738,140
nBytesWritten=3,371,002
nEntriesOldVersion=0
nGroupAckMessages=50
nGroupedAcks=50
nMaxGroupedAcks=1
nMessageBatches=56
nMessagesBatched=266
nMessagesRead=4,311
nMessagesWritten=2,053
nReadNanos=147,256,780,437
nWriteNanos=61,680,084
VLSNIndex: VLSN Index related stats.
nBucketsCreated=23
nHeadBucketsDeleted=0
nHits=64
nMisses=118
nTailBucketsDeleted=0
2024-11-07 18:54:08,393 ERROR (mysql-nio-pool-10|768) [EditLog.logEdit():1272] Fatal Error : write stream Exception
java.lang.NullPointerException: null
at org.apache.doris.journal.JournalEntity.write(JournalEntity.java:184) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.journal.bdbje.BDBJEJournal.write(BDBJEJournal.java:237) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.persist.EditLog.logEdit(EditLog.java:1265) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.persist.EditLog.logCreateTableStats(EditLog.java:2038) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.statistics.AnalysisManager.logCreateTableStats(AnalysisManager.java:1063) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.statistics.AnalysisManager.invalidateRemoteStats(AnalysisManager.java:746) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.statistics.AnalysisManager.dropStats(AnalysisManager.java:660) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.datasource.InternalCatalog.truncateTable(InternalCatalog.java:3464) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.catalog.Env.truncateTable(Env.java:5504) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.DdlExecutor.execute(DdlExecutor.java:274) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.handleDdlStmt(StmtExecutor.java:2822) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.executeByLegacy(StmtExecutor.java:984) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:598) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:521) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.executeQuery(ConnectProcessor.java:323) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.handleQuery(ConnectProcessor.java:206) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.handleQuery(MysqlConnectProcessor.java:272) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.dispatch(MysqlConnectProcessor.java:300) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.processOnce(MysqlConnectProcessor.java:358) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_331]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_331]
at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_331]
Follower这段时间的日志
2024-11-07 18:54:07,942 INFO (qtp745358381-324|324) [LoadAction.executeWithoutPassword():319] redirect load action to destination=TNetworkAddress(hostname:C', port:8040), stream: true, db: senior_ods, tbl: ods_hikari_lingshi_order_pay_record, label: label_senior_ods_ods_hikari_lingshi_order_pay_record_0_100883_03ad0a79-5816-4592-914d-64ccdd5e0138
2024-11-07 18:54:07,942 INFO (qtp745358381-324|324) [RestBaseController.redirectTo():95] Redirect url: http://C':8040/api/senior_ods/ods_hikari_lingshi_order_pay_record/_stream_load
2024-11-07 18:54:08,229 INFO (qtp745358381-322|322) [LoadAction.executeWithoutPassword():319] redirect load action to destination=TNetworkAddress(hostname:B', port:8040), stream: true, db: senior_ods, tbl: ods_hikari_lingshi_user_attendance_callback, label: label_senior_ods_ods_hikari_lingshi_user_attendance_callback_0_100883_5b5bf843-074c-42b8-a6bd-e58e123d569f
2024-11-07 18:54:08,229 INFO (qtp745358381-322|322) [RestBaseController.redirectTo():95] Redirect url: http://B':8040/api/senior_ods/ods_hikari_lingshi_user_attendance_callback/_stream_load
2024-11-07 18:54:08,235 INFO (replayer|108) [Env.replayJournal():2824] replayed journal id is 58252369, replay to journal id is 58252370
2024-11-07 18:54:08,313 INFO (replayer|108) [Env.replayJournal():2824] replayed journal id is 58252370, replay to journal id is 58252371
2024-11-07 18:54:08,323 INFO (replayer|108) [Env.replayJournal():2824] replayed journal id is 58252371, replay to journal id is 58252372
2024-11-07 18:54:09,196 INFO (mysql-nio-pool-0|310) [MasterOpExecutor.forward():126] forward to master FE TNetworkAddress(hostname:B', port:9020), statement id: 47
2024-11-07 18:54:09,372 WARN (mysql-nio-pool-0|310) [StmtExecutor.executeByLegacy():1019] execute Exception. stmt[47, 73aa7ba7e55460b-915ba2ceffddc2b3]
org.apache.doris.qe.MasterOpExecutor$ForwardToMasterException: forward to master FE TNetworkAddress(hostname:B', port:9020), statement id: 47 : failed, cause: Unknown exception, java.net.SocketException: Connection reset
at org.apache.doris.qe.MasterOpExecutor.forward(MasterOpExecutor.java:136) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MasterOpExecutor.execute(MasterOpExecutor.java:83) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.forwardToMaster(StmtExecutor.java:1094) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.executeByLegacy(StmtExecutor.java:907) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:598) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:521) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.executeQuery(ConnectProcessor.java:323) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.handleQuery(ConnectProcessor.java:206) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.handleQuery(MysqlConnectProcessor.java:272) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.dispatch(MysqlConnectProcessor.java:300) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.processOnce(MysqlConnectProcessor.java:358) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_331]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_331]
at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_331]
2024-11-07 18:54:10,325 WARN (REPLICA fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0(2)|88) [Env.notifyNewFETypeTransfer():2696] notify new FE type transfer: UNKNOWN
2024-11-07 18:54:10,326 INFO (REPLICA fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0(2)|88) [LogUtils.stdout():50] StdoutLogger 2024-11-07 18:54:10,325 notify new FE type transfer: UNKNOWN
2024-11-07 18:54:10,326 INFO (stateListener|106) [Env$5.runOneCycle():2719] begin to transfer FE type from FOLLOWER to UNKNOWN
2024-11-07 18:54:10,326 WARN (stateListener|106) [Env.transferToNonMaster():1785] FOLLOWER to UNKNOWN, still offer read service
2024-11-07 18:54:10,327 INFO (stateListener|106) [Env$5.runOneCycle():2806] finished to transfer FE type to UNKNOWN
2024-11-07 18:54:10,381 INFO (mysql-nio-pool-0|310) [StmtExecutor.handleQueryStmt():1727] Query 34af6f03dd7840be-811629d142b1a4c1 finished
2024-11-07 18:54:10,458 WARN (UNKNOWN fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0(2)|88) [Env.notifyNewFETypeTransfer():2696] notify new FE type transfer: FOLLOWER
2024-11-07 18:54:10,459 INFO (UNKNOWN fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0(2)|88) [LogUtils.stdout():50] StdoutLogger 2024-11-07 18:54:10,458 notify new FE type transfer: FOLLOWER
2024-11-07 18:54:10,459 INFO (stateListener|106) [Env$5.runOneCycle():2719] begin to transfer FE type from UNKNOWN to FOLLOWER
2024-11-07 18:54:10,469 INFO (mysql-nio-pool-0|310) [StmtExecutor.handleQueryStmt():1727] Query c0e0e4c9b5c740a4-8582d268fca2547a finished
2024-11-07 18:54:10,480 INFO (mysql-nio-pool-0|310) [MasterOpExecutor.forward():126] forward to master FE TNetworkAddress(hostname:B', port:9020), statement id: 58
2024-11-07 18:54:10,481 WARN (mysql-nio-pool-0|310) [ConnectProcessor.handleQueryException():462] Process one query failed because unknown reason:
org.apache.doris.qe.MasterOpExecutor$ForwardToMasterException: forward to master FE TNetworkAddress(hostname:B', port:9020), statement id: 58 : failed, cause: EOF, Socket is closed by peer.
at org.apache.doris.qe.MasterOpExecutor.forward(MasterOpExecutor.java:136) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MasterOpExecutor.execute(MasterOpExecutor.java:83) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.forwardToMaster(StmtExecutor.java:1094) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:700) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:545) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:521) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.executeQuery(ConnectProcessor.java:323) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.ConnectProcessor.handleQuery(ConnectProcessor.java:206) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.handleQuery(MysqlConnectProcessor.java:272) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.dispatch(MysqlConnectProcessor.java:300) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.MysqlConnectProcessor.processOnce(MysqlConnectProcessor.java:358) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_331]
B'je.info.0对应时间日志如下 (UTC)
2024-11-07 10:53:17.814 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Master changed to fe_a80a2b41_b263_4c1a_8563_2ed444adf290
2024-11-07 10:53:17.814 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Election finished. Elapsed time: 10478ms
2024-11-07 10:53:17.814 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Exiting election after 5 retries
2024-11-07 10:53:17.815 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Election thread exited. Group master: fe_a80a2b41_b263_4c1a_8563_2ed444adf290(1)
2024-11-07 10:53:17.815 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] node:fe_a80a2b41_b263_4c1a_8563_2ed444adf290(1) state change from UNKNOWN to MASTER
2024-11-07 10:53:17.816 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder manager accepting requests.
2024-11-07 10:53:17.817 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Request for unknown Service: Feeder Registered services: [Group, Acceptor, NodeState, LogFileFeeder, LDiff, BinaryNodeState, Learner]
2024-11-07 10:53:17.924 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder accepted connection from /10.55.164.202:29457
2024-11-07 10:53:17.938 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica handshake start
2024-11-07 10:53:17.951 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 handshake completed. Replica fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 Versions JE: 18.3.12 Log: 17 Protocol: 9 Stream Log: 16
2024-11-07 10:53:17.954 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 syncup started. Feeder range: first=115,333,515 last=116,529,388 sync=116,529,388 txnEnd=116,529,388
2024-11-07 10:53:17.978 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 start stream at VLSN: 116,529,334
2024-11-07 10:53:17.982 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 syncup ended. Elapsed time: 27ms
2024-11-07 10:53:17.991 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder output thread for replica fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 started at VLSN 116,529,334 master at 116,529,388 (DTVLSN:116,529,386) VLSN delta=54 socket=(fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0(2))com.sleepycat.je.rep.utilint.net.SimpleDataChannel@7c7b0705
2024-11-07 10:53:30.187 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder accepted connection from /10.55.164.203:58509
2024-11-07 10:53:30.189 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica handshake start
2024-11-07 10:53:30.219 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_a8abad4b_5319_4389_bac5_66a4370021d0 handshake completed. Replica fe_a8abad4b_5319_4389_bac5_66a4370021d0 Versions JE: 18.3.12 Log: 17 Protocol: 9 Stream Log: 16
2024-11-07 10:53:30.219 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_a8abad4b_5319_4389_bac5_66a4370021d0 syncup started. Feeder range: first=115,333,515 last=116,529,514 sync=116,529,514 txnEnd=116,529,514
2024-11-07 10:53:30.233 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_a8abad4b_5319_4389_bac5_66a4370021d0 start stream at VLSN: 116,529,389
2024-11-07 10:53:30.234 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder-replica fe_a8abad4b_5319_4389_bac5_66a4370021d0 syncup ended. Elapsed time: 15ms
2024-11-07 10:53:30.237 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Feeder output thread for replica fe_a8abad4b_5319_4389_bac5_66a4370021d0 started at VLSN 116,529,389 master at 116,529,514 (DTVLSN:116,529,514) VLSN delta=125 socket=(fe_a8abad4b_5319_4389_bac5_66a4370021d0(3))com.sleepycat.je.rep.utilint.net.SimpleDataChannel@662eb96d
2024-11-07 10:53:55.335 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Start DB remove/truncate scan, id=1165 dbId=-1424 dbName=58114309
2024-11-07 10:53:55.420 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] End DB remove/truncate scan, id=1165 scanned=50399 dbId=-1424 dbName=58114309
2024-11-07 10:54:58.253 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x230d: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 64 max: 64, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.306 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] No server auth method
2024-11-07 10:54:58.308 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Started ServiceDispatcher. HostPort=zhidao-online-03-gz.ynode.cn:9010
2024-11-07 10:54:58.308 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] DataChannel factory: com.sleepycat.je.rep.utilint.net.SimpleChannelFactory
2024-11-07 10:54:58.328 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 1 on file 0x230d ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=4917 nDbLookups=3 nINsObsolete=114 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=0 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=4801 nLNsCleaned=1 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=1 nLNsMarked=0 nLNQueueHits=0 nLNsLocked=0 inSummary=<INSummary totalINCount="114" totalINSize="104321" totalBINDeltaCount="0" totalBINDeltaSize="0" obsoleteINCount="114" obsoleteINSize="104321" obsoleteBINDeltaCount="0" obsoleteBINDeltaSize="0"/> estSummary=<summary totalCount="9717" totalSize="9999493" totalINCount="114" totalINSize="104321" totalLNCount="4802" totalLNSize="9669525" maxLNSize="339057" obsoleteINCount="114" obsoleteLNCount="4801" obsoleteLNSize="9669504" obsoleteLNSizeCounted="4801" getObsoleteSize="9999472" getObsoleteINSize="104321" getObsoleteLNSize="9669504" getMaxObsoleteSize="9999472" getMaxObsoleteLNSize="9669504" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="9717" totalSize="9999493" totalINCount="114" totalINSize="104321" totalLNCount="4802" totalLNSize="9669525" maxLNSize="0" obsoleteINCount="114" obsoleteLNCount="4801" obsoleteLNSize="9669504" obsoleteLNSizeCounted="4801" getObsoleteSize="9999472" getObsoleteINSize="104321" getObsoleteLNSize="9669504" getMaxObsoleteSize="9999472" getMaxObsoleteLNSize="9669504" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.331 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x230e: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 66 max: 66, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.406 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] DTVLSN at start:116,529,590
2024-11-07 10:54:58.408 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] node:NullNode(-1) state change from DETACHED to UNKNOWN
2024-11-07 10:54:58.435 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 2 on file 0x230e ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=5398 nDbLookups=14 nINsObsolete=206 nINsCleaned=8 nINsDead=0 nINsMigrated=8 nBINDeltasObsolete=4 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=5108 nLNsCleaned=69 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=68 nLNsMarked=0 nLNQueueHits=62 nLNsLocked=0 inSummary=<INSummary totalINCount="218" totalINSize="280962" totalBINDeltaCount="4" totalBINDeltaSize="1677" obsoleteINCount="210" obsoleteINSize="268615" obsoleteBINDeltaCount="4" obsoleteBINDeltaSize="1677"/> estSummary=<summary totalCount="10121" totalSize="9907157" totalINCount="218" totalINSize="280962" totalLNCount="5177" totalLNSize="9403968" maxLNSize="339061" obsoleteINCount="210" obsoleteLNCount="5108" obsoleteLNSize="9391861" obsoleteLNSizeCounted="5108" getObsoleteSize="9884739" getObsoleteINSize="270651" getObsoleteLNSize="9391861" getMaxObsoleteSize="9884739" getMaxObsoleteLNSize="9391861" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="10121" totalSize="9907157" totalINCount="218" totalINSize="280962" totalLNCount="5177" totalLNSize="9403968" maxLNSize="0" obsoleteINCount="210" obsoleteLNCount="5108" obsoleteLNSize="9391861" obsoleteLNSizeCounted="5108" getObsoleteSize="9884739" getObsoleteINSize="270651" getObsoleteLNSize="9391861" getMaxObsoleteSize="9884739" getMaxObsoleteLNSize="9391861" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.436 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x230f: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 69 max: 69, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.446 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Current group size: 3
2024-11-07 10:54:58.446 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Existing node fe_a80a2b41_b263_4c1a_8563_2ed444adf290 querying for a current master.
2024-11-07 10:54:58.472 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Node fe_a80a2b41_b263_4c1a_8563_2ed444adf290 started
2024-11-07 10:54:58.473 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Election initiated; election #1
2024-11-07 10:54:58.477 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Started election thread Thu Nov 07 18:54:58 CST 2024
2024-11-07 10:54:58.511 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 3 on file 0x230f ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=5472 nDbLookups=3 nINsObsolete=137 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=0 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=5333 nLNsCleaned=1 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=1 nLNsMarked=0 nLNQueueHits=0 nLNsLocked=0 inSummary=<INSummary totalINCount="137" totalINSize="159563" totalBINDeltaCount="0" totalBINDeltaSize="0" obsoleteINCount="137" obsoleteINSize="159563" obsoleteBINDeltaCount="0" obsoleteBINDeltaSize="0"/> estSummary=<summary totalCount="10803" totalSize="9966870" totalINCount="137" totalINSize="159563" totalLNCount="5334" totalLNSize="9556703" maxLNSize="339057" obsoleteINCount="137" obsoleteLNCount="5333" obsoleteLNSize="9556682" obsoleteLNSizeCounted="5333" getObsoleteSize="9966849" getObsoleteINSize="159563" getObsoleteLNSize="9556682" getMaxObsoleteSize="9966849" getMaxObsoleteLNSize="9556682" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="10803" totalSize="9966870" totalINCount="137" totalINSize="159563" totalLNCount="5334" totalLNSize="9556703" maxLNSize="0" obsoleteINCount="137" obsoleteLNCount="5333" obsoleteLNSize="9556682" obsoleteLNSizeCounted="5333" getObsoleteSize="9966849" getObsoleteINSize="159563" getObsoleteLNSize="9556682" getMaxObsoleteSize="9966849" getMaxObsoleteLNSize="9556682" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.512 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x2310: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 71 max: 71, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.559 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 4 on file 0x2310 ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=5025 nDbLookups=6 nINsObsolete=163 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=3 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=4803 nLNsCleaned=54 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=54 nLNsMarked=0 nLNQueueHits=50 nLNsLocked=0 inSummary=<INSummary totalINCount="166" totalINSize="141958" totalBINDeltaCount="3" totalBINDeltaSize="898" obsoleteINCount="166" obsoleteINSize="141958" obsoleteBINDeltaCount="3" obsoleteBINDeltaSize="898"/> estSummary=<summary totalCount="9817" totalSize="9982623" totalINCount="166" totalINSize="141958" totalLNCount="4857" totalLNSize="9615325" maxLNSize="339057" obsoleteINCount="166" obsoleteLNCount="4803" obsoleteLNSize="9603482" obsoleteLNSizeCounted="4803" getObsoleteSize="9970780" getObsoleteINSize="141958" getObsoleteLNSize="9603482" getMaxObsoleteSize="9970780" getMaxObsoleteLNSize="9603482" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="9817" totalSize="9982623" totalINCount="166" totalINSize="141958" totalLNCount="4857" totalLNSize="9615325" maxLNSize="0" obsoleteINCount="166" obsoleteLNCount="4803" obsoleteLNSize="9603482" obsoleteLNSizeCounted="4803" getObsoleteSize="9970780" getObsoleteINSize="141958" getObsoleteLNSize="9603482" getMaxObsoleteSize="9970780" getMaxObsoleteLNSize="9603482" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.560 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x2311: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 74 max: 74, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.598 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 5 on file 0x2311 ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=4408 nDbLookups=3 nINsObsolete=134 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=0 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=4272 nLNsCleaned=1 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=1 nLNsMarked=0 nLNQueueHits=0 nLNsLocked=0 inSummary=<INSummary totalINCount="134" totalINSize="113106" totalBINDeltaCount="0" totalBINDeltaSize="0" obsoleteINCount="134" obsoleteINSize="113106" obsoleteBINDeltaCount="0" obsoleteBINDeltaSize="0"/> estSummary=<summary totalCount="8679" totalSize="9939214" totalINCount="134" totalINSize="113106" totalLNCount="4273" totalLNSize="9625324" maxLNSize="339061" obsoleteINCount="134" obsoleteLNCount="4272" obsoleteLNSize="9625303" obsoleteLNSizeCounted="4272" getObsoleteSize="9939193" getObsoleteINSize="113106" getObsoleteLNSize="9625303" getMaxObsoleteSize="9939193" getMaxObsoleteLNSize="9625303" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="8679" totalSize="9939214" totalINCount="134" totalINSize="113106" totalLNCount="4273" totalLNSize="9625324" maxLNSize="0" obsoleteINCount="134" obsoleteLNCount="4272" obsoleteLNSize="9625303" obsoleteLNSizeCounted="4272" getObsoleteSize="9939193" getObsoleteINSize="113106" getObsoleteLNSize="9625303" getMaxObsoleteSize="9939193" getMaxObsoleteLNSize="9625303" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.599 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x2312: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 76 max: 76, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.641 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 6 on file 0x2312 ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=3872 nDbLookups=7 nINsObsolete=127 nINsCleaned=1 nINsDead=0 nINsMigrated=1 nBINDeltasObsolete=2 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=3687 nLNsCleaned=53 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=53 nLNsMarked=0 nLNQueueHits=48 nLNsLocked=0 inSummary=<INSummary totalINCount="130" totalINSize="86691" totalBINDeltaCount="2" totalBINDeltaSize="393" obsoleteINCount="129" obsoleteINSize="84677" obsoleteBINDeltaCount="2" obsoleteBINDeltaSize="393"/> estSummary=<summary totalCount="7556" totalSize="9927392" totalINCount="130" totalINSize="86691" totalLNCount="3740" totalLNSize="9667437" maxLNSize="339053" obsoleteINCount="129" obsoleteLNCount="3687" obsoleteLNSize="9655802" obsoleteLNSizeCounted="3687" getObsoleteSize="9915090" getObsoleteINSize="86024" getObsoleteLNSize="9655802" getMaxObsoleteSize="9915090" getMaxObsoleteLNSize="9655802" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="7556" totalSize="9927392" totalINCount="130" totalINSize="86691" totalLNCount="3740" totalLNSize="9667437" maxLNSize="0" obsoleteINCount="129" obsoleteLNCount="3687" obsoleteLNSize="9655802" obsoleteLNSizeCounted="3687" getObsoleteSize="9915090" getObsoleteINSize="86024" getObsoleteLNSize="9655802" getMaxObsoleteSize="9915090" getMaxObsoleteLNSize="9655802" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.642 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x2313: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 79 max: 79, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.683 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 7 on file 0x2313 ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=5202 nDbLookups=3 nINsObsolete=160 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=0 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=5040 nLNsCleaned=1 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=1 nLNsMarked=0 nLNQueueHits=0 nLNsLocked=0 inSummary=<INSummary totalINCount="160" totalINSize="128702" totalBINDeltaCount="0" totalBINDeltaSize="0" obsoleteINCount="160" obsoleteINSize="128702" obsoleteBINDeltaCount="0" obsoleteBINDeltaSize="0"/> estSummary=<summary totalCount="10241" totalSize="9904641" totalINCount="160" totalINSize="128702" totalLNCount="5041" totalLNSize="9539059" maxLNSize="339057" obsoleteINCount="160" obsoleteLNCount="5040" obsoleteLNSize="9539038" obsoleteLNSizeCounted="5040" getObsoleteSize="9904620" getObsoleteINSize="128702" getObsoleteLNSize="9539038" getMaxObsoleteSize="9904620" getMaxObsoleteLNSize="9539038" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="10241" totalSize="9904641" totalINCount="160" totalINSize="128702" totalLNCount="5041" totalLNSize="9539059" maxLNSize="0" obsoleteINCount="160" obsoleteLNCount="5040" obsoleteLNSize="9539038" obsoleteLNSizeCounted="5040" getObsoleteSize="9904620" getObsoleteINSize="128702" getObsoleteLNSize="9539038" getMaxObsoleteSize="9904620" getMaxObsoleteLNSize="9539038" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.684 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x2314: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 82 max: 82, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.736 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 8 on file 0x2314 ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=6340 nDbLookups=6 nINsObsolete=203 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=2 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=6077 nLNsCleaned=56 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=56 nLNsMarked=0 nLNQueueHits=52 nLNsLocked=0 inSummary=<INSummary totalINCount="205" totalINSize="186057" totalBINDeltaCount="2" totalBINDeltaSize="467" obsoleteINCount="205" obsoleteINSize="186057" obsoleteBINDeltaCount="2" obsoleteBINDeltaSize="467"/> estSummary=<summary totalCount="12451" totalSize="9961975" totalINCount="205" totalINSize="186057" totalLNCount="6133" totalLNSize="9488807" maxLNSize="339061" obsoleteINCount="205" obsoleteLNCount="6077" obsoleteLNSize="9476888" obsoleteLNSizeCounted="6077" getObsoleteSize="9950056" getObsoleteINSize="186057" getObsoleteLNSize="9476888" getMaxObsoleteSize="9950056" getMaxObsoleteLNSize="9476888" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="12451" totalSize="9961975" totalINCount="205" totalINSize="186057" totalLNCount="6133" totalLNSize="9488807" maxLNSize="0" obsoleteINCount="205" obsoleteLNCount="6077" obsoleteLNSize="9476888" obsoleteLNSizeCounted="6077" getObsoleteSize="9950056" getObsoleteINSize="186057" getObsoleteLNSize="9476888" getMaxObsoleteSize="9950056" getMaxObsoleteLNSize="9476888" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.738 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x2315: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 86 max: 86, chose file with util min: 0 max: 0 avg: 0
2024-11-07 10:54:58.780 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 9 on file 0x2315 ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=5512 nDbLookups=3 nINsObsolete=168 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=0 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=5342 nLNsCleaned=1 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=1 nLNsMarked=0 nLNQueueHits=0 nLNsLocked=0 inSummary=<INSummary totalINCount="168" totalINSize="113222" totalBINDeltaCount="0" totalBINDeltaSize="0" obsoleteINCount="168" obsoleteINSize="113222" obsoleteBINDeltaCount="0" obsoleteBINDeltaSize="0"/> estSummary=<summary totalCount="10853" totalSize="9999090" totalINCount="168" totalINSize="113222" totalLNCount="5343" totalLNSize="9634794" maxLNSize="339061" obsoleteINCount="168" obsoleteLNCount="5342" obsoleteLNSize="9634773" obsoleteLNSizeCounted="5342" getObsoleteSize="9999069" getObsoleteINSize="113222" getObsoleteLNSize="9634773" getMaxObsoleteSize="9999069" getMaxObsoleteLNSize="9634773" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="10853" totalSize="9999090" totalINCount="168" totalINSize="113222" totalLNCount="5343" totalLNSize="9634794" maxLNSize="0" obsoleteINCount="168" obsoleteLNCount="5342" obsoleteLNSize="9634773" obsoleteLNSizeCounted="5342" getObsoleteSize="9999069" getObsoleteINSize="113222" getObsoleteLNSize="9634773" getMaxObsoleteSize="9999069" getMaxObsoleteLNSize="9634773" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=0 recalcUtil=0
2024-11-07 10:54:58.781 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Clean file 0x230c: file has avg util below minFileUtilization, current util min: 64 max: 64, predicted util min: 90 max: 90, chose file with util min: 2 max: 2 avg: 2
2024-11-07 10:54:58.860 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] CleanerRun 10 on file 0x230c ends: invokedFromDaemon=true finished=true fileDeleted=false nEntriesRead=10041 nDbLookups=20 nINsObsolete=143 nINsCleaned=0 nINsDead=0 nINsMigrated=0 nBINDeltasObsolete=2 nBINDeltasCleaned=0 nBINDeltasDead=0 nBINDeltasMigrated=0 nLNsObsolete=8813 nLNsCleaned=1080 nLNsDead=0 nLNsExpired=0 nLNsExtinct=0 nLNsMigrated=1080 nLNsMarked=0 nLNQueueHits=1020 nLNsLocked=0 inSummary=<INSummary totalINCount="145" totalINSize="111059" totalBINDeltaCount="2" totalBINDeltaSize="187" obsoleteINCount="145" obsoleteINSize="111059" obsoleteBINDeltaCount="2" obsoleteBINDeltaSize="187"/> estSummary=<summary totalCount="14583" totalSize="9868743" totalINCount="145" totalINSize="111059" totalLNCount="9893" totalLNSize="9539901" maxLNSize="339061" obsoleteINCount="145" obsoleteLNCount="8813" obsoleteLNSize="9366131" obsoleteLNSizeCounted="8813" getObsoleteSize="9694973" getObsoleteINSize="111059" getObsoleteLNSize="9366131" getMaxObsoleteSize="9694973" getMaxObsoleteLNSize="9366131" getAvgObsoleteLNSizeNotCounted="NaN"/> recalcSummary=<summary totalCount="14583" totalSize="9868743" totalINCount="145" totalINSize="111059" totalLNCount="9893" totalLNSize="9539901" maxLNSize="0" obsoleteINCount="145" obsoleteLNCount="8813" obsoleteLNSize="9366131" obsoleteLNSizeCounted="8813" getObsoleteSize="9694973" getObsoleteINSize="111059" getObsoleteLNSize="9366131" getMaxObsoleteSize="9694973" getMaxObsoleteLNSize="9366131" getAvgObsoleteLNSizeNotCounted="NaN"/> estimatedUtil=2 recalcUtil=2
2024-11-07 10:55:03.683 UTC INFO [fe_a80a2b41_b263_4c1a_8563_2ed444adf290] Master changed to fe_200bb868_1ac2_4d3d_ba37_10c6b7f1eed0 ....
