【急】Ilogtail重复采集问题

[yecun123]

硬件资源：CPU： 0.5C 内存：1G
现象： CPU打满，原始日志ES重复，同一个日志打印 3次以上。
暂未扩规格原因：业务反馈给多少能用多少...，日志量有些大。
日志见附件，请帮忙确认下是否由CPU性能引起，之前也出现过一次，扩容Ilogtail容器的规格后修复，谢谢。
Uploading ilogtail(1).log…

[yecun123]

业务运行日志：平均每天20T
插件日志：
logtail_plugin.LOG

[yecun123]

当前发现已读取的offset，存在重复读现象，截取运行日志附件如下：
ilogtail.txt

[yecun123]

附上Ilogtail采集配置
user_yaml_config.d.tar.gz

[yecun123]

附上Ilogtail.log
ilogtail.log

[linrunqi08]

@yecun123

1. 建议升级到最新版本，有更详细的日志
2. 以/opt/hihonor/logs/sorting-hat/info_2023-09-07.0.log 这个文件为例，看上去这个像是轮转后的文件，但是文件大小一直在增加，你们的文件轮转模式是怎么样的

[yecun123]

根据文件大小轮转，2.1G轮转一次 。 今天发现当前文件还未触发轮转（正在写入），也触发了重复采集~
每分钟导出checkpoint文件,对比了下,下午标准重采,啥都没变,offset 重置为 0 了

[yecun123]

附上一段测试环境的debug压测日志，复现了重复消费场景。
硬件：1C*1G ， 几类日志的轮转类型：大小1G轮询一次, 按日期1d轮询，大小2G轮询，大小1Mb/s轮询
jmeter: 1秒10次请求, 每个轮转类型的日志文件每次请求写入1Mb/s,加上附加信息, 60Mb/s~80Mb/s

现象: 1G大小轮询日志出现重复采集:aiops-server-test-1G
ilogtail.1.LOG
ilogtail.2.LOG
ilogtail.3.LOG
ilogtail.4.LOG
ilogtail.5.LOG
ilogtail.6.LOG
ilogtail.7.LOG
ilogtail.8.LOG
ilogtail.9.LOG
ilogtail.10.LOG
ilogtail.LOG

[yecun123]

附上重采关键日志，你们会监听目录的最新更新时间 ？如果超过窗口期（超时），移除之前已注册的register？
[2023-09-21 19:25:34.052025] [debug] [003530] /src/core/event_handler/LogInput.cpp:315 ProcessEvent Type:9 Source:/opt/hihonor/logs/aos-business-service/dmp-business-service-5bf5cbc769-mrtw2/aiops-interface Object: Config: IsDir:true IsCreate:false IsModify:false IsDeleted:false IsMoveFrom:false IsContainerStopped:false IsMoveTo:false
[2023-09-21 19:25:34.052042] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:966 Remove all sub dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-5bf5cbc769-mrtw2/aiops-interface
[2023-09-21 19:25:34.052044] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:947 Find all sub dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-5bf5cbc769-mrtw2/aiops-interface
[2023-09-21 19:25:34.052050] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:993 unregister dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-5bf5cbc769-mrtw2/aiops-interface
[2023-09-21 19:25:34.052055] [debug] [003530] /src/core/event_handler/LogInput.cpp:315 ProcessEvent Type:9 Source:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface Object: Config: IsDir:true IsCreate:false IsModify:false IsDeleted:false IsMoveFrom:false IsContainerStopped:false IsMoveTo:false
[2023-09-21 19:25:34.052057] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:966 Remove all sub dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface
[2023-09-21 19:25:34.052072] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:947 Find all sub dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface
[2023-09-21 19:25:34.052078] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:993 unregister dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface
[2023-09-21 19:25:34.052082] [debug] [003530] /src/core/reader/LogFileReader.cpp:1770 Delete LogFileReader :/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log
[2023-09-21 19:25:34.052084] [debug] [003530] /src/core/reader/LogFileReader.cpp:1130 start close LogFileReader:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log
[2023-09-21 19:25:34.052096] [debug] [003530] /src/core/reader/LogFileReader.cpp:1139 reader update real log path:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log
from:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log
to:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log

