背景

之前写的大量代码中都会有着进行日志打印的需求,但是之前一般都会在每一个功能模块中分别实现一套简单的日志框架,但是这些分布各个项目中的日志代码在使用中存在各种问题,主要有以下几点:

  1. 代码冗余:不同的项目可能需要使用不同的日志库,这会导致代码冗余和重复。
  2. 维护困难:当需要修改日志记录方式时,每个项目都需要单独修改,这会增加维护的难度和工作量。
  3. 性能问题:不同的日志库可能有不同的实现方式,这可能导致性能问题,如日志记录速度慢、内存占用高等。
  4. 兼容性问题:不同的日志库可能支持不同的输出格式和配置选项,这可能导致兼容性问题,如无法将日志记录到其他系统或平台。
  5. 错误处理困难:没有统一的日志框架可能导致错误处理困难,因为不同项目的日志库可能有不同的错误处理机制和策略。

因此,为了提高开发效率和维护性,建议使用统一的日志框架来统一日志记录方式和规范。

日志框架介绍

1728377849572

如图 日志系统整体上的框架如图。

首先看内核态的几个模块功能:

  1. 日志设备:实际上实现了一个字符设备驱动,该驱动在/dev文件夹中创建对应设备节点,通常默认创建log_system , log_events, log_sysinit ,log_main四个设备。

1728378084393

可以将每个设备理解成一个环形队列,该设备节点提供的read,write系统调用都是在这个环形队列中进行读写操作

  1. 内核读写接口:实现了一个内核读写日志环形缓冲区接口,方便内核态读写日志
  2. 异常情况记录模块:负责在内核各种故障点挂Hook,在问题出现的时候调用日志接口记录现场到环形缓冲区。
  3. 转储挂载设备:就是一般的块设备,挂载一个文件系统用于存储压缩后的日志。

用户态功能介绍:

  1. 虚拟日志: 对于没有日志设备的环境也可以使用日志接口,在这种情况下日志会直接输出到控制台。
  2. 系统调用读写接口: 使用writev或者read接口或者直接调用虚拟日志接口读写日志。
  3. 日志压缩转储模块:当出现环形缓冲区队满的情况时进行一次日志压缩,将压缩后的日志写入文件系统。
  4. 二进制日志读写模块:读取二进制日志tags文件并mmap到内存中,节省二进制日志tag查询时间。
  5. 对外接口:通过hiklog.h对外提供日志写接口。

日志工具介绍:

  1. hiklogcat: 支持将环形缓冲区的日志输出到串口控制台或者文件中,支持控制输出格式。
  2. hiklogrec: 提供shell日志记录工具,方便shell进行日志记录。

日志原理介绍

下面简单看一下日志系统的整体写入过程:

1728378814821

上图展示了从libhiklog.so提供的对外接口到写入环形缓冲区的简单过程,其中红线代表了一般日志的写入过程,蓝线代表二进制日志的写入过程。

在系统初始的过程中需要为日志系统分配一块内存,这块内存可以是任意的不要求在物理上连续,但是如果需要激活保留内存特性,则需要指定物理地址和长度,具体方法是在模块插入的时候输入保留内存地址和长度:

1728380196467

以申请2M的保留内存为例,则默认情况按照如下进行内存分配:

1728380638865

系统默认初始化四个日志设备,日志设备再内核中通过这样的数据结构进行管理:

1728381014659

buffer指向 环形缓冲区,ext指向保留内存中的logger_ext, offset记录日志在整个日志内存中的偏移,size代表环形缓冲区大小,ext_size是保留的内存大小。

每个日志设备除了ringbuffer之外还需要占有一块8K的内存用来存储管理数据,和一部分不希望被队列刷掉的日志,管理数据定义如下:

1728380737855

该结构体主要作用就是存储环形队列的队头和写指针以及转储信息。这些信息存在这块内存中的主要原因是不希望再系统重启后丢失掉于这块队列有关的信息,这样就可以使得队列即便重启再下一次重启后如果感知到这块内存之前被使用过可以继续使用。

日志设备的写入接口,会将日志格式化为如下结构:

1728379796136

