误操作引起的Logstash重复收集

当需要做一个日志系统时,可能第一时间会想到ELK全家桶。
ELK分别表示:Elasticsearch , Logstash, Kibana 。他们组成了一套完整的日志系统的解决方案,方便我们使用。

  • Logstash 对各个服务的日志进行采集、过滤、推送。
  • Elasticsearch 存储Logstash传送的结构化数据,提供给Kibana。
  • Kibana 提供用户UIweb页面进行,数据展示和分析形成图表等

在使用Logstash进行收集的时候,仅仅需要简单的一个配置文件就可以启动一个logstash-agent来进行日志收集。

input {
        file {
                type => "test"
                path => ["/home/hadoop/hao.zhang/logstashTest/1.txt"]
                sincedb_path => "/home/hadoop/elk/logstash-agent/conf/datafall/test_sincedb"
        }
}
output{
     stdout {
   }
}

上述示例简单的从某个文件目录下收集日志打印到控制台。

然后我们启动这个logstash-agent:bin/logstash -f conf/datafall/test.config

往日志文件push数据:
echo "hello world" >> 1.txt

就可以看到控制输出:

172.20.33.5:hadoop@sz-pg-dm-it-001:/home/hadoop/elk/logstash-agent]$ bin/logstash  -f conf/datafall/test.config
Settings: Default pipeline workers: 40
Pipeline main started
2019-05-07T12:17:37.113Z sz-pg-dm-it-001.tendcloud.com hello world

到此时是正确的一个流程。

误操作开始了:

但是我们以vim命令进入日志文件的时候,在文件末尾追加一个数据happy,此时控制台会输出:

[172.20.33.5:hadoop@sz-pg-dm-it-001:/home/hadoop/elk/logstash-agent]$ bin/logstash  -f conf/datafall/test.config
Settings: Default pipeline workers: 40
Pipeline main started
2019-05-07T12:17:37.113Z sz-pg-dm-it-001.tendcloud.com hello world
2019-05-07T12:22:58.313Z sz-pg-dm-it-001.tendcloud.com hello world
2019-05-07T12:22:58.314Z sz-pg-dm-it-001.tendcloud.com happy

会发现logstash会从文件开始从新读取数据(此时就会造成数据的重复收集)。

为什么会出现这种情况呢?

Logstash有一个有趣的组件或功能叫做sincedb。该文件存储了当前logstash-agent收集的文件日志的offset。在前面test.config配置了sincedb的位置。
如果不配置,它会默认在当前用户的根目录下创建一个.sincedb开头的文件

sincedb的具体内容:

[172.20.33.5:hadoop@sz-pg-dm-it-001:/home/hadoop/elk/logstash-agent/conf/datafall]$ cat test_sincedb
4306020249 0 2052 12
4306020236 0 2052 18
第一列是收集日志文件的inode
第二列、第三列是当前设备的一些值(先不用关心)。
第四列是已收集文件日志的offset。

每一行代表一个日志文件。

看到上述内容,发现我们明明只收集了一个日志文件,为什么会又多出来一条记录呢。

这就要追述到使用vim命令编辑文件并保存时。相当于会创建拥有全新inode的文件。

此时logstash会发现一个文件名一样但是inode却不一样的文件。logstash还是会进行文件的收集工作。
通过debug模式可以看到更详细的细节:

each: new inode: /home/hadoop/hao.zhang/logstashTest/1.txt: old inode was ["4306020236", 0, 2052], new is ["4305990263", 0, 2052] {:level=>:debug, :file=>"filewatch/watch.rb", :line=>"245", :method=>"each"}
:delete for /home/hadoop/hao.zhang/logstashTest/1.txt, closing file {:level=>:debug, :file=>"filewatch/observing_tail.rb", :line=>"52", :method=>"subscribe"}
_open_file: /home/hadoop/hao.zhang/logstashTest/1.txt: opening {:level=>:debug, :file=>"filewatch/tail_base.rb", :line=>"86", :method=>"_open_file"}
Received line {:path=>"/home/hadoop/hao.zhang/logstashTest/1.txt", :text=>"hello world", :level=>:debug, :file=>"logstash/inputs/file.rb", :line=>"306", :method=>"log_line_received"}
Pushing flush onto pipeline {:level=>:debug, :file=>"logstash/pipeline.rb", :line=>"458", :method=>"flush"}
Received line {:path=>"/home/hadoop/hao.zhang/logstashTest/1.txt", :text=>"happy", :level=>:debug, :file=>"logstash/inputs/file.rb", :line=>"306", :method=>"log_line_received"}
Received line {:path=>"/home/hadoop/hao.zhang/logstashTest/1.txt", :text=>"happy", :level=>:debug, :file=>"logstash/inputs/file.rb", :line=>"306", :method=>"log_line_received"}
writing sincedb (delta since last write = 1557233399) {:level=>:debug, :file=>"filewatch/observing_tail.rb", :line=>"102", :method=>"observe_read_file"}
filter received {:event=>{"message"=>"hello world", "@version"=>"1", "@timestamp"=>"2019-05-07T12:49:59.108Z", "path"=>"/home/hadoop/hao.zhang/logstashTest/1.txt", "host"=>"sz-pg-dm-it-001.tendcloud.com", "type"=>"test"}, :level=>:debug, :file=>"(eval)", :line=>"17", :method=>"filter_func"}
filter received {:event=>{"message"=>"happy", "@version"=>"1", "@timestamp"=>"2019-05-07T12:49:59.116Z", "path"=>"/home/hadoop/hao.zhang/logstashTest/1.txt", "host"=>"sz-pg-dm-it-001.tendcloud.com", "type"=>"test"}, :level=>:debug, :file=>"(eval)", :line=>"17", :method=>"filter_func"}
filter received {:event=>{"message"=>"happy", "@version"=>"1", "@timestamp"=>"2019-05-07T12:49:59.118Z", "path"=>"/home/hadoop/hao.zhang/logstashTest/1.txt", "host"=>"sz-pg-dm-it-001.tendcloud.com", "type"=>"test"}, :level=>:debug, :file=>"(eval)", :line=>"17", :method=>"filter_func"}
output received {:event=>{"message"=>"hello world", "@version"=>"1", "@timestamp"=>"2019-05-07T12:49:59.108Z", "path"=>"/home/hadoop/hao.zhang/logstashTest/1.txt", "host"=>"sz-pg-dm-it-001.tendcloud.com", "type"=>"test"}, :level=>:debug, :file=>"(eval)", :line=>"22", :method=>"output_func"}
output received {:event=>{"message"=>"happy", "@version"=>"1", "@timestamp"=>"2019-05-07T12:49:59.116Z", "path"=>"/home/hadoop/hao.zhang/logstashTest/1.txt", "host"=>"sz-pg-dm-it-001.tendcloud.com", "type"=>"test"}, :level=>:debug, :file=>"(eval)", :line=>"22", :method=>"output_func"}
output received {:event=>{"message"=>"happy", "@version"=>"1", "@timestamp"=>"2019-05-07T12:49:59.118Z", "path"=>"/home/hadoop/hao.zhang/logstashTest/1.txt", "host"=>"sz-pg-dm-it-001.tendcloud.com", "type"=>"test"}, :level=>:debug, :file=>"(eval)", :line=>"22", :method=>"output_func"}
2019-05-07T12:49:59.108Z sz-pg-dm-it-001.tendcloud.com hello world
2019-05-07T12:49:59.116Z sz-pg-dm-it-001.tendcloud.com happy
2019-05-07T12:49:59.118Z sz-pg-dm-it-001.tendcloud.com happy
Pushing flush onto pipeline {:level=>:debug, :file=>"logstash/pipeline.rb", :line=>"458", :method=>"flush"}

从上述日志可以看出logstash会产生监控到一个新的inode文件,并且在原有sincedb文件中并没有这个inode记录,因此logstash会从头开始收集这个日志文件中的日志。

当我们在使用logstash收集日志文件时,尽量不要用Vim、vi命令去打开日志文件,尽量使用cat、more这之类的。

注:
inode: 操作系统中的文件数据都储存在"块"中,当然,我们还必须找到一个地方储存文件的元信息,比如文件的创建者、文件的创建日期、文件的大小等等。这种储存文件元信息的区域就叫做inode,中文译名为"索引节点"
inode包含文件的元信息,具体来说有以下内容:

  • 文件的字节数
  • 文件拥有者的User ID
  • 文件的Group ID
  • 文件的读、写、执行权限
  • 文件的时间戳,共有三个:ctime指inode上一次变动的时间,mtime指文件内容上一次变动的时间,atime指文件上一次打开的时间。
  • 链接数,即有多少文件名指向这个inode
  • 文件数据block的位置

一般情况下,文件名和inode号码是"一一对应"关系,每个inode号码对应一个文件名。

vim、vi:为什么在编辑的时候会产生一个新的inode: 在使用vim打开文件是,会把当前打开的文件放入buffer中(内存),然后进行操作。当我们保存时,相当于替换了原来的文件。所以会有个新的inode的文件产生。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 218,036评论 6 506
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 93,046评论 3 395
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 164,411评论 0 354
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,622评论 1 293
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,661评论 6 392
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,521评论 1 304
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,288评论 3 418
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,200评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,644评论 1 314
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,837评论 3 336
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,953评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,673评论 5 346
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,281评论 3 329
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,889评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,011评论 1 269
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,119评论 3 370
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,901评论 2 355

推荐阅读更多精彩内容