发现该目录下日志文件有修改，新建了日志读取跟踪器，此时重置checkPoint~
[2023-09-21 19:25:34.464777] [debug] [003530] /src/core/event_handler/LogInput.cpp:315 ProcessEvent Type:4 Source:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface Object:aiops-interface.log Config: IsDir:false IsCreate:false IsModify:true IsDeleted:false IsMoveFrom:false IsContainerStopped:false IsMoveTo:false
[2023-09-21 19:25:34.464784] [debug] [003530] /src/core/event_handler/LogInput.cpp:338 LogInput handle event, find no handler:register for it type:4 wd:-1 source:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface object:aiops-interface.log inode:25429178
[2023-09-21 19:25:34.464832] [info] [003530] /src/core/controller/EventDispatcherBase.cpp:316 add a new watcher for dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface isSymbolicLink:false dir inode:25427991 wd:281
[2023-09-21 19:25:34.464882] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:406 add exist file:aiops-interface.log inode:0 config:
[2023-09-21 19:25:34.464906] [debug] [003530] /src/core/event_handler/EventHandler.cpp:118 register dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log logstore: max depth:0
[2023-09-21 19:25:34.464917] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:216 replace handler:both path and inode of dir is registered, just replace EventHandler path:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface wd:281
[2023-09-21 19:25:34.464924] [debug] [003530] /src/core/event_handler/EventHandler.cpp:271 Process event with multi config:1 /opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface:aiops-interface.log
[2023-09-21 19:25:34.465047] [debug] [003530] /src/core/reader/LogFileReader.cpp:724 begin to read file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log start offset:0
[2023-09-21 19:25:34.465059] [debug] [003530] /src/core/reader/LogFileReader.cpp:1055 UpdateFilePtr open log file :/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log
[2023-09-21 19:25:34.465071] [debug] [003530] /src/core/event_handler/EventHandler.cpp:422 create reader name:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log inode:25429178 readerArraySize:1 handlerAddress:34015824

[linrunqi08]

看了下aiops-server-test-1G相关的日志，offset 重置为 0是因为文件inode变化了，属于正常的行为。你这些日志看上去并没有复现第一次发的日志场景，是否可以在第一次的现场打开debug日志呢

[linrunqi08]

目录带*是什么样的配置呢？可以给个样例出来看下吗，如果方便的话，配置采集的完整的目录结构也发一下，可以使用tree命令输出一下

[yecun123]

附上确认重采的日志，日志路径：/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface
以下是重采截取的日志：
ilogtail.21.LOG.zip

