来源:https://zhuanlan.zhihu.com/p/24785018?from_voters_page=true
本文适用范围:Linux系统
使用语言:C/C++
打log的原则
1、异常分支或错误处理一定要打log
2、重大操作时一定要打log,下面打log场景会讲述
log格式的原则
1、时间戳必须有,最好能够精确到微秒。精确到秒的时间戳,相信很多人都熟悉,这能够确认问题的时间和系统uptime的对比,能够进一步还原问题的场景。
至于到微秒,在多线程程序下,如果进程停止响应,可以从日志时间看是否死锁。
一般格式:
[2017-01-09 12:16:30.541]
2.日志所在位置的文件名和行号。不用多说,这个是用来定位问题根源的。其实最主要的还是为了防止纠纷。因为大部分程序员都喜欢复制粘贴,如果你不加文件名和行号,一个程序员复制你的代码,修改一下,出错了,那他就会拉你下水。
一般格式:
[2017-01-09 12:16:30.541][network.c:541]
3. 有进程ID,有些日志机制在进程重启时不会重新生成日志文件,而是直接把日志追加到同一个日志文件的末尾,或者有时候同一个程序的多个进程同时运行,也可能写入同一个日志文件。
一般格式:
[2017-01-09 12:16:30.541][network.c:541][pid=15529]
4.有线程ID,在多线程程序中,如果不添加线程ID,则很难追踪程序的行为
一般格式:
[2017-01-09 12:16:30.541][network.c:541][pid=15529][thread=0x12345]
5. 日志级别。日志反映问题,针对不同的紧急程序问题,有不同的日志级别,一般使用Error、Warning、Info、Debug。定义不同的级别,也可以方便在日志中查找问题的来源。
一般格式:
[2017-01-09 12:16:30.541][network.c:541][pid=15529][thread=0x12345][Error]
日志场景
1、申请内存的时候,如果失败,打印出申请的大小,以前我申请内存失败的时候,都是直接打印:
[2017-01-09 12:16:30.541][network.c:541][pid=15529][thread=0x12345][Error]Failed to allocate memory
后来在重构过程中遇到了一个问题:该进程运行了较长时间之后,大概一天左右的时间,其他程序向其发送消息都会收到失败的响应,并且日志中会出现大量“Failed to allocate memory”等内存失败的消息。
使用 free 命令发现还有好几 GB 的空闲物理内存,而使用 top 命令发现该进程只占用了 700MB 内存。当时我怀疑是内存碎片导致的。于是打印出请求的内存大小,结果得到了一堆这样的结果:
[2017-01-09 12:16:30.541][network.c:541][pid=15529][thread=0x12345][Error]Failed to allocate memory of size 65536
[2017-01-09 12:16:30.588][network.c:541][pid=15529][thread=0x12345][Error]Failed to allocate memory of size 1048576当时我看了一下代码引用的数据结构,最小的64K,最大的16M,基本上一个结构里面就包含了很多个大数组,当时我就把那些数组都改成指针,然后再应用,代码变得很臃肿,不过这个问题再也没有出现过。
再查看bug系统,发现这个问题很多,其他程序也存在这个问题,当时没找到根本原因,就隔了一段时间重启一下进程才解决。
2.当函数参数不为空时,应该打印日志,原因就不解释了,我们看一下对比:
前:
if ( ( pInfo == NULL ) || ( pHandler == NULL ) )
{
log( ERROR, "invalid arguments" );
}后:
if ( ( pInfo == NULL ) || ( pHandler == NULL ) )
{
log( ERROR, "invalid arguments:(pInfo, pHandler )=(%p,%p)",
pInfo, pHandler );
}3. 加载和卸载模块,并在正常和异常情况下进行打印,毕竟这些操作大多是一次性操作,对性能影响不大。
[2017-01-09 12:16:30.588][modules.c:54][pid=15529][thread=0x12345][Error]Failed to load module libftp.so, error=module already loaded
4. 操作文件目录时,若失败,则打印出文件名和错误码。例如:
[2017-01-09 12:16:30.588][config.c:120][pid=15529][thread=0x12345][Error]Failed to open file conf/ftp.xml, errno=(13:Permission denied)
假设该错误导致流程初始化失败,并且环境在客户端,则维护人员可以自行确认并解决问题。
5. 操作socket时,打印出IP、端口号或路径名(Unix socket)和错误码。例如:
[2017-01-09 12:16:30.588][network.c:541][pid=15529][thread=0x12345][Error]Failed to connect to host (10.17.128.10:9981), errno=(111:Connection refused)
假设客户环境出现错误,维护人员可以通过日志确认10.17.128.10这台机器是否在线以及对应服务是否开启,或者如果服务开启了,可能只是端口配置错误(这种情况争议最大)
6、操作数据库时,打印出相应操作的IP、端口、数据库、用户名、SQL语句、错误。例如:
[2017-01-09 12:16:30.588][dbmgr.c:781][pid=15529][thread=0x12345][Error]user tiger failed to operate in host (10.17.128.10:3365) with db test, sql="select * from users", error="no table users exists"
在客户环境中,维护人员可以通过命令行来验证这些问题,从而确定问题所在。有些人可能会考虑安全性,毕竟在日志中暴露IP、端口、库、用户名似乎不太合适。
但如果你曾经在通信行业做过在线问题维护的话你就会知道可维护性比这些细节的安全性更加重要。
7、创建新进程时,需要打印出程序名称、参数及错误代码。
[2017-01-09 12:16:30.588][process.c:154][pid=15529][thread=0x12345][Error]failed to execute program "iptables -L", errno=(2:No such file or directory)
往往在客户环境中,由于运维人员水平参差不齐,可能会出现误操作或者疏漏,导致文件丢失或者权限不正确。在公司的模拟环境中不会出现此类错误。如果日志足够详细,可以减少很多工作量。
8.解析文件的时候,需要打印出文件名、字段、行号。
[2017-01-09 12:16:30.588][config.c:120][pid=15529][thread=0x12345][Error]Failed to parse file conf/ftp.xml, line:20, tag
is not closed 总结:以上每一条原则都是血的教训。我在 H 的时候,见过太多因为日志不完整而导致的问题。一线客户经理不停地向客户要求更多时间,维护人员不停地在客户环境中寻找线索,后端领导不停地分配资源跟踪问题,后端测试人员不停地测试并试图重现问题,后端开发人员不停地查看代码。
我也看到过Z因为日志不全被客户罚款太多次,整个产品都陷入亏损。正如@帝都铁匠说的“我感觉学会日志就是编程的开始。”
‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧ 结尾 ‧‧‧‧‧‧‧‧‧‧‧‧‧‧‧
关注我的微信公众号,回复“加群”按规则加入技术交流群。
点击“阅读原文”查看更多分享,欢迎点分享、收藏、点赞、在看。
如果嵌入式系统中没有模拟器,则只能登录仿真器是什么
发布时间:2024-07-07浏览:10
热点资讯
-
魔法学徒日常:揭秘冰凤凰的强大与涅槃重生之谜 11-15
-
安卓手机加速器推荐:盘点几款实用加速器 11-15
-
免费考试软件大盘点:热门考试应用合集推荐 11-15
-
《天龙八部2》手游神器系统深度解析 11-15
-
盘点2024年耐玩经典祖玛游戏大全 11-15
-
探索蔚蓝档案月咏:全面资料解读 11-15
-
2024年大型FPS游戏盘点:前五名热门游戏一览 11-15
-
王者荣耀星之破晓云樱详解:全面攻略解析 11-15
-
山海异兽分布位置全解析:全面攻略揭示 11-15