科普时间
IBM AIX(Advanced Interactive eXecutive)是IBM开发的一套UNIX操作系统,也可称为 AIX。它可以在所有的IBM ~ p系列和IBM RS/6000工作站、服务器和大型并行超级计算机上运行。
难用的 AIX
已经不记得上一次体验 AIX 是什么时候了,最近刚好在客户的一个项目上,需要采集 AIX 系统的日志,重新接触了一把 AIX 系统,AIX 系统的操作体验和 Linux 相比实在太糟糕,如果不是买了 IBM 的各种套装,我相信没有人会想要自虐装个 AIX 吧。
采集方案
Beats?
要是论普通日志的采集,首先考虑的当然是 Beats 家族的 Filebeat 啦,基于 Go 语言编写,能够生成非常小的没有依赖的二级制执行程序,拷贝到服务器上就能运行,不过坑爹的是 Golang目前还没有正式支持 AIX 下的编译。从这里可以追踪Golang 社区进展:https://github.com/golang/go/issues/25893,看样子 2019 年是没有机会看到 Filebeat 提供 AIX 下的安装包了。
Syslog?
既然 AIX 是 Unix,那么我们可以考虑一下 Syslog 啊,Syslog 历史悠久,肯定能工作,给 Logstash 配置一个 Syslog Input,监听任意一个端口,然后 syslog 转发日志到 Logstash 的这个端口,可以看到数据都能正常采集进来,系统级别的日志采集算是搞定了,不过这些日志都是 syslog 协议的系统内的日志,那应用程序自己写的日志呢?抱歉,Syslog 不支持,因为 Syslog 没有办法指定自己的日志路径。额。。。
RSyslog
除了系统日志,应用日志才是主角啊,Syslog 不支持自定义日志路径,那也有办法,就是使用 RSyslog 啊,全称是 og new generation 也就是下一代的 Syslog。完全兼容 Syslog,也支持很多新功能,如支持按消息内容过滤,支持自定义日志路径的模块等。
不过看到这一句 RSyslog 的版本限制,又凉凉了:
rsyslog is now on the expansion pack of the two main aix versions i work on. The minimum server level is :
6.1.8.0 : AIX 6.1, TL8, SP0
7.1.2.0 : AIX 7.1, TL2, SP0
目标服务器的版本是:7.1.0.0,不在支持安装 rsyslog 的最低版本范围内,命运女神再一次擦肩而过。
Logstash?
好吧,再想想别的方案,Logstash 怎么样?基于 Java 的,跨平台嘛,从Elastic 产品的支持矩阵里面可以找找最新的支持情况:
https://www.elastic.co/support/matrix
坏消息是没有找到 AIX 的支持清单,好消息是也没说不支持 AIX,总得试试才知道,拷贝Logstash 安装包过去一运行,第一个启动脚本就不支持。。。目测如果继续折腾要看看 JDK、JRuby 的支持情况,还需要从启动脚本起开始调试,果断放弃。
Python 脚本?
对 Python 无爱,世上管理依赖最烂的语言,如果有其他方案,果断放弃。
Logstash-forwarder-java?
突然记起还有一个 java 的 Logstash-forwarder 的小东西,虽然很旧了,看样子能解决问题,Logstash-forwarder 最早是 Logstash 用 Go 写的一个小工具,只是用来采集数据,后面被 Filebeat 接管过去就没继续了,还产生了一个叫做 Lumberjack 的副产物,就是一个自定义的日志传输协议,支持压缩,结构紧凑。社区有一个Java 版本的客户端实现,地址:
https://github.com/didfet/logstash-forwarder-java。好吧,直觉告诉我,这个应该有戏。
初次尝试
因为 Logstash-Forwarder 用了一个自己的轮子协议,而 Logstash 没有自带这个 Input,所以需要单独下载安装一个名为:logstash-input-lumberjack 的插件(隐隐觉得哪里有点不对劲),而服务器上当然没有办法安装插件,需要离线准备一个插件包,具体方法如下:
bin/logstash-plugin install logstash-input-lumberjack
bin/logstash-plugin prepare-offline-pack logstash-input-lumberjack
在 Logstash 目录,首先执行上面的第一个命令用来下载安装这个插件,然后执行上面第二个的命令来准备离线插件安装包,得到一个 zip 包:http://logstash-offline-plugins-7.4.1.zip,待会后面会用到这个 zip 包。
在服务器上通过下面的方法来安装这个 zip 包,如下:
$ ./bin/logstash-plugin install file:///tmp/logstash-offline-plugins-7.4.1.zip
重启 Logstash 让插件生效,然后新增一个 Lumberjack 的管道,定义如下的 Input:
input {
lumberjack {
port => 5033
ssl_certificate => "/opt/logstash-7.4.1/config/certs/logstash-forwarder.crt"
ssl_key => "/opt/logstash-7.4.1/config/certs/logstash-forwarder.key"
codec => plain { charset => "GB2312" }
}
}
filter {
}
output {
stdout {}
}
因为使用了加密的通道,需要配置一对公私钥证书,生成方法:
openssl req -subj '/CN=localhost/' -x509 -batch -nodes -newkey rsa:2048 -keyout logstash-forwarder.key -out logstash-forwarder.crt -days 1095
接下来就是采集端的设置了,客户端同样需要证书,不过需要使用另外一种格式,可以通过下面的命令来进行生成:
keytool -importcert -trustcacerts -file logstash-forwarder.crt -alias ca -keystore keystore.jks -noprompt
拷贝 Logstash-Forwarder-Java 的程序包和 keystore.jks 文件到 AIX 服务器上,首先需要确保 Java 环境,确认 JAVA JDK 为 1.6,目测一切正常,新增一个采集端的配置文件 config.json:
{
"network":{
"servers":["LogstashIP:5033"],
"ssl ca": "/homoe/elastic/logstash-forwarder-java-0.2.4/keystore.jks"
},
"files":[
{
"paths":["/homoe/log/*.log","/var/log/*/*.log"],
"fields":{"labels.application":"aix-system"}
}
]
}
执行如下命令启动这个 Jar 包,如下:
java -jar logstash-forwarder-java-0.2.4.jar -config config.json
采集端输出正常,Logstash 也能看到日志出现了,so far so good.
出问题了
高兴还没三分钟,Logstash 服务端提示我别得意太早,警告我如下:
[2019-12-17T12:59:12,744][WARN ][logstash.inputs.lumberjack][aix-logstash-input] Lumberjack input: The circuit breaker has detected a slowdown or stall in the pipeline, the input is closing the current connection and rejecting new connection until the pipeline recover. {:exception=>LogStash::CircuitBreaker::HalfOpenBreaker}
[2019-12-17T12:59:12,789][WARN ][logstash.inputs.lumberjack][aix-logstash-input] Lumberjack input: the pipeline is blocked, temporary refusing new connection.
[2019-12-17T12:59:12,982][WARN ][logstash.inputs.lumberjack][aix-logstash-input] Lumberjack input: The circuit breaker has detected a slowdown or stall in the pipeline, the input is closing the current connection and rejecting new connection until the pipeline recover. {:exception=>LogStash::CircuitBreaker::OpenBreaker}
[2019-12-17T12:59:13,290][WARN ][logstash.inputs.lumberjack][aix-logstash-input] Lumberjack input: the pipeline is blocked, temporary refusing new connection.
[2019-12-17T12:59:13,790][WARN ][logstash.inputs.lumberjack][aix-logstash-input] Lumberjack input: the pipeline is blocked, temporary refusing new connection.
大意就是这个 Logstash 管道堵住了,无法继续处理更多请求,而 Logstash-Forwarder 端也是大量报错,如下:
2019-12-17 14:15:11,992 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:11,999 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,005 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,012 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,022 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,028 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,035 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,041 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
2019-12-17 14:15:12,047 ERROR Forwarder - Failed to connect to server SOMEIP:5033 : A remote host refused an attempted connect operation. (Connection refused)
难道是有死锁,Jstack -F 可以看到当前 Logstash 进程存在大量 block 住的线程,不过没有死锁:
Thread 37120: (state = BLOCKED)
- sun.misc.Unsafe.park(boolean, long) @bci=0 (Compiled frame; information may be imprecise)
- java.util.concurrent.locks.LockSupport.parkNanos(java.lang.Object, long) @bci=20, line=215 (Compiled frame)
- java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(java.util.concurrent.SynchronousQueue$TransferStack$SNode, boolean, long) @bci=160, line=460 (Compiled frame)
- java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.lang.Object, boolean, long) @bci=102, line=362 (Compiled frame)
- java.util.concurrent.SynchronousQueue.poll(long, java.util.concurrent.TimeUnit) @bci=11, line=941 (Compiled frame)
- java.util.concurrent.ThreadPoolExecutor.getTask() @bci=134, line=1066 (Compiled frame)
- java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=26, line=1127 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=617 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=745 (Interpreted frame)
Thread 37119: (state = BLOCKED)
- sun.misc.Unsafe.park(boolean, long) @bci=0 (Compiled frame; information may be imprecise)
- java.util.concurrent.locks.LockSupport.parkNanos(java.lang.Object, long) @bci=20, line=215 (Compiled frame)
- java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(java.util.concurrent.SynchronousQueue$TransferStack$SNode, boolean, long) @bci=160, line=460 (Compiled frame)
- java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.lang.Object, boolean, long) @bci=102, line=362 (Compiled frame)
- java.util.concurrent.SynchronousQueue.poll(long, java.util.concurrent.TimeUnit) @bci=11, line=941 (Compiled frame)
- java.util.concurrent.ThreadPoolExecutor.getTask() @bci=134, line=1066 (Compiled frame)
- java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=26, line=1127 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=617 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=745 (Interpreted frame)
Thread 37066: (state = BLOCKED)
- sun.misc.Unsafe.park(boolean, long) @bci=0 (Compiled frame; information may be imprecise)
- java.util.concurrent.locks.LockSupport.parkNanos(java.lang.Object, long) @bci=20, line=215 (Compiled frame)
- java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(java.util.concurrent.SynchronousQueue$TransferStack$SNode, boolean, long) @bci=160, line=460 (Compiled frame)
- java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.lang.Object, boolean, long) @bci=102, line=362 (Compiled frame)
- java.util.concurrent.SynchronousQueue.poll(long, java.util.concurrent.TimeUnit) @bci=11, line=941 (Compiled frame)
- java.util.concurrent.ThreadPoolExecutor.getTask() @bci=134, line=1066 (Compiled frame)
- java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=26, line=1127 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=617 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=745 (Interpreted frame)
时间不等人,在客户现场首要的任务是要尽快解决问题,以 Lumberjack Block 等关键字搜了一下,发现类似的问题存在很久也一直没有得到解决,看来这里有坑且很深,Lumberjack Input 是 JRuby 写的,代码分析起来比较麻烦,没有时间做研究了,继续想办法。
一顿爆改
看来目前出问题的在 Logstash 端,重启之后能稳定几分钟,是不是有种脑血栓的感觉,看样子主要还是 Lumberjack Input 代码的问题,既然都是 TCP,不如在现有的 Logstash-Forwarder-Java 版本上把 Lumberjack 的协议替换为原始的 TCP,Logstash 的 TCP input 用了很多地方了,非常稳定,说干就干,开始一顿爆改。
Logstash-Forwarder-Java 的代码结构还算比较清晰,Lumberjack 协议抽象了一个接口,现在只需要实现一个新的协议就可以了。
有一些不兼容的结构类型暂时兼容新的 TCP 协议,去掉压缩等额外操作,打包编译输出。
顺手 Fix 一个 Bug
在测试的时候,在 /tmp目录下面放了一个文件,本地启动了一个 Logs 进行调试,结构发现生成的记录文件读取状态的元数据文件不正确,原来 mac 下面的/tmp目录,实际的目录是 /private/tmp,算是一个软连接或者别名。而 Logstash-forwarer-java 没有处理软连接的问题,代码里面有些处理成了最终的文件路径,有些没有,结果就造成了两个路径一个文件的问题,这样就会存在每次都读取多份数据,且读取游标无法持久化的问题,一顿代码修改,统一了文件的命令使用方式,元数据正确保存且内容自然就去重了。
重新编译打包,在 AIX 机器上使用新的 Logstash-Forwarder-Java 程序。
Logstash 的 Pipeline 则修改使用 TCP Input,如下:
input {
tcp {
port => 5033
ssl_cert => "/opt/logstash-7.4.1/config/certs/logstash-forwarder.crt"
ssl_key => "/opt/logstash-7.4.1/config/certs/logstash-forwarder.key"
ssl_verify => false
tcp_keep_alive => true
codec => json_lines { charset => "GB2312" }
}
}
经过修改后的 Logstash-Forwarder-Java 和 Logstash 的 TCP Input 配合良好,平稳运行。
新的麻烦
这不,在另外的一台 AIX 服务器部署的时候,发现操作系统版本更老,JDK 版本又不一样,是 1.5 的版本,如果要修改代码来适配 1.5 就麻烦了,不过通过采用嵌入一个 1.6 JRE 的方法,完美解决!
后记
作为 Consultant,你永远不知道会有什么样的环境等着你,有很多代码其实没有你想象的那么完美,很多产品,你要相信一定会有没有测试到的地方,且一定会有很多坑在等着你,没有办法,只能见招拆招,要允许这些不完美的出现。相关的代码和打好的包都放在这个仓库了:https://github.com/medcl/logstash-forwarder-java