《一文讲透》第4期：KWDB 数据库运维（1） —— 日志系统解读

数据库日志系统在现代数据库管理系统（DBMS）中扮演着至关重要的角色。今天主要为大家分享 KWDB 日志系统，帮助大家了解其规范以及可以帮助你解决什么问题。Go！

01 KWDB 的日志类型及级别

KWDB 根据数据类型不同，生成的日志和存储位置也有所不同。下表列出了目前 KWDB 在数据库运维期间可能生成的所有日志：

KWDB 时序引擎日志、关系引擎日志和通用日志分为以下级别：

✅ DEBUG
仅用于现场分析定位问题，或者开发调试时抓取代码执行过程信息。例如：

• 某个函数调用其他函数的返回值
• 某个算子处理的记录条数
• 代码运行中由于某些 if-else 条件进入了特定的代码分支

✅ INFO
现场日志的默认级别。用于记录不需要操作的一般信息，包括用户操作或应用触发的重要操作、系统重要事件、系统内部重要任务操作起止、系统或数据库对象重要的状态变化、系统运行中遇到轻微且无损恢复的异常情况。例如：

• 用户创建数据库、数据表
• 用户打开了特定系统开关
• 系统启动过程中重要模块的初始化完成
• 系统定时任务触发、完成表分区的压缩
• 数据副本分裂、节点加入、副本补足
• 系统执行某操作，第一次失败但重试后成功

✅ WARNING
用于记录预期可以自行恢复的，可能需要特殊处理的警告信息，包括系统遇到预期外或不合理情况，这个问题可能造成更严重的系统问题或故障，运维人员必须关注，且在必要时采取措施的情况。例如：

• 磁盘空间即将耗尽
• 内存分配失败造成系统关闭了某服务，中止了某操作
• 数据压缩失败
• 某系统任务运行时间过长

✅ ERROR
用于记录预期无法自行恢复的，需要特殊处理的错误信息，包括系统运行中遇到错误，造成当前操作失败或阻塞，但是用户会话或应用可继续运行，且对系统的可用性没有致命影响的情况。例如：

• 某操作由于事务冲突被回滚
• 用户建表时遇到磁盘IO故障失败
• 某节点心跳丢失

✅ FATAL
用于记录需要立即停止服务的致命错误信息，包括系统遇到致命错误，全部或大部分系统服务无法正常工作，或执行用户命令、应用时触发严重问题，可能造成严重系统故障的情况。例如：

• 系统初始化时发现部分系统表无法正常访问
• 集群处于脑裂、数据丢失的状态
• 某操作失败，造成数据库处于不一致的状态
• 由于副本丢失系统处于只读模式的状态

02 如何进行日志管理

KWDB 日志由启动参数进行控制，如通过--log-dir 参数来控制日志输出目录，通过 --log-file-verbosity 控制日志级别。日志相关的启动参数如下：

03 常见日志格式

✅ 时序引擎日志

时序日志 TsEngine.log 记录时序引擎的日志信息，日志以 日志级别线程号[定制化日志信息] 为格式。其中

• 日志级别：下列字符之一， "D", "I", "W", "E", "F" 分别表示 debug，info，warning，error，fatal
• 时间戳：格式为 [yymmdd HH:MM:SS.usec]
• 线程号：对应 TID
• 代码文件和行号：filename:loc
• 定制化日志信息：时序引擎运行记录信息，如时序副本迁移、WAL recover

日志示例

I2407 2 11:28:05.862568 246 MMapHashIndex.cpp:163 Hash Index 79.tag.ht rehash, new_size: 256
I2407 2 11:34:02.260845 265 db.cpp:181 table 78, update rangeGroup 4 to follower

✅ 关系引擎日志

时序日志 kwbase-rocksdb.log 记录时序引擎 rocksdb 的日志信息。日志以 日志级别线程号[定制化日志信息] 为格式。其中：

• 日志级别：下列字符之一， "D", "I", "W", "E", "F" 分别表示 debug，info，warning，error，fatal
• 时间戳：格式为 [yymmdd HH:MM:SS.usec]
• 线程号：对应 TID
• 代码文件和行号：filename:loc
• 定制化日志信息：时序引擎运行记录信息，如 rocksdb 压缩记录

日志示例

I240702 03:28:09.254802 8370 storage/rocksdb.go:103  (Original Log Time 2024/07/02-11:28:09.254709) EVENT_LOG_v1 {"time_micros": 1719890889254695, "job": 262, "event": "compaction_finished", "compaction_time_micros": 34185, "compaction_time_cpu_micros": 33466, "output_level": 6, "num_output_files": 1, "total_output_size": 593244, "num_input_records": 10455, "num_output_records": 9753, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [1, 0, 0, 0, 0, 0, 3]}
I240702 03:28:09.254931 8370 storage/rocksdb.go:103  EVENT_LOG_v1 {"time_micros": 1719890889254913, "job": 262, "event": "table_file_deletion", "file_number": 497}

