DolphinDB 日志分析工具使用手册

该 demo 实现批量读取目录 /dolphindb/server/log 下的日志到原始日志流表 originLogLines，日志时间范围为 1 小时前到当前时间戳，订阅并解析日志内容输出到解析结果流表 logAnalysisResult：

clearCachedModules()
go
use DDBLogAnalyser::config
use DDBLogAnalyser::logReader
use DDBLogAnalyser::logParser::logParser
use DDBLogAnalyser::reportGenerator::reportGenerator
go

clearEnv()
go
batchModeVersion = version() // 与 logDir 下的日志对应的 DolphinDB 版本相同
config = getExampleConfig(batchModeVersion)
config["logDir"] = "/dolphindb/server/log"
config["startTime"] = temporalAdd(now(), -1H) // 日志开始时间为当前时间戳 - 1H
config["endTime"] = now() // 日志结束时间当前时间戳
initConfig(config)
go

readLog()
parseLog()
generateReport()

全部解析完毕后生成多份报表，包括 errors 所有错误信息表、warnings 所有警告信息表、longestTransactionsReport 最长耗时事务表、transactionAuditReport 所有事务 DDL 日志表等：

运行脚本时要求指定集群所有节点都在线，运行脚本后只要求指定集群控制节点和代理节点在线即可监控所有节点日志。

该 demo 实现流式读取指定远程集群的所有节点的日志到原始日志流表 originLogLines，订阅并解析日志内容输出到解析结果流表 logAnalysisResult：

try { loadPlugin("httpClient") } catch(err) { print(err) }
go
clearCachedModules()
go
use DDBLogAnalyser::config
use DDBLogAnalyser::logReader
use DDBLogAnalyser::logParser::logParser
use DDBLogAnalyser::reportGenerator::reportGenerator
use DDBLogAnalyser::alertGenerator
go

clearEnv()
go
config = getExampleConfig()
config["remoteControllerSites"] = [
  "192.168.100.43:7600",
  "192.168.100.44:7600",
  "192.168.100.45:7600"
] // 远程集群的所有控制节点的 IP:端口号
config["remoteUsername"] = "admin" // 远程集群的管理员账户
config["remotePassword"] = "123456" // 远程集群的管理员密码
alertConfig = dict(STRING, ANY)
alertConfig["userId"] = "xxx@xxx.com" // 告警发送邮箱账号，必须开启 SMTP
alertConfig["pwd"] = "xxxxxx" // 告警发送邮箱密码
alertConfig["recipient"] = "xxx@xxx.com" // 告警接收人邮箱
alertConfig["logLevelFilter"] = ["DEBUG"] // 按日志等级过滤，排除 DEBUG 日志
alertConfig["whitelist"] = ["%whitelist error%"] // 用 like 和日志内容匹配，过滤需要的日志，优先生效。不需要白名单时不配置。
alertConfig["blacklist"] = ["%blacklist error%"] // 用 like 和日志内容匹配，过滤不要的日志，在白名单后生效。不需要黑名单时不配置。
config["alertConfig"] = alertConfig
initConfig(config)
go

readLog()
parseLog()
initAlertGenerator()

对内容含 “whitelist error“ 的日志发送邮件告警（需要修改 config 字典里配置的邮箱；需要邮箱支持 SMTP）：

writeLog("whitelist error")

参数：

• config：字典，定义详见《配置项》一节。

初始化一个名为 logAnalyserConfig 的共享字典，作为工具的全局配置。 需要首先运行该接口。

无法重复运行该接口。 需要修改配置时，可以直接修改共享字典的指定键的值（例如 logAnalyserConfig["version"] = "2.00.12"），或者 undef("logAnalyserConfig", SHARED) 该共享字典后再重新调用 initConfig 接口。

读取日志。根据全局配置字典配置的读取模式，读取日志到 originLogLinesTbName 配置项指定名称的流表。批处理模式读取 logDir 配置项指定的文件夹下的日志到流表，流处理模式自动读取集群所有节点的日志到流表。

