如何打印有效的日志

log就像车辆保险,没人愿意为保险付钱,但是一旦出了问题谁都又想有保险可用

  几乎学习每一门语言,都是从 “hello world” 开始的,日志是新手程序员学习和调试的一大利器。当项目上线之后,也会有各种各样的日志。可以是记录用户的行为,服务器的状态,服务器的异常等。

log

  当某天你看到自己的控制台上打印出如下日志:

Error Happended

  你觉的你会打日志吗?
  当从log中看到这条日志的时候,我们是知道程序出错了,但是除了知道错了,我们什么都不知道。我自己也这么打过,老板一问,这个是出的什么问题?能立刻解决吗?顿时就傻了。在我看来,日志打印是一门艺术,而且长期被特别是前端程序员忽视

  如何打印有效日志,有以下几个方面:

  • why to log
  • when to log
  • what to log
  • log and tips

# why to log

  为什么要打印日志,那就要从我们的目的出发,我们是要检查问题,还是要记录代码执行顺序,还是要记录事件发生时间节点,还是要提供报警机制信息等。
  对于调试阶段,大都是为了处理逻辑时序和问题发生节点;对于线上项目,为了准确定位并解决处理问题; 不存在没 bug 的程序,高级程序员相比与普通程序员,更多的优势在于他能写出易于维护的代码,在合适的地方,打印关键日志内容,在不需要浏览程序代码的情况下,便能准确定位出问题。

# when to log

(1) 调试开发日志
  目的是开发期调试程序使用,这种日志量比较大,且没有什么实质性的意义,只应该出现在开发期,而不应该在项目上线之后输出。
(2) 用户行为日志
  这种类型的日志,记录用户的操作行为,用于大数据分析,比如监控、风控、推荐等等。这种日志,一般是给其他团队分析使用,而且可能是多个团队,因此一般会有一定的格式要求,开发者应该按照这个格式来记录,便于其他团队的使用。当然,要记录哪些行为、操作,一般也是约定好的,因此,开发者主要是执行的角色。这种日志,又叫事件上报,或埋点。
(3)程序运行日志
  记录程序的运行状况,特别是非预期的行为、异常情况,这种日志,主要是给开发、维护人员使用。什么时候记录,记录什么内容,完全取决于开发人员,开发者具有高度自主性。本文讨论的主要也是指这种类型的日志,因为作为一个服务端开发、运维人员,程序运行日志往往是解决线上问题的救命稻草。
(4)记录系统或者机器的状态
  比如网络请求、系统CPU、内存、IO使用情况等等,这种日志主要是给运维人员使用,生成各种更直观的展现形式,在系统出问题的时候报警。

# what to log

  一条信息完整的日志,应该包含 when、where、level、what、who、context
  我们要记录日志,总是要在某个时机,比如用户的某个请求、某个网络调用、或者内部状态发生了改变。在后文中,统称为事件(event),即日志内容是对某个事件的描述。

when: the time event happens
when,就是我们打印日志的时间(时间戳),注意这里的时间指的是日志记录的事件的发生时间,而不是日志被最终输出的时间。

where: where the event happens
where,就是指日志是在哪里的被记录的,本质上来说,是事件的产生地点。根据情况,可以具体到是哪个模块、哪个文件,甚至是哪一个函数、哪一行代码;目的是为了能一眼就看出日志在哪里产生的,而不去grep代码。

level:how importance of the event
  每一条日志都应该有log level,log level代表了日志的重要性、紧急程度。例如:debug,info,warn,error,fatal(critical); 调试日志是最不重要的,是不应该出现在线上项目的,但是程序运行报错日志却需要认真对待,因为代表程序已经出现了异常;如果是fatal日志,即使是在大半夜,也得立刻起来分析、处理。

what:what is the log message
what是日志的主体内容,应该简明扼要的描述发生的什么事情。要求可以通过日志本身,而不是重新阅读产生日志的代码,来大致搞清楚发生了什么事情。下面这个日志是不合格的:

def user_login(username, password):
    if not valid_username(username):
        logger.warn('Error Happened')
        return
    # some others code

是的,我知道,出了问题了,但是日志应该告诉我出了什么问题,所以日志至少应该是这样的:

def user_login(username, password):
    if not valid_username(username):
        logger.warn('user_login failed due to unvalid_username')
        return
    # some others code