✅ 通用日志

通用日志 kwbase.log 记录非存储引擎的日志信息。日志以 日志级别线程号[定制化日志信息] 为格式。其中：

• 日志级别：下列字符之一， "D", "I", "W", "E", "F" 分别表示 debug，info，warning，error，fatal
• 时间戳：格式为 [yymmdd HH:MM:SS.usec]
• 线程号：对应 TID
• 代码文件和行号：filename:loc
• 定制化日志信息：非存储引擎运行记录信息，如节点心跳、通信状态

日志示例

W240706 00:57:35.240359 1511957 vendor/google.golang.org/grpc/clientconn.go:1206  grpc: addrConn.createTransport failed to connect to {server_svt_node_4:26257 0  <nil>}. Err :connection error: desc = "transport: Error while dialing cannot reuse client connection". Reconnecting...
E240706 00:57:35.240491 1511904 rpc/context.go:1003  [n1] removing connection to server_svt_node_4:26257 due to error: cannot reuse client connection

✅ 审计日志

审计功能由 admin 用户通过 SQL 语句开启：

set cluster setting audit.enabled = true;

开启后，系统会默认将审计结果保存在审计日志文件。审计日志文件包含以下信息：

日志示例

I240415 06:49:34.207014 538 security/audit/actions/record_to_log.go:45  [n1] 3 {"EventTime":"2024-04-15T06:49:34.206948441Z","Elapsed":2242701,"User":{"UserID":0,"Username":"root","Roles":[{"ID":0,"Name":"admin"}]},"Event":"CREATE","Target":{"Typ":"DATABASE","Targets":{"78":{"ID":78,"Name":"db1","Cascades":null}}},"Level":1,"Client":{"AppName":"$ kwbase sql","Address":"127.0.0.1:55564"},"Result":{"Status":"OK","ErrMsg":"","RowsAffected":0},"Command":{"Cmd":"CREATE DATABASE db1","Params":"{}"},"Reporter":{"ClusterID":"ae93118d-28bc-492f-bd4f-852cafab0ad9","NodeID":1,"HostIP":"localhost","HostPort":"26257","HostMac":"","LastUp":0}}

如需关闭审计日志，可通过以下 SQL 语句将 audit.log.enabled 设为 false：

set cluster setting audit.log.enabled=false;

✅ 错误日志

错误 errlog.log 会记录数据库严重异常时，数据库进程的当前 call stack 记录。

日志示例

Exception time(UTC):2024-11-02 13:33:22
signal:Segmentation fault(11)
pid=109818 tid=110896 si_code=1 si_addr=0x48
backtrace: size:14
#0 /usr/local/kaiwudb/bin/../lib/libcommon.so(kwdbts::PrintBacktrace(std::ostream&)+0x3d) [0x7fa9805b2f9d]
#1 /usr/local/kaiwudb/bin/../lib/libcommon.so(kwdbts::ExceptionHandler(int, siginfo_t*, void*)+0x281) [0x7fa9805b36a1]
#2 /lib/x86_64-linux-gnu/libc.so.6(+0x42520) [0x7fa97fd51520]
#3 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(+0x2546d3) [0x7fa98082c6d3]
#4 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::SynchronizerOperator::~SynchronizerOperator()+0x2a7) [0x7fa98082e0b7]
#5 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::SynchronizerOperator::~SynchronizerOperator()+0xd) [0x7fa98082e1dd]
#6 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::Processors::Reset()+0x37) [0x7fa980816677]
#7 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::DmlExec::DestroyTsScan(kwdbts::DmlExec::TsScan*)+0x4e) [0x7fa9807963ee]
#8 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::DmlExec::ClearTsScans(kwdbts::_kwdbContext_t*)+0x51) [0x7fa980796771]
#9 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::DmlExec::Next(kwdbts::_kwdbContext_t*, int, bool, _QueryInfo*)+0xeb) [0x7fa980796e7b]
#10 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(kwdbts::DmlExec::ExecQuery(kwdbts::_kwdbContext_t*, _QueryInfo*, _QueryInfo*)+0x174) [0x7fa980797004]
#11 /usr/local/kaiwudb/bin/../lib/libkwdbts2.so(TSExecQuery+0x261) [0x7fa980728571]
#12 /usr/local/kaiwudb/bin/kwbase(_cgo_b2bb81300987_Cfunc_TSExecQuery+0x31) [0x36abbe1]
#13 /usr/local/kaiwudb/bin/kwbase() [0x6a1b70]