结果流表如下：

字段说明：

解析读取的日志日志。 订阅 originLogLinesTbName 配置项指定名称的流表，调用全局配置字典配置的解析项目进行解析，然后输出到 resultTbName 指定名称的流表。详见《自定义解析项目》一节。

结果流表如下：

字段说明：

根据解析日志结果生成报告表。 批处理模式下使用。 实现为运行 reportGenerator/projects 目录下所有与文件名同名的方法，详见《自定义解析项目》一节。

订阅解析结果流表，在触发配置的告警规则时发送邮件到指定邮箱。 流处理模式下使用。 注意需要邮箱开启 SMTP。 详见《自定义告警规则和内容》一节。

根据全局配置字典的配置项，清理所有相关的流表、订阅和后台任务等，然后清理全局配置字典。

logParser 目录结构如下：

.
├── logParser.dos
└── projects
    ├── controller
    │   └── parseTransactionsInfo.dos
    └── datanode
        └── parseTransactionsInfo.dos

其中，logParser.dos 包含入口方法 parseLog，该方法运行时，会加载 logParser/projects/controller 和 logParser/projects/datanode 目录下的所有模块文件，并运行与文件名同名的方法。

例如，对解析事务相关日志行的模块 logParser/projects/controller/parseTransactionsInfo.dos，会加载并运行其中定义的方法 parseTransactionsInfo，入参说明：

• logTime：日志时间戳
• logLevel：日志等级
• line：日志行原始内容。 建议指定为 mutable 以提高性能。
• s：dropna(s.split(" ")) 的值，用于提取信息。 建议指定为 mutable 以提高性能。

返回值：一个元组。

• 第一个元素为自定义类型字符串。
• 第二个元素为解析的信息的字典，可自定义字段。

例如：

module DDBLogAnalyser::logParser::projects::datanode::parseTransactionsInfo

def parseTransactionsInfo(logTime, logLevel, mutable line, mutable s) {
  contentType = "transactionCompleted"
  info = {"completedTime": logTime,"tid": getTid(s),"cid": getCid(s)}
  return (contentType, info)
}

logParser 目录结构如下：

.
├── projects
│   └── generateTransactionsReport.dos
└── reportGenerator.dos

其中，reportGenerator.dos 包含入口方法 generateReport，该方法运行时，会加载 reportGenerator/projects 目录下的所有模块文件，并运行与文件名同名的方法。

例如，对生成事务相关报表的模块 reportGenerator/projects/generateTransactionsReport.dos，会加载并运行其中定义的方法 generateTransactionsReport，无入参，无返回值。目前设计为自行在方法内 share 报表。

例如：

def generateTransactionsReport() {
    rolledBackTransactions = generateRolledBackTransactionsReport()
    if (!isVoid(rolledBackTransactions)) {
        share(rolledBackTransactions, "rolledBackTransactions")
    }
}

主要通过 alertConfig 配置项来配置告警相关规则，支持黑名单和白名单模式，支持自定义告警邮件标题和内容。 具体见配置项一节的 alertConfig 说明。

例如，通过自定义告警邮件内容包含"custom" 字符串：

def customGenerateEmailFunc(alertMsg) {
    h = "custom alert!\n"
    ret = exec string(originContent) from alertMsg
    ret = concat(ret, "\n")
    subject = "Custom alert from DolphinDB log analyser!"
    body = h + ret
    return (subject, body)
}

alertConfig = dict(STRING, ANY)
alertConfig["userId"] = "xxx@xxx.com" // 告警发送邮箱账号
alertConfig["pwd"] = "xxxxxx" // 告警发送邮箱密码
alertConfig["recipient"] = "xxx@xxx.com" // 告警接收人邮箱
alertConfig["logLevelFilter"] = ["DEBUG"] // 按日志等级过滤
alertConfig["whitelist"] = ["%whitelist error%"] // 用 like 和日志内容匹配，过滤需要的日志，优先生效
alertConfig["blacklist"] = ["%blacklist error%"] // 用 like 和日志内容匹配，过滤不要的日志，在白名单后生效
alertConfig["generateEmailBody"] = customGenerateEmailBody
config["alertConfig"] = alertConfig

