Logstash无法读取文件的更新内容

最近工作中正在用ELK搭建一套数据平台,通过Logstash(以下简称LS)读取文件的内容,然后同步给ES。文件的内容是用Python脚本生成的,文件名一直不变,即每次Python脚本是往同一个文件里覆盖的去写,demo如下:
python demo t.py

import json

lst = list()
for i in range(3):
    lst.append(dict(a=i+1, b=4.3, c='world', date=1554972722911))
fi = '/Applications/logstash-5.6.3/test1.json'
with open(fi, 'w') as f:
    f.write(json.dumps(lst))

Logstash demo t.conf

input {
    file {
        path => "/Applications/logstash-5.6.3/test1.json"
        start_position => "beginning"
        codec => "json"
    }
}
filter {
    date {
        match => [ "date", "MMM dd yyyy HH:mm:ss", "UNIX_MS" ]
        timezone => "Asia/Shanghai"
        target => "date"
    }
}
output {
    elasticsearch {
        hosts => ["xx.xx.xx.xx:8080"]
        index => "t_l-%{+YYYY.MM.dd}"
        document_type => "tt"
        manage_template => false
        template_name => "t_temp"
    }
}

结果超级诡异的现象出现了!!LS并不读取文件的内容,只有手动vim去修改一下文件,LS才会读数据。
最开始以为是file input插件的参数那里设置的不对,然后在官方的社区里搜到了这个问题https://discuss.elastic.co/t/file-plugin-doesnt-read-file/49052/3,提问者的问题跟我一模一样,下面有人回答是ignore_older参数捣的鬼,然后提问那哥们把ignore_older参数值改了后,问题解决了。我以为这就找到答案了,就去看ignore_older参数的定义,摘抄如下:

ignore_older

ignore_older的作用就是设置一个时长来让LS忽略文件。比如这个参数设置为1小时,那Logstash就会忽略到当前为止已经超过1小时没有任何修改的文件,即只会读取1小时内有修改的文件。这个参数主要是用来屏蔽时间久远的log文件。
当前官方最新插件说这个参数默认是关闭的,即不起作用,上面的答案说这个参数默认是1天(插件版本不一致)。
然后我发现这个参数跟我的问题没啥关系,因为我现在的demo是立马更新文件,即时间绝对在1天内,但LS还是忽略这个文件了。
无奈从头开始详读input file插件文档,在Tracking_of_current_position_in_watched_files中了解到,file插件是通过一个叫sincedb的文件来保存Logstash已经读取的文件,以及上一次读取文件时的最后一个位置(方便下一次接着该位置继续往下读)。所以我该从sincedb入手查问题,在data目录下找到sincedb文件:

➜  file pwd
/Applications/logstash-5.6.3/data/plugins/inputs/file
➜  file ll
total 8
drwxr-xr-x  3 ivanli  admin  102  4 19 16:39 ./
drwxr-xr-x  3 ivanli  admin  102  4 18 15:12 ../
-rw-r--r--  1 ivanli  admin   17  4 19 16:39 .sincedb_34488dda9a79102a6b4436bfb0f592d2

https://discuss.elastic.co/t/logstash-sincedb-files/95297/2中详细说明了.conf文件中的path参数中的每一个路径对应1个sincedb文件,如果文件路径有通配符,如“/Applications/logstash-5.6.3/test.json”,则Logstash会把读取test.json文件的相关信息统一放在一个sincedb文件中,而不是每一个文件一个sincedb文件。
另外这个链接里也说了LS读取文件的规则,这个稍后再说。先看下sincedb文件的内容:

➜  file cat .sincedb_34488dda9a79102a6b4436bfb0f592d2
13326659 1 2 172

文件里一行数据包含4个数,分别代表inode number、major device number、minor device number和current byte offset。
其中inode,major device,minor device是操作系统的文件系统的概念。current byte offset表示上一次文件读取的位置。
Logstash不读取文件的问题就出在inode上。简单理解,inode记录一个文件的属性,如文件的字节数、userId、groupId,读写执行权限等。一个文件对应一个inode。
上面的链接中说了LS读取文件和inode的关系,引用如下:

Be aware of the INODE reuse problem. Background: the sincedb tracks read content position by INODE, because during file rotation (different techniques have different effects), the name of the log file may change but its INODE does not. Eventually as files are created and deleted inevitably an INODE will be reused and if by chance that INODE has been seen before via a log file name that once satisfied the glob pattern, LS will think it has read the file before. Two things can happen here 1) the new file is smaller than the last-read point then LS will detect this and start from the beginning (assumes rotation) and 2) the new file is bigger than the last-read point then LS will read from the last-read point on. This random unfortunate situation is difficult to foresee and to code for and leads to very confused OPS people.

即当文件滚动(rotation,参考:logrotate机制和原理)的时候,文件的inode是不会变化的,这时:

  • 文件的内容小于上一次文件读取的位置时,LS会从头(beginning)开始读文件内容;
  • 文件的内容大于上一次文件读取的位置时,LS会从上一次文件读取的位置开始读文件内容。

所以,之前我本地测试Py demo的时候,每次往同一个文件里覆盖写的内容是一模一样的,文件大小没有变化,所以LS不会去读文件的内容。只要每次文件更新的内容造成文件大小有变化,LS就可以读数据了,但这也不符合我的需求。毕竟每次我写的都是全新的内容,而且新写的内容可能和上一次的内容是一模一样的(业务上的要求),这样LS就不读数据了。另外,即使内容不完全一样,若新的内容大于offset的话,LS读取出来的内容是不全的(因为从上一次的offset开始读,前面的内容忽略了)。

又在这个链接中https://discuss.elastic.co/t/logstash-is-not-reading-the-log-file-thats-being-updated-automatically-continuously/92686/7看到文件重读的机制:

The file input rereads a file if
its inode number changes, or
if the file shrinks (indicating that it was rotated via copy/truncate).
The file input does not support other means of detecting changes in a file.

一是文件的inode变化了,即新生成一个文件;二是如之前所说的文件rotate。
所以可以通过每次都往一个新文件里写内容(新的inode),在.conf中使用通配符:

input {
    file {
        path => "/Applications/logstash-5.6.3/test*.json"
        start_position => "beginning"
        codec => "json"
    }
}

这样,sincedb会新增一行记录新inode的内容,新文件的内容也可以全部被Logstash读取了。
这也解释了为什么之前需要我手动去编辑一下文件,就可以被Logstash读取了,因为每次编辑后,文件的inode就已经变化了。
可以试一下:

➜  logstash-5.6.3 stat test1.json
16777218 13326659 -rw-r--r-- 1 ivanli admin 0 572 "Apr 19 17:48:39 2019" "Apr 19 17:48:34 2019" "Apr 19 17:48:34 2019" "Apr 19 16:39:35 2019" 4096 8 0 test1.json

在mac上,源文件的inode号是13326659,然后vim编辑下文件(随便改1个数),再保存:

➜  logstash-5.6.3 vim test1.json
➜  logstash-5.6.3 stat test1.json
16777218 13334123 -rw-r--r-- 1 ivanli admin 0 572 "Apr 19 18:16:47 2019" "Apr 19 18:16:46 2019" "Apr 19 18:16:46 2019" "Apr 19 18:16:46 2019" 4096 8 0 test1.json

发现文件的inode号变成13334123了,对于LS来说是一个新文件,内容全部被读。 至于vim为啥会改变文件的inode号:

So the inode is unchanged. In Vim, as cjm has already stated, the choice is controlled by the backup , backupcopy and writebackup options. By default, Vim renames the old file, then writes a new file with the original name, if it thinks it can re-create the original file's attributes.

即vim修改文件的背后机制是重命名该文件,然后新建一个文件和源文件名一样,再把原文件的内容写入新建文件里。

虽然因为本地测试每次写的都是同样的内容导致在解决问题的道路上绕了一大圈,但也通过这一大圈了解了LS读取文件的机制,总比稀里糊涂的用要好很多吧,而且在这个过程中了解了inode,还有rotate,收获也不小~