转自戈神 如何打印日志

日志打印的基本原则是:重点突出、尽量短、自然、易搜索

成功日志:动词+一些事
Created sockfd=29 to localhost:7407
Waiting for channel@localhost:7406 to start
Destroyed FiberGroup(0x159e000)
动词开头大写,更易被注意到。写前面而不是后面,可以更快地感知主题。
别忘了加上时态,以更好地区分事情前后,读起来也更自然。发生在事情之前用进行时(常为ing后缀),发生在事情之后的用过去式(常为ed后缀)。
尽量用不同的动词,grep会比较方便,否则易匹配到大量无关日志。

失败日志:Fail to 动词+一些事
Fail to plan tps, Not enough tps
Fail to wait epollfd=57982058515, The fiber has a break
"Fail to"可以让阅读者第一眼就意识到"有什么失败了",而无需扫描那些夹杂在句子中央的"failed"。区分成功和失败也非常机械化,搜索一下Fail to+动词就好了。其余规则参考成功日志。

打印多个值:name1=value1 name2=value2 name3=value3 ...
不要用冒号分隔name和value,因为冒号还有其他很多含义和使用场景(如ip和端口之间),会干扰到grep效率,而等号几乎不可能有其他含义。
日志应尽量避免多层结构,否则脚本处理很麻烦。对于少量的结构化数据打印:
value是pb message的话可以直接调用ShortDebugString()获得字段描述。
支持RTTI的语言一般都可直接生成结构体的描述。
自定义描述可参考如下方法:value是结构体的话用{}包围,空格分隔,如{time=10 tps=1000 host=192.168.0.1:8080},用逗号分隔的话会显得比较挤,看不清楚;value是数组的话用[]包围,空格分隔,比如[12 13 14 15 16] ,若要突出下数组的长度,可加上长度前缀,用冒号分隔,如 5:[12 13 14 15 16];value是pair或tuple的话用()包围,逗号分隔,比如(10,20)。

用简单英语
越复杂的单词越容易拼错。当需要处理紧急线上问题时,复杂或拼错的单词可能导致排查者找不到对应的日志,来来回回增加沟通成本。

懂得汇总
虽然每秒打印上百条日志,对程序影响较小(打印一条日志的代价大约是10us)。但如果一秒打上几万甚至几十万条,那这个服务基本就不可用了(debug时除外)。
当需要高频打印日志时,请考虑:
能否用统计量代替,如个数、均值、方差、异常值等。可以的话应考虑bvar或prometheus。
这些值是否有明显的共性,可以把一批数据汇总为一行?如一个session的所有日志可以缓存在thread-local或session-local中直至session结束时再一次打印出去。
如果你真的需要每个值,且这些值难以归并(极其少见),应该把它们打印到专门的文件中去并进行相应的IO优化,而不是打印在普通程序日志中。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,080评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,422评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 157,630评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,554评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,662评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,856评论 1 290
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,014评论 3 408
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,752评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,212评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,541评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,687评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,347评论 4 331
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,973评论 3 315
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,777评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,006评论 1 266
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,406评论 2 360
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,576评论 2 349

推荐阅读更多精彩内容

  • 原子操作,即不可分割开的操作;该操作一定是在同一个cpu时间片中完成,这样即使线程被切换,多个线程也不会看到同一块...
    德阳凯子哥阅读 20,169评论 0 11
  • 上音乐课时,我们正在唱歌,可洪诗灿却点到了我的名,让我站后面去。我听了,心想:我又没得罪你,为什么要我站后面...
    万彬浩阅读 264评论 0 0