嵌入式设备系统日志记录及调试技巧

系统日志

系统日志是一个很好分析系统状态的工具，可以监控设备软件的运行状态，及时记录问题点以及关键信息，方便开发人员后期定位以及解决问题。web后台开发中，有很多很方便的日志框架，可以很方便快捷得实现系统日志，而嵌入式相对来说就需要自行实现。

SpringCloud+LogBack日志效果

2020-05-31 00:00:36.063 DEBUG [cloud-data-communication-service,a4d26cd44853a39b,a4d26cd44853a39b,false] 5888 --- [http-nio-15050-exec-5] c.s.s.c.c.a.interceptor.UserInterceptor  : //TODO 校验token:null
2020-05-31 00:00:36.064 DEBUG [cloud-data-communication-service,a4d26cd44853a39b,a4d26cd44853a39b,false] 5888 --- [http-nio-15050-exec-5] c.s.s.c.c.core.util.UserContextHolder    : 设置上下文信息:{}
2020-05-31 00:00:36.192 DEBUG [cloud-data-communication-service,a4d26cd44853a39b,a4d26cd44853a39b,false] 5888 --- [http-nio-15050-exec-5] o.s.w.s.r.ResourceHttpRequestHandler     : Resource not found

• Date and Time: Millisecond precision and easily sortable. 日期和时间:毫秒精度，易于排序。
• Log Level: ERROR, WARN, INFO, DEBUG, or TRACE. 日志级别:错误、警告、信息、调试或跟踪。
• — separator to distinguish the start of actual log messages. 分隔符，用于区分实际日志消息的开始。
• Thread name: Enclosed in square brackets (may be truncated for console output). 线程名称:括在方括号中(可能会被截断以用于控制台输出)。
• Process ID. 进程ID。
• Logger name: This is usually the source class name (often abbreviated). 日志程序名称:这通常是源类名称(通常缩写)。
• The log message. 日志消息。

嵌入式设备一般来说，常见的日志输出方式基本就以下四种：

• 串口 ——最直接最常见的方式，也是本人最常用的调试方式。
• 内存 —— 最简单的方法，指定部分ram 存储日志信息，不过嵌入式设备内存紧张，日志信息不会存太多。
• 文件 ——也比较常见，针对一些带sd卡或者片外flash的设备。方便做日志存储。
• 显示模块、网络网口等其他输出—— 不解释。

这里主要还是扯扯串口和文件这种。毕竟日志这种东西更多的是用在嵌入式初期调试验证，更直观；其次就是才是通过日志文件分析仪器故障。

串口日志

串口打印基本都是重写putc函数+不使用半主机模式，没什么好说的，网上一抓一大把。

基本串口打印

/********** 禁用半主机模式 **********/
#pragma import(__use_no_semihosting)
 
struct __FILE
{
	int a;
};
 
FILE __stdout;
 
void _sys_exit(int x)
{	
}
/*****************************************************
*function:	写字符文件函数
*param1:	输出的字符
*param2:	文件指针
*return:	输出字符的ASCII码
******************************************************/
int fputc(int ch, FILE *f)
{
	while(USART_GetFlagStatus(USART1, USART_FLAG_TC) == RESET);		//等待上次发送结束
	USART_SendData(USART1, (unsigned char)ch);				//发送数据到串口
	return ch;
}

贴上上面的代码,再另外初始化串口，就可以实现printf打印日志信息了，但日志信息讲究日志层级分层，一股脑信息太多杂乱。优化下然后就有了以下代码

串口日志层级分层

 
#ifdef ENBALE_DEBUG
	#define DBG_ERROR(fmt,args...) printf("[%s,%s,%d] ERROR:"#fmt"\r\n", __FILE__,__FUNCTION__,__LINE__,##args)
	#define DBG_WARN(fmt,args...)  printf("[%s,%s,%d] WARN:"#fmt"\r\n", __FILE__,__FUNCTION__,__LINE__,##args)
	#define DBG_DEBUG(fmt,args...) printf("[%s,%s,%d] DEBUG:"#fmt"\r\n", __FILE__,__FUNCTION__,__LINE__,##args)
