记一次 Kafka 未增大文件描述符限制的翻车经历

2022年04月29日 22时51分24秒 Monterry 12.3.1 (21E258) 101.0.4951.41 Stable 新家 140

记一次翻车经历系列，第二篇新鲜出炉

0x00.`TL;DR`

https://mastodon.yuangezhizao.cn/@yuangezhizao/108214813032210497

0x01.前言

周二早上起床睁开朦胧的睡眼，打开手机发现wx群里有新消息，说一节点的硬盘满了……并且已经引发其他组件的异常
瞬间清醒起来，大脑高速运转猜想到底是哪里出的问题，不到一个小时客户就已经准备好环境，我们这边可以进行远程连接了

0x02.问题确认

好在SSH还是可以正常连接上的，操作起来也没有卡顿之类的异样感，df -h看硬盘确实满了，然后dh -h --max-depth=1排查到底是哪个文件夹惹的祸
好家伙找到了，/kafka占用327G草……继续深入logs文件夹，发现二十多个每个占用12G的server.log日志文件，自2022-04-23-12至2022-04-24-20
迫不及待的等着看里面到底写了啥，结果全是Too many open files的报错信息，心里的一块石头落地了

[2022-04-24 20:59:58,804] ERROR Error while accepting connection (kafka.network.Acceptor)
java.io.IOException: Too many open files
        at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
        at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:421)
        at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:249)
        at kafka.network.Acceptor.accept(SocketServer.scala:460)
        at kafka.network.Acceptor.run(SocketServer.scala:403)
        at java.lang.Thread.run(Thread.java:748)

再追溯到前面一点儿的日志文件内容，前辈说是在commit偏移量的时候产生的报错

1
2

[2022-04-23 16:06:59,117] ERROR Error while writing to checkpoint file /usr/local/kafka/log/kafka/log-start-offset-checkpoint (kafka.server.LogDirFailureChannel)
java.io.FileNotFoundException: /usr/local/kafka/log/kafka/log-start-offset-checkpoint.tmp (Too many open files)

0x03.恢复服务

首先释放硬盘空间，删除这两天内过大的日志文件

1 2	rm -rf server.log.2022-04-23* rm -rf server.log.2022-04-24*

0x04.增大文件描述符限制

参照官方文档：OS
File descriptor limits: Kafka uses file descriptors for log segments and open connections. If a broker hosts many partitions, consider that the broker needs at least (number_of_partitions)*(partition_size/segment_size) to track all log segments in addition to the number of connections the broker makes. We recommend at least 100000 allowed file descriptors for the broker processes as a starting point. Note: The mmap() function adds an extra reference to the file associated with the file descriptor fildes which is not removed by a subsequent close() on that file descriptor. This reference is removed when there are no more mappings to the file.
参照：kafka 中遇到的问题
对于一个高并发高性能的应用来说，1024或者4096的文件描述符限制未免太少，可以适当的调大这个参数。比如使用ulimit -n 65535命令将上限提高到65535，这样足以应对大多数的应用情况

因为是Kafka是用systemd来启动的，所以修改/etc/sysctl.conf或者/etc/security/limits.conf对其是不生效的，因为它仅对PAM登录的用户生效

首先systemctl status kafka定位到单元文件的位置
然后vim kafka.service增加LimitNOFILE=65535一行
最后systemctl daemon-reload
再次systemctl start kafka看到启动成功了，松了一口气

当然，重启之后还是要看一下文件描述符的限制是否变大了

首先ps -ef | grep kafka可以过滤到两个PID，其中一个是Kakfa，另一个是Zookeeper
然后cat /proc/<Kakfa_PID>/limits查看Max Open Files值是65535就没有问题啦

最后，也可以通过lsof -p <Kakfa_PID> | wc -l查看占用了多少个文件描述符

0x05.限制日志文件大小

万万没想到的是，谷歌Kafka 日志出来的结果全是针对于数据的设置，而不是日志的设置……
经过不懈努力终于找到一篇medium的看上去还算靠谱的文章：Kafka Limit Server Logs，需要修改Kafka路径下config文件夹中的log4j.properties配置文件

把log4j.appender.kafkaAppender=org.apache.log4j.RollingFileAppender改成log4j.appender.kafkaAppender=org.apache.log4j.DailyRollingFileAppender
这样就不是按日切分，而是可以按照大小和个数切分

追加MaxFileSize和MaxBackupIndex限制

1 2	log4j.appender.kafkaAppender.MaxFileSize=500MB log4j.appender.kafkaAppender.MaxBackupIndex=10

最后systemctl restart kafka重启生效

备注：kafkaAppender默认输出的是server.log，其他log暂未修改？

0x06.后记

部署文档没写好，现网翻车火葬场
其实恢复Kafka很快就搞完了，但是果不其然systemctl start mariadb又failed了淦，直到晚上八点多才恢复正常（中途远程设备电量不足提前倒下，被迫暂停了一段时间
自己好心疼前辈刚集中隔离结束回家但晚上还在远程，不过关于MariaDB Galera Cluster的话题，还是再单拎出一篇文章来讲吧（继续挖坑

0x07.引用

Kafka too many open files解决
 kafka too many open files的解决方法

评论区已关闭 (╯‵□′)╯︵┻━┻

推荐订阅源

远哥制造