who:the uniq identify
who代表了事件产生者的唯一标识(identity),用于区分同样的事件。特别是在服务器端,都是大量用户、请求的并发,如果日志内容不包含唯一标识信息,那么这条日志就会淹没在茫茫大海中,比如下面这条日志:

def user_login(username, password):
    # some code has check the username
    if not valid_password(password) or not check_password(username, password):
        logger.warn('user_login failed due to password')
        return
    # some others code

有效的日志应该是包含用户信息的:

def user_login(username, password):
    # some code has check the username
    if not valid_password(password) or not check_password(username, password):
        logger.warn('user_login failed due to password, username %s', username)
        return

当然,这个唯一标识是很广泛的,需要根据具体情况决定,如果网络请求,可能更好的是requestid、sessionid;如果是系统日志,那么可能是进程、线程ID;如果是分布式集群,那么可能是副本的唯一id。

context: environment when event happens
  日志记录的事件发生的上下文环境直观重要,能告知事件是在什么样的情况发生的。当然,上面提到的when、where、who都属于上下文,这些都是固定的,通用的。context专指高度依赖于具体的日志内容的信息,这些信息,是用于定位问题的具体原因

def user_login(username, password):
    # some code has check the username
    if not valid_password(password) or not check_password(username, password):
        logger.warn('user_login failed due to password, username %s', username)
        return
    # some others code

如上代码只能知道出什么错误了,但是并不能知道当时出错误的上下文环境,因此还是不足。这部分弹性最大,需要结合具体项目思考加上什么内容能定位到问题发生的原因。

# log and tips

  如何输出日志?单纯的 console.log() 并不能满足我们的需求,可以引入框架,常见的log框架有 glog,log4cpp,log4j,elf4j;
  在很多logging框架模块(thon logging、log4j)中,都有named logger这一概念,这个name就可以是module, filename, classname或者instance,这就解决了上一章节提到了“where the event happen”这个问题。

(1)设置log的输出等级
  这样可以不改程序代码,仅仅修改log的输出等级,就能够控制哪些日志输出,哪些日志不输出。比如我们在开发期的调试日志,都可以设置为DEBUG,上线的时候设置输出等级为INFO,那么这些调试日志就不会被输出。

(2)设置每条日志默认包含的内容
  设置每条日志默认包含哪些信息,比如时间、文件、行号、进程、线程信息

(3)设置日志的输出目标
  通过配置,可以指定日志是输出到stdout,还是文件,还是网络。特别是在linux服务器上,将日志输出到syslog,再使用syslog强大的处理、分发功能,配合elk系统进行分析,是很多应用程序的通用做法。

# log never throw

  打印日志,是为了记录事故发生的现场,以便发现问题,解决问题。那么就得保证,打印日志这一行为本身不能引入新的问题,比如,不能出错抛异常。这就好比,处理车祸的消防车不能冲进现场一样。

# log when u think something never happen

  不能认为某种情况一定不会发生,因为程序在高并发下和网络本省的不确定性,它还是可能发生,如果这个地方属于关键代码,应该就为error级别的错误,也经常就是因为这种地方,让查bug时候的你,有种想骂娘的冲动。

# 总结

  打日志的时候总是很随意,至于查bug的时候恨不得“手撕鬼子”,为了自己的人身安全,建议还是好好写每一条日志吧!
  不对的地方,欢迎指正。

参考

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

推荐阅读更多精彩内容

  • Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具(例如配置管理,服务发现,断路器,智...
    卡卡罗2017阅读 134,048评论 18 139
  • Android 自定义View的各种姿势1 Activity的显示之ViewRootImpl详解 Activity...
    passiontim阅读 170,471评论 25 707
  • 在应用程序中添加日志记录总的来说基于三个目的:监视代码中变量的变化情况,周期性的记录到文件中供其他应用进行统计分析...
    时待吾阅读 4,807评论 1 13
  • 在应用程序中添加日志记录总的来说基于三个目的:监视代码中变量的变化情况,周期性的记录到文件中供其他应用进行统计分析...
    时待吾阅读 4,887评论 0 6
  • 1、不使用GCD的方式 2、使用GCD // 补充再来说说:Objective-C 里的 Alloc 和Alloc...
    Jt_Self阅读 5,587评论 0 1