#C语言实现一个简单便捷的日志打印宏

[调试手段] [日志系统]

在写应用的时候难免会遇到一些要调试的代码段，习惯了Windows下IDE的调试手段的人，刚开始面对嵌入式的交叉编译环境的时候一般会想有什么好的调试手段吧，这里总结一下最传统的调试方法：打印日志。并通过C语言实现一个简单便捷的日志打印宏。

---

##Sample

在程序运行过程中,如果我们想调试某段代码,那么一般在那段代码中加printf(); 打印出想看的信息即可.

printf("Sample print\n");

但如果我们遇到如下类型,存在多数相同日志信息的时候该如何具体定位那一段代码出现了问题呢？

		//sample
        s32Ret = SAMPLE_COMM_VENC_Start(VencChn, enPayLoad[2], \
                                        gs_enNorm, enSize[2], enRcMode, u32Profile);
        if (HI_SUCCESS != s32Ret)
        {
            SAMPLE_PRT("Start Venc failed!\n");
            goto END_VENC_1080P_CLASSIC_5;
        }

        s32Ret = SAMPLE_COMM_VENC_BindVpss(VencChn, VpssGrp, VpssChn);
        if (HI_SUCCESS != s32Ret)
        {
            SAMPLE_PRT("Start Venc failed!\n");
            goto END_VENC_1080P_CLASSIC_5;
        }

可以使用编译器预置宏 __TIME__、__LINE__、__FILE__、__FUNCTION__等，来定位打印出现的文件，函数，及行数等.

__TIME__为编译时间，__LINE__当前行数，__FILE__所在文件，__FUNCTION__所在函数.

printf("something debug at time [%s] in function [%s] on line [%d] of file [%s],\n", __TIME__, __FUNCTION__, __LINE__, __FILE__);

##自定义宏

可是每个打印都这么写启不是很麻烦，我们可以定义如下的宏来简化.

#define TAG "TEST"

#define LOG_D(...) \
		do{\
			printf("D/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0)

#define LOG_W(...) \
		do{\
			printf("W/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0)

#define LOG_E(...) \
		do{\
			printf("E/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0)

	//测试代码
	LOG_D("something debug");
	LOG_W("something warning");
	LOG_E("something error");

##关于注释

如果我们只是需要在调试阶段加这些打印,正常情况下不需要这些打印,当然也可以通过宏实现.

#define TRUE 1
#define FALSE 0

#define TAG "TEST"
#define DEBUG FALSE

#if DEBUG
#define LOG_D(...) \
		do{\
			printf("D/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0)
#else
#define LOG_D(...)
#endif

##log应该包含的信息

当然有些情况这类日志还是不能充分的满足我们的要求的例如:
如果我们想知道一个服务拉起一个进程所产生的延迟是多少,这个时候我们的log还需要有执行时间的记录。
总的来说一条log最好能包含以下信息：级别，时间，tickcount，进程id，线程id，filter，Log正文内容，

级别	说明
级别	这个可以参照大多数的三方库里面的做法，分为INFO，WARNING, ERROR，FATAL等等级别。不过我们目前从方便使用的角度考虑只分了DEBUG和RELEASE两个级别，省的开发人员去写个LOG还要考虑这个LOG到底属于什么类型。
时间	这个就很简单了，一般精确到MS就可以了，主要是用于查看程序运行的大致时间信息。
进程ID	关于进程ID这个信息需不需要，取决于你的LOG系统存储实际方式了，如果你的LOG数据是每个进程又自己独立的存储文件，那就不需要。如果是多个进程共享同一个存储，那就需要加上这一项。另一点即使你的LOG存储系统是进程独立的，为了支持动态查看LOG信息，最好还是加上这一项。
线程ID	在解决多线程问题的时候，这一项信息是必不可少的。
Filter	主要用于查找某一类LOG时候方便，这个Filter是开发人员在开发过程中自己定义的，比如开发者xiaowang写了个模块，他为了能在LOG中很容的找到这一类LOG信息，于是就给这些LOG设置了filter为“xiaowang”
LOG正文内容	这个就没太多说的，主要就是LOG信息了

对于一个完备的日志系统这些是必要的。便于我们快速的跟踪流程、监控运行状态、定位问题等。
最后再添加一条时间的记录的例子，结束本文。

#define TRUE 1
#define FALSE 0

#define TAG "TEST"
#define DEBUG TRUE

#define TIMEPRINT \
	do{\
	struct timeval now;\
	struct tm *ptime = NULL;\
	suseconds_t mstime;\
	\
	gettimeofday(&now, NULL);\
	ptime = gmtime(&now.tv_sec);\
	mstime = now.tv_usec/10000;\
	\
	printf("%d-%d-%d-%d-%d-%d:%02d  ", 1900 + ptime->tm_year, 1 + ptime->tm_mon, ptime->tm_mday, ptime->tm_hour, ptime->tm_min, ptime->tm_sec, mstime);\
	}while(0);

#if DEBUG
#define LOG_D(...) \
		do{\
			TIMEPRINT\
			printf("D/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0);
#else
#define LOG_D(...)
#endif

#define LOG_W(...) \
		do{\
			TIMEPRINT\
			printf("W/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0);

#define LOG_E(...) \
		do{\
			TIMEPRINT\
			printf("E/%s: ",TAG);\
			printf(__VA_ARGS__);\
			printf(" (%s, %d)\n", __FILE__,__LINE__);\
		}while(0);

测试代码：

	LOG_D("something debug");
	int i = 999999999;
	while(i--);
	LOG_W("something warning");
	sleep(1);
	LOG_E("something error");

总结

通过自行定义的日志打印宏,这样就能便捷的在自己的程序中调试代码了,可以根据自己程序的需要自行定义宏.
当然在大型的项目工程中,例如安卓系统,它们都有一套自己的日志系统，用于监控及排查软件故障。一般会在运行过程中产生日志文件，包括时间、TAG、进程名、消息结构、函数返回值、执行情况等信息。在程序发生崩溃的时候甚至有单独的ANR或core dump等文件生成。通过阅读这些日志和文件，我们能快速跟踪程序流程，排查程序问题，因此熟练的掌握日志系统，并通过日志快速的定位问题，是作为一个软件工程师的基本要求。

本文就写到这了，有机会的话，会再写一个完整日志系统,敬请关注。