#elif  ENBALE_WARN
	#define DBG_ERROR(fmt,args...) printf("[%s,%s,%d] ERROR:"#fmt"\r\n", __FILE__,__FUNCTION__,__LINE__,##args)
	#define DBG_WARN(fmt,args...)  printf("[%s,%s,%d] WARN:"#fmt"\r\n", __FILE__,__FUNCTION__,__LINE__,##args)
	#define DBG_DEBUG(fmt,args...)  
#elif  ENBALE_ERROR
	#define DBG_ERROR(fmt,args...) printf("[%s,%s,%d] ERROR:"#fmt"\r\n", __FILE__,__FUNCTION__,__LINE__,##args)
	#define DBG_WARN(fmt,args...)  
	#define DBG_DEBUG(fmt,args...) 
#else
	#define DBG_ERROR(fmt,args...)  
	#define DBG_WARN(fmt,args...)   
	#define DBG_DEBUG(fmt,args...)   
#endif

这个也是之前用的比较多的，以上代码是模仿linux 内核的写法，可以比较好的做到日志信息分层，编译时相加对应的编译开关即可。另外如果嵌入式设备有可靠的时钟，可以加上日志信息时间。
但有个弊端就是，切换debug等级时，需要重新编译且需更新固件，而嵌入式设备出现异常后更新固件往往复位后，故障有时很难复现，调试起来比较浪费时间。

优化后的带信息分层的串口日志

需要不通过更新新固件切换debug等级，那只能放弃debug宏,自行实现log函数。也就是如下内容，也是本人正在用的。

#include <stdarg.h> 
#include <stdio.h> 
const unsigned short debugLevel __attribute__((section("ConfigSector"))) = 0; //指定到配置扇区
enum LogLevel
{
    ERROR_FILTER = 1,
    WARN_FILTER  = 2,
    DEBUG_FILTER = 3,
};

#define OUPUT_ERROR (debugLevel>= ERROR_FILTER)
#define OUPUT_WARN (debugLevel>= WARN_FILTER)
#define OUPUT_DEBUG (debugLevel>= DEBUG_FILTER)
//strrchr(__FILE__, '\\')去除目录路径，只保留文件
#define DBG_ERROR(fmt,args...) error_core(strrchr(__FILE__, '\\'),__FUNCTION__,__LINE__,fmt,##args)
#define DBG_WARN(fmt,args...)  warn_core(strrchr(__FILE__, '\\'),__FUNCTION__,__LINE__,fmt,##args)
#define DBG_DEBUG(fmt,args...) debug_core(strrchr(__FILE__, '\\'),__FUNCTION__,__LINE__,fmt,##args)

void change_debug_level(enum LogLevel level)
{
	unsigned short temp = level; //枚举sizeof会按子值优化
	FLASH_Write(&temp,&debugLevel ,1); //flash写入一个半字两字节至debuglevel的位置
}

void error_core(const char* filename,const char* func, int line,const char* fmt, ...)
{
	if(OUPUT_ERROR)
	{
		va_list valist;/*可变参数的宏*/
		printf("[%s,%s,%d] ERROR:",filename,func,line);
		va_start(valist,fmt);
		vprintf(fmt,valist);
		va_end(valist);
		printf("\r\n");
	}
}	

void debug_core(const char* filename,const char* func, int line,const char* fmt, ...)
{
	if(OUPUT_DEBUG)
	{
		va_list valist;/*可变参数的宏*/
		printf("[%s,%s,%d] DEBUG:",filename,func,line);
		va_start(valist,fmt);
		vprintf(fmt,valist);
		va_end(valist);
		printf("\r\n");
	}
}	

void warn_core(const char* filename,const char* func, int line,const char* fmt, ...)
{
	if(OUPUT_WARN)
	{
		va_list valist;
		printf("[%s,%s,%d] WARN:",filename,func,line);
		va_start(valist,fmt);
		vprintf(fmt,valist);
		va_end(valist);
		printf("\r\n");
	}
}	

通过flash存储调试等级，即可在程序运行中修改等级，同时通过封装printf函数实现日志记录。

