见微知著的Splunk
日前，笔者对手中管理的部分Cisco交换机进行IOS 版本升级，升级过程一切顺利。但升级完成后，发现运行一段时间后的交换机性能出现下降的现象。登录交换机使用命令查看系统资源使用情况发现，交换机的内存使用量到达一个相当高的水平。试着对其中一台交换机进行重启后，发现系统启动之初内存使用量与未升级的同类交换机相差无几。那么，交换机内存上升必然是发生在运行的过程中。
为了解交换机运行过程中内存变化情况，笔者使用脚本程序定时登录交换机查看内存使用情况并记录到文本文件中。脚本运行一段时间后便产生了大量的日志记录。面对大量不规则的日志，采用人工分析的办法无疑效率比较低下，而且只能做事后分析，无法监控实时的变化情况。正在一筹莫展之际，突然想起可以使用Splunk 来实现日志分析和实时监控的需求。
首先，将脚本程序定时产生的日志发送到splunk 服务器上。Splunk根据时间戳、主机地址等字段对日志进行初步分类。在搜索栏输入任意关键字即可定位所需的日志信息。对于日志中的关键信息，可以进行对其进行灵活的栏位定义，作为进一步深入搜索分析的基础。而定义所用的工具正是强大的正则表达式。Splunk 可以根据选取的信息进行智能分析，生成正则表达式对指定范围内信息进行筛选和定义。那么正则表达式是如何工作的呢？我们来看以下这段日志：
14:22:17.654 Beijing Fri Aug 20 2010
GDL-DSF-4948-01#show processes memory | inc Free
Processor Pool Total: 226857300 Used: 137342824 Free: 89514476
PID TTY Allocated Freed Holding Getbufs Retbufs Process
GDL-DSF-4948-01#
GDL-DSF-4948-01#exit
Connection closed by foreign host.
日志中关键的信息是已使用的内存用量，全部由数字组成，用正则表达式可以表示为(?i) Used: (?P<UsedMem>\d+)，其中(?i)为扩展模式，表示关闭正则表达式中的大小写区别。(?P<UsedMem>\d+)表征已使用的内存数字并将其定义为UsedMem。那么为什么正则表达式中为什么还要有一段额外的信息呢？原因是日志中其他位置也包含数字信息，以上表达式不足以抽取所需信息，一个比较直观的办法是将其前后的文字作为定义的一部分。在这里可以将”Used：”作为前缀来定位UsedMem。交换机使用的内存量就这样被精确的提取出来了：
对UseMem关键字进行搜索分析，也许能找到问题原因的一些端倪。搜索语句使用管道符命令分割搜索命令，对日志进行精确搜索和分析处理。搜索语句Used: “4948-MemMonitor-test#show processes memory” | reverse | table _time UsedMem，首先使用交换机名称和命令关键字筛选单个交换机与内存相关的日志信息，并按日志产生时间先后排序，最后生成 UsedMem 与时间相关的数据表格和图表：
图表和表格内存使用情况在相对较长的事件内保持平稳，并没有出现显著增加的情况。那么交换机的内存耗尽是如何发生的呢？仔细观察表格的数据，可以发现随着时间的流逝，交换机的使用内存其实是逐步增加的，只不过增量相当小，在大的单位刻度图表上看不出变化。那么查看内存的增量呢？说不定会有新的发现。对搜索命令进行修改：
Used: “4948-MemMonitor-test#show processes memory” | reverse | eventstats first(UsedMem) as first_UsedMem | eval delta=UsedMem-first_UsedMem | table _time delta
首先找出观察到的第一个内存使用值，将其与所有内存使用值进行比较，最后生成变化值的表格。这次交换机内存耗尽的过程终于真相大白了：交换机的使用内存在运行过程中是以一个极其微小的增量在变化，变化过程中还伴随着若干个小突变。
至此，读者可以发现使用 splunk 进行日志分析的几大优点：首先是分析的数据来源广泛，无论是标准的 syslog，还是命令输出的不规则结果信息，只要是文本格式的数据内容 splunk 都可以进行分析处理；其次，强大的正则表达式能在文本信息中抽取关键信息进行定制，作为深入搜索分析的参数；最后，灵活的搜索命令能帮助有经验的用户从浩如烟海的日志信息中去芜存菁，挖掘到有价值的信息。这些信息都可以作为知识在 splunk 中保存，作为后续搜索、分析和实时告警之用。
Gavin
Recent Comments