[2023-09-21 19:25:34.464777] [debug] [003530] /src/core/event_handler/LogInput.cpp:315 ProcessEvent Type:4 Source:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface Object:aiops-interface.log Config: IsDir:false IsCreate:false IsModify:true IsDeleted:false IsMoveFrom:false IsContainerStopped:false IsMoveTo:false
[2023-09-21 19:25:34.464784] [debug] [003530] /src/core/event_handler/LogInput.cpp:338 LogInput handle event, find no handler:register for it type:4 wd:-1 source:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface object:aiops-interface.log inode:25429178
[2023-09-21 19:25:34.464832] [info] [003530] /src/core/controller/EventDispatcherBase.cpp:316 add a new watcher for dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface isSymbolicLink:false dir inode:25427991 wd:281
[2023-09-21 19:25:34.464882] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:406 add exist file:aiops-interface.log inode:0 config:
[2023-09-21 19:25:34.464906] [debug] [003530] /src/core/event_handler/EventHandler.cpp:118 register dir:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log logstore: max depth:0
[2023-09-21 19:25:34.464917] [debug] [003530] /src/core/controller/EventDispatcherBase.cpp:216 replace handler:both path and inode of dir is registered, just replace EventHandler path:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface wd:281
[2023-09-21 19:25:34.464924] [debug] [003530] /src/core/event_handler/EventHandler.cpp:271 Process event with multi config:1 /opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface:aiops-interface.log
[2023-09-21 19:25:34.465047] [debug] [003530] /src/core/reader/LogFileReader.cpp:724 begin to read file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log start offset:0
[2023-09-21 19:25:34.465059] [debug] [003530] /src/core/reader/LogFileReader.cpp:1055 UpdateFilePtr open log file :/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log
[2023-09-21 19:25:34.465071] [debug] [003530] /src/core/event_handler/EventHandler.cpp:422 create reader name:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log inode:25429178 readerArraySize:1 handlerAddress:34015824
[2023-09-21 19:25:34.478044] [debug] [003530] /src/core/reader/LogFileReader.cpp:1562 read bytes:524288 last read pos:524288
[2023-09-21 19:25:34.478065] [debug] [003530] /src/core/reader/LogFileReader.cpp:1589 read size:524173 last file pos:524173
[2023-09-21 19:25:34.478070] [debug] [003530] /src/core/reader/LogFileReader.cpp:989 read log file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log last file pos:524173 last file size:3859565696 read size:524173
[2023-09-21 19:25:34.505431] [debug] [003530] /src/core/reader/LogFileReader.cpp:1562 read bytes:524288 last read pos:1048461
[2023-09-21 19:25:34.505458] [debug] [003530] /src/core/reader/LogFileReader.cpp:1589 read size:524278 last file pos:1048451
[2023-09-21 19:25:34.505480] [debug] [003530] /src/core/reader/LogFileReader.cpp:989 read log file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log last file pos:1048451 last file size:3859565696 read size:524278
[2023-09-21 19:25:34.508964] [debug] [003530] /src/core/reader/LogFileReader.cpp:1562 read bytes:524288 last read pos:1572739
[2023-09-21 19:25:34.508991] [debug] [003530] /src/core/reader/LogFileReader.cpp:1589 read size:524186 last file pos:1572637
[2023-09-21 19:25:34.509000] [debug] [003530] /src/core/reader/LogFileReader.cpp:989 read log file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log last file pos:1572637 last file size:3859565696 read size:524186
[2023-09-21 19:25:34.510794] [debug] [003530] /src/core/reader/LogFileReader.cpp:1562 read bytes:524288 last read pos:2096925
[2023-09-21 19:25:34.510816] [debug] [003530] /src/core/reader/LogFileReader.cpp:1589 read size:524244 last file pos:2096881
[2023-09-21 19:25:34.510823] [debug] [003530] /src/core/reader/LogFileReader.cpp:989 read log file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log last file pos:2096881 last file size:3859565696 read size:524244
[2023-09-21 19:25:34.576891] [debug] [003530] /src/core/reader/LogFileReader.cpp:1562 read bytes:524288 last read pos:2621169
[2023-09-21 19:25:34.576915] [debug] [003530] /src/core/reader/LogFileReader.cpp:1589 read size:524163 last file pos:2621044
[2023-09-21 19:25:34.576922] [debug] [003530] /src/core/reader/LogFileReader.cpp:989 read log file:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface/aiops-interface.log last file pos:2621044 last file size:3859565696 read size:524163
[2023-09-21 19:25:34.576940] [debug] [003530] /src/core/event_handler/EventHandler.cpp:700 read log breakout:file io cost 1 time slice (50ms) or push blocked pushRetry:0 begin time:1695295534464961 path:/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface file:aiops-interface.log

[linrunqi08]

@yecun123 ilogtail是部署在容器里的是吗，deployment可以发一下吗

[linrunqi08]

目前怀疑是 TailSizeKB: 10485760这个配置导致的，如果ilogtail没有持久化checkpoint的话，每次重启都会设置文件offset为当前文件大小-10485760，所以会有重复采集的现象。建议把checkpoint持久化一下，然后如果数据量过大，是需要分配更多的cpu和内存的

[yecun123]

对这个回答有点疑问，checkpoint 我们已经外挂到磁盘了，平常重启是基本不会有重采的。 但目录/opt/hihonor/logs/aos-business-service/dmp-business-service-7d66f64989-94ndr/aiops-interface 为何会被监听是否有修改，不应该是目录的文件嘛。