这里面我使用的芯片为哈弗体系，全局常量存储编译器默认分配在flash，需要注意如果使用片内flash时，注意存储调试等级的flash块不要与代码区重合，要不然修改调试等级擦除flash块同时PC指针指向当前块的代码区，会导致仪器死机；

在项目中我通过散列加载指定一个扇区，专门存储一些配置数据。

Config_ROM2 0x08010800 FIXED 0x0000800  {  ;指定根区，即load address = execution address，
   .ANY (ConfigSector)
  }

const unsigned short debugLevel attribute((section(“ConfigSector”))) = 0; //指定到配置扇区

日志文件存储

串口只能做实时信息输出，所以只用调试阶段比较适用，查阅历史日志排查故障还是得通过日志文件来管理。
一般嵌入式设备日志管理都是fatfs，fatfs移植啥的就不多说。

基本代码逻辑是没有什么变化，将以上串口日志输出改为文件输出，文件管理的话最好加上rtc模块好做文件切分管理。

#include <stdarg.h> 
#include <stdio.h> 
const unsigned short debugLevel __attribute__((section("ConfigSector"))) = 0; //指定到配置扇区
enum LogLevel
{
    ERROR_FILTER = 1,
    WARN_FILTER  = 2,
    DEBUG_FILTER = 3,
};
u8 outputFile[30];
#define OUPUT_ERROR (debugLevel>= ERROR_FILTER)
#define OUPUT_WARN (debugLevel>= WARN_FILTER)
#define OUPUT_DEBUG (debugLevel>= DEBUG_FILTER)


void change_debug_level(enum LogLevel level)
{
	unsigned short temp = level; //枚举sizeof会按子值优化
	FLASH_Write(&temp,&debugLevel ,1); //flash写入一个半字两字节至debuglevel的位置
}

void error_core(const char* filename,const char* func, int line,const char* fmt, va_list valist)
{
	if(OUPUT_ERROR)
	{
		FIL fsrc;
		time_t time =rtc_get_time(); //按自己的系统获取时间
		sprintf(&outputFile[0], "0:/log_%04d-%02d-%02d.txt",
			time.Year, time.Month, time.Day);
		if(f_open( &fsrc , outputFile,FA_READ|FA_WRITE|FA_OPEN_APPEND) == FR_OK )
		{
			f_printf(&fsrc,"[%04d-%02d-%02d %02d:%02d:%02d] [%s,%s,%d] ERROR:",time.Year, time.Month, time.Day,time.Hour, time.Minute, time.Second,filename,func,line);
			f_vprintf(&fsrc,fmt,valist);//需要自己实现
			f_printf(&fsrc,"\r\n");
			f_close(&fsrc);
		}
	}
}	

void debug_core(const char* filename,const char* func, int line,const char* fmt, va_list valist)
{
	if(OUPUT_DEBUG)
	{
		FIL fsrc;
		time_t time =rtc_get_time(); //按自己的系统获取时间
		sprintf(&outputFile[0], "0:/log_%04d-%02d-%02d.txt",
			time.Year, time.Month, time.Day);
		if(f_open( &fsrc , outputFile,FA_READ|FA_WRITE|FA_OPEN_APPEND) == FR_OK )
		{
			f_printf(&fsrc,"[%04d-%02d-%02d %02d:%02d:%02d] [%s,%s,%d] DEBUG:",	time.Year, time.Month, time.Day,time.Hour, time.Minute, time.Second,filename,func,line);
			f_vprintf(&fsrc,fmt,valist);//需要自己实现
			f_printf(&fsrc,"\r\n");
			f_close(&fsrc);
		}
	}
}	

void warn_core(const char* filename,const char* func, int line,const char* fmt, va_list valist)
{
	if(OUPUT_WARN)
	{
		FIL fsrc;
		time_t time =rtc_get_time(); //按自己的系统获取时间
		sprintf(&outputFile[0], "0:/log_%04d-%02d-%02d.txt",
			time.Year, time.Month, time.Day);
		if(f_open( &fsrc , outputFile,FA_READ|FA_WRITE|FA_OPEN_APPEND) == FR_OK )
		{
			f_printf(&fsrc,"[%04d-%02d-%02d %02d:%02d:%02d] [%s,%s,%d] WARN:",	time.Year, time.Month, time.Day,time.Hour, time.Minute, time.Second,filename,func,line);
			f_vprintf(&fsrc,fmt,valist);//需要自己实现
			f_printf(&fsrc,"\r\n");
			f_close(&fsrc);
		}
	}
}	

