linux-实现日志分析--python

linux-实现日志分析--python

涉及到的主要python包和系统命令：

1. datetime #用于处理时间
2. subprocess #用于调用命令行工具
3. tail -f logFile #获取logFile新增内容

废话不多说，下面说一下场景需求和具体解决方案。

1. [场景需求]

一个区块链项目，在项目测试过程中，通过日志发现出块不稳定，为了定位问题，需要精确的统计出块时间。截取一段日志如下：

I[2019-07-11|16:57:24.139][45712] reapMaxBytesMaxGas                           module=mempool mempoolTxNum=0 reapTxNum=0 maxNumPerBlock=2000
I[2019-07-11|16:57:24.220][45712] [60]---------- BeginBlock[4367] ----------   module=main
I[2019-07-11|16:57:24.224][45712] Executed block                               module=state height=4367 validTxs=0 invalidTxs=0
D[2019-07-11|16:57:24.307][45712] Commit synced                                module=main commit=436F6D6D697449447B5B333520342031383720363120343120313336203137312031203137302032343120323220313230203836203233382031333120313634203231302031323420313530203233322036203434203130342033322036302031303220343120323530203131352031323720313138203134355D3A313130467D
I[2019-07-11|16:57:24.307][45712] BlockHeight<4367>, BeginBlock<0ms>, DeliverTx<0ms>, EndBlock<0ms>, Commit<82ms>, Tx<0> module=main
I[2019-07-11|16:57:24.307][45712] BlockHeight<4367>, Abci<82ms>, Tx<0>, fullfilled<0>, pending<0>, canceled<0>, expired<0>, partialfilled<0> module=main
I[2019-07-11|16:57:24.307][45712] Committed state                              module=state height=4367 txs=0 appHash=2304BB3D2988AB01AAF1167856EE83A4D27C96E8062C68203C6629FA737F7691
I[2019-07-11|16:57:25.208][45712] reapMaxBytesMaxGas                           module=mempool mempoolTxNum=0 reapTxNum=0 maxNumPerBlock=2000
I[2019-07-11|16:57:25.284][45712] [60]---------- BeginBlock[4368] ----------   module=main

2. [日志分析]

日志中Committed state代表状态持久化，也就是区块生命周期的末尾。 因此我们使用Committed state来对日志进行过滤，并用最新一条日志的时间戳减去上条日志时间戳作为本区块出块时间。

3. [代码]

#!/usr/bin/python
#encoding=utf-8
#Filename: block_time.py

import subprocess
from datetime import datetime
import time

logFile = "./blockchain.log"
lastDateTime = datetime.now()

#主程序
def monitorLog(logFile):
   print("monitor logFile: %s" % logFile)
   stopTime = time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(time.time()+100)) #脚本100秒后退出
   popen = subprocess.Popen(["tail", "-f", logFile], stdout=subprocess.PIPE, stderr=subprocess.PIPE) #启动子进程执行tail命令
   while True:
      line = popen.stdout.readline().strip() #按行获取日志
      if line:
         if 'Committed state' in line:
            getBlockInterval(line)  #分析日志
      now = time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(time.time())) #当前时间
      if now >= stopTime: #如果当前时间超过stopTime，表示不再分析日志，退出程序
           popen.kill()
           print("kill subprocess")
           break

#计算连续两条日志的时间差
def getBlockInterval(line): 
   t = getDateTime(line)
   global lastDateTime
   blockInterval = (t-lastDateTime).total_seconds() #将datetime时间差用seconds计算
   blockHeight = getBlockHeight(line)

   lastDateTime = t
   print('%s, interval=%s' % (blockHeight, blockInterval)) #打印结果

#获取区块高度
def getBlockHeight(line): 
   return line.split('module')[1].split(' ')[1]

#获取每行日志的时间戳
def getDateTime(line): 
   line = line.split('[')[1][:-1].split('.')[0].replace('|', ' ')
   t = datetime.strptime(line, "%Y-%m-%d %H:%M:%S")
   return t

if __name__ == '__main__':
   monitorLog(logFile)

4. [日志分析结果]

height=4343, interval=1.0
height=4344, interval=1.0
height=4345, interval=1.0
height=4346, interval=1.0
height=4347, interval=1.0
height=4348, interval=1.0
height=4349, interval=2.0
height=4350, interval=1.0
height=4351, interval=1.0

5.[总结-脚本详细注解]

这个Python脚本，其主要目的是监视一个名为blockchain.log的日志文件，并分析其中包含特定字符串('Committed state')的行。该脚本的主要功能和步骤如下：

初始化:

导入所需的模块。
设置日志文件的路径为./blockchain.log。
获取当前时间，并设置为lastDateTime。
主程序(monitorLog函数):

定义一个停止时间(当前时间加上100秒)。
使用subprocess.Popen启动一个子进程来执行tail -f命令，该命令会实时显示日志文件的最新内容。
进入一个无限循环，从子进程的输出中按行读取日志。
如果读取到的行包含'Committed state'字符串，则调用getBlockInterval函数来分析该日志行。
检查当前时间是否超过定义的停止时间。如果超过，则杀死子进程并退出循环。
分析日志(getBlockInterval函数):

从日志行中提取时间戳，并转换为datetime对象。
计算当前时间与上次记录的时间之间的差值(以秒为单位)。
从日志行中提取区块高度。
更新lastDateTime为当前时间戳。
打印区块高度和时间间隔。
辅助函数:

getBlockHeight: 从日志行中提取区块高度。
getDateTime: 从日志行中提取时间戳，并转换为datetime对象。
执行主程序:

如果该脚本作为主程序运行(而不是被其他脚本导入)，则调用monitorLog函数开始监视日志文件。
总的来说，这个脚本的主要目的是监视区块链日志，并在找到包含'Committed state'的行时，计算连续两条此类日志之间的时间间隔，并打印出相应的区块高度和时间间隔。这对于分析区块链的性能和稳定性可能非常有用。