当某个库表由于事务回滚而出现数据缺失时，需要排查事务回滚的具体原因，使用命令行工具逐个查找回滚事务相关日志效率比较低且可读性较差。 参照 2.1 节执行批处理流程，查看生成的回滚事务报告表 rollbackTransactionsReport 如下：

可见有 6 个事务回滚。 编写如下脚本遍历查询包含回滚事务 ID 的 ERROR 和 WARNING 日志并打印：

tids = exec tid from rolledBackTransactions
for (tid in tids) {
    pattern = "%" + tid + "%"
    info = select * from errors where originContent like pattern
    if(info.size() > 0)
        print("\nTransaction " + tid + " relative errors:\n", info["originContent"])
    info = select * from warnings where originContent like pattern
    if(info.size() > 0)
        print("\nTransaction " + tid + " relative warnings:", info["originContent"])
}

可见对 ID 为 53664920 的事务，有一个 WARNING 日志表明回滚原因可能为磁盘满。

例如对分布式表执行每日导入数据的任务，如果用户反馈某天导入的数据量不合预期，或者导入时间过长，可以使用日志分析工具分析对分布式表的写入数据量。参照 2.1 节执行批处理流程，生成事务操作报告表 transactionAuditReport 和事务信息日志 transactionMetricsReport，执行如下查询统计每天每小时的对指定库的 DDL 操作数：

select count(*) as DDLCount from transactionAuditReport where dbName 
	= "dfs://TL_Level2_merged" group by dbName, date(logTime), hour(logTime) 
	as date order by DDLCount desc

可见 16, 17 日对库 dfs://TL_Level2_merged 的 DDL 操作数远高于 18 日。

执行如下查询统计每天每小时的对指定库的写入分区数：

select sum(partitionCount) from transactionMetricsReport left join transactionAuditReport on 
	transactionMetricsReport.tid == transactionAuditReport.tid where dbName = 
	"dfs://TL_Level2_merged" group by dbName, date(startTime) as date, 
	hour(startTime) as hour order by sum_partitionCount desc

可见 16, 17 日对库 dfs://TL_Level2_merged 的写入分区数远高于 18 日。

综上可以确定具体的业务逻辑，是16, 17 日重复提交了一些导入任务，导致并发写入变慢。

用户可能对分布式库表存在误操作，例如不小心执行了两遍 append! 写入重复数据，或者不小心执行了 delete SQL 导致数据丢失。以排查重复写入为例，参照 2.1 节执行批处理流程，生成事务操作报告表 transactionAuditReport 如下：

该表记录了所有用户对库表的写入事务操作记录，注意到存在两条对 dfs://rangedb_tradedata 库的 Trades 表的 operation 为 savePartitionedTable 写入分布式表的记录，且 logTime 日志时间非常接近。 可结合 userName 用户名、remoteIP 客户端 IP 联系写入的用户，结合业务进一步确认是否为用户误操作导致重复写入。

当客户写入性能出现问题时，一般需要排查耗时过长的事务以及其写入的库表，然后结合具体业务代码分析。 参照 2.1 节执行批处理流程，生成最长耗时事务报告表 longestTransactionsReport 如下：

注意到事务 ID 为 30710128 的事务耗时最长，此时再查询 transactionAuditReport 表获得操作日志：

select * from transactionAuditReport where tid == 30710128

可见该事务 contentType 为 savePartitionedTable 即写入事务，此时可结合 logTime 日志时间、userName 用户名、remoteIP 客户端 IP 联系写入的用户，结合业务进一步确认写入方式和数据量是否合理。