f_vprintf需要自己实现，将f_printf变参改为va_list类型即可。

/*-----------------------------------------------------------------------*/
/* Put a Formatted String to the File                                    */
/*-----------------------------------------------------------------------*/

int f_vprintf (
	FIL* fp,			/* Pointer to the file object */
	const TCHAR* fmt,	/* Pointer to the format string */
	 va_list arp					/* Optional arguments... */
)
{

	putbuff pb;
	BYTE f, r;
	UINT i, j, w;
	DWORD v;
	TCHAR c, d, str[32], *p;


	putc_init(&pb, fp);

	for (;;) {
		c = *fmt++;
		if (c == 0) break;			/* End of string */
		if (c != '%') {				/* Non escape character */
			putc_bfd(&pb, c);
			continue;
		}
		w = f = 0;
		c = *fmt++;
		if (c == '0') {				/* Flag: '0' padding */
			f = 1; c = *fmt++;
		} else {
			if (c == '-') {			/* Flag: left justified */
				f = 2; c = *fmt++;
			}
		}
		if (c == '*') {				/* Minimum width by argument */
			w = va_arg(arp, int);
			c = *fmt++;
		} else {
			while (IsDigit(c)) {	/* Minimum width */
				w = w * 10 + c - '0';
				c = *fmt++;
			}
		}
		if (c == 'l' || c == 'L') {	/* Type prefix: Size is long int */
			f |= 4; c = *fmt++;
		}
		if (c == 0) break;
		d = c;
		if (IsLower(d)) d -= 0x20;
		switch (d) {				/* Atgument type is... */
		case 'S' :					/* String */
			p = va_arg(arp, TCHAR*);
			for (j = 0; p[j]; j++) ;
			if (!(f & 2)) {						/* Right padded */
				while (j++ < w) putc_bfd(&pb, ' ') ;
			}
			while (*p) putc_bfd(&pb, *p++) ;		/* String body */
			while (j++ < w) putc_bfd(&pb, ' ') ;	/* Left padded */
			continue;

		case 'C' :					/* Character */
			putc_bfd(&pb, (TCHAR)va_arg(arp, int)); continue;

		case 'B' :					/* Unsigned binary */
			r = 2; break;

		case 'O' :					/* Unsigned octal */
			r = 8; break;

		case 'D' :					/* Signed decimal */
		case 'U' :					/* Unsigned decimal */
			r = 10; break;

		case 'X' :					/* Unsigned hexdecimal */
			r = 16; break;

		default:					/* Unknown type (pass-through) */
			putc_bfd(&pb, c); continue;
		}

		/* Get an argument and put it in numeral */
		v = (f & 4) ? (DWORD)va_arg(arp, long) : ((d == 'D') ? (DWORD)(long)va_arg(arp, int) : (DWORD)va_arg(arp, unsigned int));
		if (d == 'D' && (v & 0x80000000)) {
			v = 0 - v;
			f |= 8;
		}
		i = 0;
		do {
			d = (TCHAR)(v % r); v /= r;
			if (d > 9) d += (c == 'x') ? 0x27 : 0x07;
			str[i++] = d + '0';
		} while (v && i < sizeof str / sizeof *str);
		if (f & 8) str[i++] = '-';
		j = i; d = (f & 1) ? '0' : ' ';
		if (!(f & 2)) {
			while (j++ < w) putc_bfd(&pb, d);	/* Right pad */
		}
		do {
			putc_bfd(&pb, str[--i]);			/* Number body */
		} while (i);
		while (j++ < w) putc_bfd(&pb, d);		/* Left pad */
	}

	return putc_flush(&pb);
}

另外提一句写文件比较花时间，最好单独开一个日志进程调用以上程序处理日志文件写入，任务进程通过消息队列的将日志内容传给日志进程。