项目地址是:https://github.com/fanfank/timecat
安装办法很大略,只要你装了Python 2,那么可以直接在命令行实行如下pip命令:
pip install timecat
或者直接下载源码中的timecat,实行即可。
0 背景
在开始之前,前辈行提问:
假设给你一个日志文件 A.log
,它的大小达到了28G
日志的起始韶光为 Jan 1 00:00:00
,日志的结束韶光为 Jan 1 23:59:59
现在哀求你从中找出 1月1号20点13分14秒
到 1月1号20点14分13秒
的所有日志并输出
你会怎么做?
目前头条的线上环境中,大部分日志切分是按照一天一次的办法进行。也便是说,在每台机器上2016年1月2号的日志全部打到一个文件,2016年1月3号的日志全部打到一个文件,目前我看到最大的一个单一日志文件,大小便是28G。
连续上面的例子,现在我们要在线上的所有机器上,搜 20点13分14秒
到 20点14分13秒
之间的这个日志中的某个关键字,并且把包含这个关键字的日志都输出。如果偷点
并且,我们终极是要搜索线上的(部分或所有)机器,该当尽可能减少实行操作时对机器的影响。
以是,我们有几个基本的思路:
碰到非搜索韶光段内的日志时,直接跳过;
只管即便减少对日志文件内容的逻辑判断,过多的判断会造成韶光和CPU的摧残浪费蹂躏。
1 思路
还是以上面的例子连续思考。
实在可以这样,我们用awk命令去获取每一行的日期韶光:
当创造日期韶光小于1月1号20点13分14秒,就直接跳过不处理;
当创造日期韶光在这个区间 [1月1号20点13分14秒, 1月1号20点14分13秒 ),那么就用正则或者用grep去匹配一下有没有对应关键字,有就直接输出;
当创造日期韶光大于即是1月1号20点14分13秒,就直接退出程序。
看起来没啥问题,能省的彷佛都省了不少。不过还是不足,由于所有韶光小于20点13分14秒的行,实际是没有必要读取的,同时在目标韶光段内所有日志行,都进行了读取韶光日期的操作。
如果日志文件本身是有序的,这些实际是可以省的,我只须要知道起始韶光和结束韶光在文件中的位置即可,然后读取这两个位置之间的内容并匹配关键字就行。
要直接对有序的内容进行元素定位,最好的办法之一便是利用二分查找。
2 难点与细节
思路都有,便是细节比较多,以下列出几个。
与传统的二分搜索不一样,日志文件中的每一条日志长度都是不一样的,我们利用 mid = start + (end - start) / 2
得到mid时,并不直接指向一行的行首。以是我们须要找到mid
所在行的行首。
要解决死循环的问题,哪怕mid
的值前后不一样,但是mid
指向的行可能是一样的。
日志文件中可能包含造孽的日志行,例如Python业务中,有些地方利用logging.exception(\"大众...\公众)
打印出来的调用栈便是多行的,而且每一行还没有日期韶光。
有的日志文件可能是按升序排的,有的日志文件可能是按降序排的,这两种排序利用的比较运算是不一样的。
不同的日志文件可能有多种不同的日期韶光格式,须要对这些日期韶光进行格式判断。而且有的日期韶光格式之间不能直接比较,例如 Jan 01 18:00:00
与 Apr 01 19:00:00
,谁比较大呢?直接按照字典序来说肯定是 Jan 01 18:00:00
这个日期大,而实际不是如此,类似的例子还有 12/30/2014 19:00:00
与 11/25/2015 20:00:00
。
当mid
所对应的日志行为造孽行时,我们须要顺序向下查找合法的行,如果向下查找失落败,那么实际要从mid
开始倒序查找,须要办理从文件的一个位置开始倒序读取内容的问题。
3 利用timecat
timecat的命名借鉴了Linux的cat命令,利用也非常大略,只要你有Python 2.x的版本就可以。
3.1 获取timecat
有三种办法获取timecat
,分别是用pip
,用git
,或者直接下载源码。如果你利用的是git下载的办法,还能够直接运行demo文件夹下的demo.sh来查看实行效果。下面给出操作步骤。
通过pip获取
如果你安装了pip
那很赞(常日现在的Python都直接包含了pip),无论是在Mac还是在Linux上,都直接实行 pip install timecat
就可以了。
通过git获取
如果你没有安装pip
,但是有git,那么就利用这条命令直接下载timecat
的git仓库:
git clone https://github.com/fanfank/timecat.git
这个时候你可以直接运行一下demo程序查看效果,实行如下命令就可以:
cd timecat/demo && ./demo.sh
该当能够看到如下输出:
直接下载源码文件
实行下面这条命令把文件下载到当前路径:
wget https://raw.githubusercontent.com/fanfank/timecat/master/timecat
然后给timecat加上实行权限:
chmod +x ./timecat
大功告成,接下来就可以利用了。
3.2 小试牛刀
假设你的日志文件如下所示(大家不用看日志内容,只看开头的韶光日期即可):
2016-01-09 17:19:55 68692113882222190977560551 865969137578988688464537824 45127033797620 25268 19794311951 363339271218256312476
2016-01-09 17:19:57 620 57 9676957541840624 638946878393487926780486792 8264753419974059162790266 221945347
2016-01-09 17:19:59 521 131961372942259333254 72174142230175134322552 283404142112130755323294682
2016-01-09 17:20:01 688539156634 467523585 500308101641647812782 760638506088853897676640 939 9861232428742044437504409 821661638908811331 265388383605362517 959268249
2016-01-09 17:20:03 635661147810144176414432793 816603137738591 68545363157279891134139 819 637622125619812
2016-01-09 17:20:05 616173422373449362 585993672 503548 685861354202534861175935452 4554796537058443695487738
2016-01-09 17:20:07 7429683039795652999560918 620657930764
2016-01-09 17:20:09 852490805701941615 383656872473 663855723240467381814340 914191453104695977571 4585 9441078028601307763 441784374740 7755808594652491
2016-01-09 17:20:11 154442965727180531881 3970499952176505510 6696691180156818678 64049767649 729945176906
2016-01-09 17:20:13 86042599715952474756 58960950978864628731244377 317119182225941 895361413416520347 799808993563678401396 303544554690341508623796227 104901 568 430818129
上面的日志是我用随机数天生的,把这个日志保存为demo.log
。
这份文件中,日志的开始韶光是从 2016-01-09 17:19:55
到 2016-01-09 17:20:13
,我们通过以下三个任务来熟习timecat
。
任务1:获取2016-01-09 17:20:01 ~ 2016-01-09 17:20:03的日志
如果你是通过pip
获取timecat
,那么实行以下命令:
timecat -s '2016-01-09 17:00:00' -e '2016-01-09 17:20:03' ./demo.log
如果是通过git或者直接下载源码的办法获取,实行以下命令(下面不再赘述):
./timecat -s '2016-01-09 17:00:00' -e '2016-01-09 17:20:03' ./demo.log
实行完毕后,该当看到如下结果:
2016-01-09 17:19:55 68692113882222190977560551 865969137578988688464537824 45127033797620 25268 19794311951 363339271218256312476
2016-01-09 17:19:57 620 57 9676957541840624 638946878393487926780486792 8264753419974059162790266 221945347
2016-01-09 17:19:59 521 131961372942259333254 72174142230175134322552 283404142112130755323294682
2016-01-09 17:20:01 688539156634 467523585 500308101641647812782 760638506088853897676640 939 9861232428742044437504409 821661638908811331 265388383605362517 959268249
终极输出了从 17:19:55
到 17:20:01
的日志,为什么没有输出 17:20:03
的那行日志呢?由于timecat的韶光区间是左闭右开的,以是终极不包括 17:20:03
的日志。
从这个例子,我们知道了运行timecat只须要指定3个参数:
第一个参数是-s
参数,它表示希望timecat
获取日志的起始韶光;
第二个参数是-e
参数,它表示希望timecat
获取日志的终止韶光(不包括这个韶光本身);
第三个参数是文件的路径,这里可以指定多个文件路径。
以是利用起来是非常大略的,要把稳的是,-s
与-e
参数中指定的日期韶光格式,因该与日志中涌现的日期韶光格式同等。
timecat会自动判断日期韶光格式,无论你要搜的是syslog,nginx,apache,php,还是python等日志文件,都能自动判别出韶光的格式而无需你手动再敲一次。
任务2:获取2016-01-09 17:19:56 ~ 2016-01-09 17:20:00的日志
直接实行命令:
timecat -d '2016-01-09' -s '17:19:56' -e '17:20:00' ./demo.log
这时可以看到以下输出:
2016-01-09 17:19:57 620 57 9676957541840624 638946878393487926780486792 8264753419974059162790266 221945347
2016-01-09 17:19:59 521 131961372942259333254 72174142230175134322552 283404142112130755323294682
这次我们利用的命令参数有点不一样,用了一个新的-d
参数,这个参数实际是给大家偷
任务3:获取2016-01-09 17:20:10 ~ EOF的日志
EOF便是一贯到文件的末端。
实行以下命令:
./timecat -d '2016-01-09' -s '17:20:10' ./demo.log
得到的输出结果如下:
2016-01-09 17:20:11 154442965727180531881 3970499952176505510 6696691180156818678 64049767649 729945176906
2016-01-09 17:20:13 86042599715952474756 58960950978864628731244377 317119182225941 895361413416520347 799808993563678401396 303544554690341508623796227 104901 568 430818129
这次我们把-e
参数省了,以是timecat
就直接从起始韶光开始一贯读到EOF。
完成上面三个任务后,你就基本节制了timecat
的所有用法,是不是很随意马虎?
末了再说说其余两个参数:
一个是-v
参数,用来打印额外信息的,这些信息包括:二分查找的循环次数,全体二分查找过程中一共扫描了多少行内容,终极二分查找出来的日志起始位置和结束位置到底是哪里等;
令一个是--color
参数,用来在程序输出错误信息、提示信息时把笔墨颜色变成赤色、或者绿色,如果你运行timecat
后输出的内容是在命令行,那么可以加上这个参数,如果不是,那么不建议加这个参数。
4 性能测试 – Benchmark
是骡子是马,也得拉出来遛遛,到底timecat
是不是就比awk
、grep
要快,下面就进行一下测试。
4.1 测试环境与测试步骤解释
这次测试利用的日志文件来源于头条线上机器的真实日志的一部分,大小为5.9G,我将这个文件命名为6g.log
。
环境:
宿主机:MacBook Pro (Retina, 13-inch, Early 2015) 2.7 GHz Intel Core i5 8 GB 1867 MHz DDR3 Intel Iris Graphics 6100 1536 MB
虚拟机软件:VirtualBox Version 5.0.10 r104061
虚拟机系统:CentOS 7(Linux version 3.10.0-229.el7.x86_64 (builder@kbuilder.dev.centos.org) (gcc version 4.8.2 20140120 (Red Hat 4.8.2-16) (GCC) ) #1 SMP Fri Mar 6 11:36:42 UTC 2015),1024MB内存,1个CPU
测试流程:
实行sync,清空读写cache,让timecat查找6g.log中2015年12月25日9点钟的所有日志,并输出到『test_timecat.out』,得到资源花费、实行韶光等数据;
实行sync,清空读写cache,让grep查找6g.log中2015年12月25日9点钟的所有日志,并输出到『test_grep.out』,得到资源花费、实行韶光等数据;
实行sync,清空读写cache,让awk查找6g.log中2015年12月25日9点钟的所有日志,并输出到『test_awk.out』,得到资源花费、实行韶光等数据。
4.2 timecat测试
实行命令:
./clear_cache.sh && timecat -s \公众2015-12-25 09:00:00\"大众 -e \公众2015-12-25 10:00:00\"大众 -v \"大众/huge/6g.log\"大众 > test_timecat.out
————————————
测试结果:
总耗时(s):9.49
均匀CPU占用(%):71
User time(s):4.76
System time(s):2.05
Minor (reclaiming a frame) page faults:1,683
Major (requiring I/O) page faults:16
File system inputs(Byte):1,794,048
File system outputs(Byte):1,778,416
————————————
由于利用了-v
参数,以是输出的字节数比实际打印的日志内容多一点。
4.3 grep测试
实行命令:
./clear_cache.sh && grep \"大众2015-12-25 09:\公众 /huge/6g.log > test_grep.out
————————————
测试结果:
总耗时(s):16.31
均匀CPU占用(%):70
User time(s):3.81
System time(s):7.70
Minor (reclaiming a frame) page faults:299
Major (requiring I/O) page faults:6
File system inputs(Byte):11,735,800
File system outputs(Byte):1,778,408
————————————
4.4 awk测试
在这次测试中,我们利用的awk脚本如下:
#!/bin/awk
# @file: bench.awk
BEGIN {
st = \公众2015-12-25 09:00:00\"大众;
ed = \"大众2015-12-25 10:00:00\公众;
}
{
datetime = $2\公众 \"大众$3
if (datetime < st) {
next;
} else if (datetime >= ed) {
if (match(datetime, /\w{2}:\w{2}:\w{2}/, _) == 0) {
next;
} else {
exit 0;
}
} else {
print $0;
}
}
END {}
实行命令:
./clear_cache.sh && awk -f \公众/huge/bench.awk\"大众 \"大众/huge/6g.log\公众 > test_awk.out
————————————
测试结果:
总耗时(s):19.32
均匀CPU占用(%):85
User time(s):10.30
System time(s):6.27
Minor (reclaiming a frame) page faults:389
Major (requiring I/O) page faults:5
File system inputs(Byte):10,551,480
File system outputs(Byte):1,778,408
————————————
4.5 总体结果比拟
timecat,grep,awk的总体比拟如下:
————————————
总耗时(s):
timecat:9.49
grep:16.31
awk:19.32
均匀CPU占用(%):
timecat:71
grep:70
awk:85
User time(s):
timecat:4.76
grep:3.81
awk:10.30
System time(s):
timecat:2.05
grep:7.70
awk:6.27
Minor (reclaiming a frame) page faults:
timecat:1683
grep:299
awk:389
Major (requiring I/O) page faults:
timecat:16
grep:6
awk:5
File system inputs(Byte):
timecat:1,794,048
grep:11,735,800
awk:10,551,480
File system outputs(Byte):
timecat:1,778,416
grep:1,778,408
awk:1,778,408
————————————
从测试结果来看,timecat
无疑是有着巨大上风的,由于利用了“跳读”的办法,因此缺页次数会比较多。但是从实行韶光、CPU占用、系统输入输出(I/O)来看,timecat
险些完胜。
但是不是任何时候都适宜用timecat?我以为不是,当文件足够小(3G旁边且你的内存比较大时),或者你确定要搜索的内容在日志文件的比较起始或者比较靠后的位置(这样你可以利用tac
)时,利用grep
或者awk
说不定是个更好的选择。
5 结语
为什么要有timecat这个工具?由于确实存在一些情形,我们须要对很大的日志进行处理,我们出于历史缘故原由没有对线上的日志进行很好的切分(虽然要做这个实际上不难),但我们又须要去搜索个中的内容,而你所知道的,出了关键字以外,常日还有一个大致的韶光段。
或许有更好、更高等的方法去管理、搜索我们的日志,例如对日志内容进行索引、分类、流式打算,从而更快地获取我们想要的信息,但这样的代价在于我们要搭建一整套与此干系的环境,去掩护所有这些组件。
timecat供应的是一种最原始、无需掩护、易用、即用而且又能在一定程度上媲美专业工具的功能。或许终有一天,你会用上更专业的工具,但是在那一天来临之前,如果你对弘大的日志有搜索需求,都可以考试测验让timecat赞助你。