该结构除了写入日志的内容还会自己填充日志的写者uid,写入长度,pid,写入时间等关键信息,这个结构体的msg中存储着一块日志信息。加上日志的长度这个接口不能大于4K。环形缓冲区中只会存储着一个一个logger_entry。

下面我们分析一下各个关键过程中的日志接入过程:

1728386468885

我们大致画出了环形缓冲区的变化过程,在一开始的时候环形缓冲区没满的时候,写入的过程就是向前移动W_OFF指针的过程,W_OFF就是下一次要写入的位置,当环形缓冲区渐渐写满后也就是W_OFF要越过HEAD的时候这个时候代表W_OFF发生回绕要开始覆盖之前的日志数据了,这个时候的写入W_OFF依然向前移动,但是每次移动需要同步移动HEAD,到下一个可以读取的log_entry。

而日志读取也非常简单就是从HEAD处的一个log_entry开始读取日志数据返回到用户态,读取完成后向后移动这个entry的大小,然后继续读取,一直遇到W_OFF读取结束。

日志转储介绍

基于上述环形缓冲区的日志存储可以保证最新的日志可以一直存在,但是其存储的日志量不大,每次发生回绕的时候会覆盖掉之前的日志,所以需要设计一个更大的环形缓冲区,将日志压缩后存储到flash中。

1728387474009

默认情况下转储的环形缓冲区会是一个挂载在flash上的文件系统中大小固定的一个文件,这个文件大小需要是整个日志内存大小的整数倍。以一个2M的后备区域为例,其 采用如上图的映射方式,写入的时候都会检查写指针的位置,如果发现写入结束后的写指针小于上一次的位置代表已经发生回绕,此时会触发压缩存储流程。而hiklogcat支持读取压缩存储后的日志。

日志功能介绍

对外接口

hiklog主体是一个动态库,该动态库通过hiklog.h提供对外接口主要提供两类接口

文本日志接口

是正常的文本日志写入接口

其基本格式为hiklog_xxx_yyy

xxx 主要包含app,sysinit,system,代表着日志会写入哪一个日志设备。

yyy主要代表打印等级,可选等级如下:

1728388002953

下面是使用实例:

    hiklog_app_verbose("APPLOG TEST ID:%d n" , 1);
    hiklog_app_verbose_if((2 > 1) ,"APPLOG TEST ID:%d n" , 2);
    hiklog_app_debug("APPLOG TEST ID:%d n" , 3);
    hiklog_app_debug_if((2 > 1) ,"APPLOG TEST ID:%d n" , 4);
    hiklog_app_info("APPLOG TEST ID:%d n" , 5);
    hiklog_app_info_if((2 > 1) ,"APPLOG TEST ID:%d n" , 6);
    hiklog_app_warn("APPLOG TEST ID:%d n" , 7);
    hiklog_app_warn_if((2 > 1) ,"APPLOG TEST ID:%d n" , 8);
    hiklog_app_error("APPLOG TEST ID:%d n" , 9);
    hiklog_app_error_if((2 > 1) ,"APPLOG TEST ID:%d n" , 10);

    hiklog_system_verbose("SYSLOG TEST ID:%d n" , 1);
    hiklog_system_verbose_if((2 > 1) ,"SYSLOG TEST ID:%d n" , 2);
    hiklog_system_debug("SYSLOG TEST ID:%d n" , 3);
    hiklog_system_debug_if((2 > 1) ,"SYSLOG TEST ID:%d n" , 4);
    hiklog_system_info("SYSLOG TEST ID:%d n" , 5);
    hiklog_system_info_if((2 > 1) ,"SYSLOG TEST ID:%d n" , 6);
    hiklog_system_warn("SYSLOG TEST ID:%d n" , 7);
    hiklog_system_warn_if((2 > 1) ,"SYSLOG TEST ID:%d n" , 8);
    hiklog_system_error("SYSLOG TEST ID:%d n" , 9);
    hiklog_system_error_if((2 > 1) ,"SYSLOG TEST ID:%d n" , 10);

    hiklog_sysinit_verbose("SYSINIT TEST ID:%d n" , 11);
    hiklog_sysinit_verbose_if((2 > 1) ,"SYSINIT TEST ID:%d n" , 12);
    hiklog_sysinit_debug("SYSINIT TEST ID:%d n" , 13);
    hiklog_sysinit_debug_if((2 > 1) ,"SYSINIT TEST ID:%d n" , 14);
    hiklog_sysinit_info("SYSINIT TEST ID:%d n" , 15);
    hiklog_sysinit_info_if((2 > 1) ,"SYSINIT TEST ID:%d n" , 16);
    hiklog_sysinit_warn("SYSINIT TEST ID:%d n" , 17);
    hiklog_sysinit_warn_if((2 > 1) ,"SYSINIT TEST ID:%d n" , 18);
    hiklog_sysinit_error("SYSINIT TEST ID:%d n" , 19);
    hiklog_sysinit_error_if((2 > 1) ,"SYSINIT TEST ID:%d n" , 20);