当节点启动失败、停止失败或宕机时，一般需要排查问题发生前日志是否有 ERROR 或 WARNING。 使用批处理模式分析日志得到节点启动和停止报表 startupAndShutdownReport 如下：

其中 contentType 含义：

• startupInitializing：启动节点开始。
• startupCompleted： 启动节点完成。
• startupFailed：启动节点失败。 该 contentType 的记录前会自动填充最近的 10 条 ERROR 和 WARNING 日志。
• shutdownReceivedSignal：节点收到 kill 信号。
• shutdownStarted：关闭节点开始。
• shutdownCompleted：关闭节点完成。
• shutdownFailed：关闭节点失败。 该 contentType 的记录前会自动填充最近的 10 条 ERROR 和 WARNING 日志。
• coredump：节点可能发生 coredump 宕机。 因为 coredump 并不会产生表明 coredump 的日志，该条记录为使用规则推理得到，需要根据是否产生 coredump 文件和操作系统日志（dmesg, /var/log/messages 等）来确定是否发生 coredump。 该 contentType 的记录前会自动填充最近的 10 条 ERROR 和 WARNING 日志。

注意到存在 contentType 为 coredump 的记录，检查 logTime 时间左右有对应 coredump 文件存在，需要进一步分析 coredump 堆栈内容和宕机前的动作确定原因。

注意到存在 contentType 为 startupFailed 的记录，查看之前的 ERROR 日志发现报错内容为 Invalid license file，检查 license 发现已过期。

使用批处理模式分析日志得到登录报表 loginReport 如下：

执行如下 SQL 统计每天各用户登录次数：

select count(*) from loginReport group by date(logTime) as date, operate

例如当客户的环境存在长期大量写入时，产生的大量事务日志可能干扰其他问题的排查，此时希望能过滤掉事务相关日志，可以直接对分析结果表执行查询，使用 like 方法过滤掉 contentType 为 transaction 开头的日志：

t = select * from logAnalysisResult where contentType not like "transaction%"

如果需要过滤其他类型的日志，可以参考《自定义解析项目》一节编写相关日志的解析脚本，然后使用同样的方法过滤。

可以结合定时任务和 HttpClient 插件实现生成日志分析每日报表并发送到指定邮箱。 参考定时任务如下：

try { loadPlugin("HttpClient") } catch(err) { print(err) }
go

clearCachedModules()
go
use DDBLogAnalyser::config
use DDBLogAnalyser::logReader
use DDBLogAnalyser::logParser::logParser
use DDBLogAnalyser::reportGenerator::reportGenerator
use DDBLogAnalyser::alertGenerator
go

def analyseLogAndSend(userId, pwd, recipient) {
    clearEnv()
    go
    batchModeVersion = version()
    config = getExampleConfig(batchModeVersion)
    config["logDir"] = getLogDir()
    config["startTime"] = temporalAdd(now(), -24H)
    config["endTime"] = now()
    initConfig(config)
    go
    
    readLog()
    parseLog()
    generateReport() // 批处理用

    body = "<pre>"
    body += "ERROR logs: " + string(exec count(*) 
    	from objByName("errors")) + "\n" + string(objByName("errors"))
    body += "\nWARNING logs: " + string(exec count(*) 
    	from objByName("warnings")) + "\n" + string(objByName("warnings"))
    body += "</pre>"
    res = HttpClient::sendEmail(userId, pwd, recipient, 
    	"log analyser report for " + string(today()), body);
    go

    clearEnv()
}

scheduleJob("analyseLogAndSend", "analyseLogAndSend", 
	analyseLogAndSend{"xxxx@xxx.com", "xxxxxxxx", "xxxxx@xxx.com"}, 
	23:55m, today(), 2055.12.31, 'D')

该定时任务每天 23:55 执行，解析单节点的日志生成报表，发送 ERROR 和 WARNING 日志的统计信息到指定邮箱。