对我们bsp而言 一般使用sysinit, system两个设备,其中sysinit主要用于初始化日志,比如bsp_init整个流程的打印需要使用sys_init,而system用来存储进程运行中会产生的打印。

二进制日志接口

二进制日志主要通过hiklog_event_write接口进行使用

int (*__hiklog_event_write)(int tag ,...) ;

实例:

    hiklog_event_write(1,1,2,3);
    hiklog_event_write(2,1,24,3000);
    hiklog_event_write(3,"HELLO","HELLO1","HELLO2");
    hiklog_event_write(4,1,2,"HELLO2");

其中的tag,每一种二进制格式会有唯一的tag与之对应。如果一个项目需要定义自己的event_tag只需要在项目中添加一个eventlog.logtags文件,hiklog在编译的时候会查找所有eventlog.logtags进行合并

1728388646277

合并后的文件如下,然后还会生成对应的头文件

1728388678270

在使用的时候可以使用这些枚举体。

日志写入命令

为了方便在shell脚本中的日志写入开发了hiklogrec工具,其主要就是调用上面的日志接口写入日志:

hiklogrec -b sysinit -l i -s hello

向sysinit写入hello。

1728389564035

控制写入打印等级:

1728389614072

控制写入tag:

hiklogrec -b sysinit -l i -s hello -t hello2

1728389884583

此外hiklogrec还支持将其他程序的输出通过管道写入日志系统:

ps | hiklogrec -b sysinit

1728389734479

日志查看导出

查看导出日志都需要基于hiklog编译出的hiklogcat工具:

1728388873452

查看内存日志

hiklogcat -b log_dev

1728388957498

二进制日志是一样的:

1728389090910

hiklogcat还支持日志过滤功能:

tag过滤:

1728389979322

打印大于某个等级的日志:

1728390074281

同时使用:

1728390139108

导出内存日志

hiklogcat -b system -f system.log

1728389055678

导出flash日志

hiklogcat -b events -H

1728390633438

因为flash日志一般变成文本格式内容会非常多,并不适合打到控制台,所以还有一种办法就是将文件系统中的那个日志文件导出。

1728390391637

导出后可以在服务器中解析:其中 -H代表解析压缩日志,-f代表解压缩文件名称,-F代表压缩日志 -b 指定日志设备。

1728441521148

展开后的日志大概有17M左右。

日志方案移植

该日志方案移植关键在于创建保留内存,具体创建方式参考《Linux预留内存与基于预留内存的日志文件系统》。然后在uboot启动过程传参即可:

1728390925898

HIKTOP使用方式介绍

hiktop是基于hiklog机制开发的系统性能采集工具

主要基于page_owner机制以及常见几种开源工具采集性能的方式。下面简单介绍一下使用方式:

需要在系统启动的时候拉起hiktop可执行程序:

1728391795662

1728391565124

导出hiklog二进制日志,然后将该信息使用hiklogcat转化为文本日志,文本日志格式如下:

1728391594182

这里的信息其实也可分析但是信息不够直观,信息密度太低,可以进一步处理下。

将日志拷贝到hiktop底下的tools目录,然后运行hiktopplot.py脚本:

可以得到如下一份运行报告。

1728391651445

正常运行时,采集频率是很低的,一般3min采集一次,但是这个频率可以通过anycall调整:

1728391915689

这条命令的功能是将page_info的采集周期调整到1s 1次。

最后修改日期: 2024年11月19日

作者

留言

撰写回覆或留言

发布留言必须填写的电子邮件地址不会公开。