(转)日志打印的5点建议

最近我们介绍了几款日志分析的工具,比如Scribe和LogStash这类的开源项目,以及Splunk这样的企业级工具,还有像SumoLogic和PaperTrail这样的托管服务。你可以使用这些工具从海量的日志数据提取到一些有价值的信息。

不过还有一件事它们是帮不了你的。它们都依赖于你实际输出到日志文件里面的数据。日志数据保质保量的重任就落到你肩上了。因此万一情况不妙,你又得在日志文件不全的情况下自己去调试代码,那估计你只好赶紧把原先订好的晚餐取消掉了。

为了减少出现类似的情况,我这里想分享5点日志打印的心得,希望能对你有所帮助:

线程名

就像Ringo一样,线程名应该是Java里最被低估的功能之一了。因为其实它的表述性很强。那又怎样?就像我们的名字一样,我们会给它赋予一个含义。

线程名最有用的时候应该就是多线程的情况下了。许多日志框架都会记录当前方法调用所在线程的名字。不幸的是,一般看起来都是这样的:“http-nio-8080-exec-3″,这是线程池或者容器自动分配的线程名。

我经常听到有谣传称线程名是不可变的。当然不是。线程名就是你日志中最优质的不动产,你得确保自己能正确的使用它们。通常给它赋值会带上上下文的详细信息,比如说Servlet或者任务的名字之类的,以及一些动态的上下文信息比如用户ID。

这么做的话,你的代码看起来应该是这样的:
Thread.currentThread().setName(ProcessTask.class.getName() + “: “+ message.getID);
更高级的做法是引入一个ThreadLocal的变量,然后配置一个appender,自动把里面的信息输出到日志中。

当多个线程同时在往文件中写入日志而你需要关注其中某个线程的时候,这个功能尤其有用。如果你在一个分布式或者SOA环境中运行的话,这么做还会有一个额外的好处,下面我们很快就会看到。

分布式标识符

在SOA或者消息驱动的架构中,某个任务的执行可能会涉及到多台机器。这种架构下如果出了错要进行处理的话,要想知道到底发生了什么,这里所牵涉到的相关机器以及它们的状态就显得至关重要。很多日志分析器只是帮你把这些日志收集起来,它们假设你已经有一个唯一的标志符,可以用它来进行过滤。

从设计的角度来看,这意味着系统中每一个入站操作都需要有一个唯一的ID,处理过程中会一直携带着这个ID直到处理结束。这里如果使用持久性标识比如说用户ID之类的可能并不适合,因为在一个日志文件中一个用户可能会有多个请求在同时进行处理,这就很难提取出具体的某个处理流。UUID是个不错的选择,你可以把它存储到线程名或者TLS——ThreadLocal Storage里面。

不要使用循环

你经常会看到有在循环体中进行日志打印,这么做的前提是循环的次数是有限的。

如果不出什么问题的话当然还好。不过如果代码碰到一些异常的输入导致循环无法退出的话,这就不妙了。这可不止是循环无法结束的问题了,你的程序还一直在往磁盘或者网络中写入数据。

如果只是写到自己的设备中,结果可能就只是挂了一台服务器,但如果是一个分布式的环境,就可能就是一整个集群都瘫了。所以最好还是不要在循环里面打印日志,尤其是当涉及到异常处理的时候。

我们来看一个例子,这里是在循环中来打印异常的信息:
void read() { while (hasNext()){ try { readData(); } catch {Exception e) { // this isn’t recommend logger.error(“error reading data“, e); } } }
如果readData()抛出异常并且hasNext()返回true,这段代码就会不停在打印日志。一个解决方法就是不要每次都打印出来:
void read() { int exceptionsThrown = 0; while (hasNext()) { try { readData(); } catch (Exception e) { if (exceptionsThrown < THRESHOLD) { logger.error(“error reading data", e); exceptionsThrown++; } else { // Now the error won’t choke the system. } } } }
还有一个方法就是把日志操作从循环中去掉,在另外的地方进行打印,只记录第一个或者最后一个异常就好了。

未捕获的异常

维斯特洛有一道最后的防御墙,而你有Thread.uncaughtExceptionHandler。请确认你已经用上它们了。如果没有的话,你的异常可能这么没了,而你只能拿到很少的一些上下文信息,同时这些异常在哪打印,是否打印,你也不好控制。

如果你的代码出现异常却没有记录下来,或者记录下来了却没有相关的状态信息,那真是非常失败。

尽管在uncaughtExceptionHandler里面看似已经访问不了线程里面的任何变量了(它已经挂了),但你至少还有一个当前线程的引用。如果结合刚才提到的第一条建议的话,至少日志中还能打印出一个有意义的thread.getName()的值。

捕获外部调用的异常

只要你调用到了JVM以外的接口,那么发生异常的概率就大大提升了。这包括WEB服务,HTTP,数据库,文件系统,操作系统或者其它的一些JNI调用。你得把每一个调用都当成一个定时炸弹来处理。

大多数情况下,外部调用之所以会失败是因为传入了错误的参数。为了修复这些问题,把这些请求参数记录到日志中是非常有必要的。

你可能不想记录错误信息,而是直接去抛出异常,这样做也没有问题。不过这么做的话,你要尽可能把相关的参数都收集起来,放到异常信息里面去。

你得确保在上一层调用中捕获了异常并且记录到了日志里。
try { return s3client.generatePresignedUrl(request); } catch (Exception e) { String err = String.format(“Error generating request: %s bucket: %s key: %s. method: %s", request, bucket, path, method); log.error(err, e); //这里你也可以抛出一个异常,记得把ERR信息带上。 }

原文地址:http://it.deepinmind.com/java/2014/05/03/5-techniques-2-improve-your-server-logging.html

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

推荐阅读更多精彩内容

  • 1. Java基础部分 基础部分的顺序:基本语法,类相关的语法,内部类的语法,继承相关的语法,异常的语法,线程的语...
    子非鱼_t_阅读 31,560评论 18 399
  • error code(错误代码)=0是操作成功完成。error code(错误代码)=1是功能错误。error c...
    Heikki_阅读 3,352评论 1 9
  • Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具(例如配置管理,服务发现,断路器,智...
    卡卡罗2017阅读 134,580评论 18 139
  • 来源与:阿里云栖 禁止用于商业用途 ps:如果需要电子书 评论你们邮箱 我会发给你们 下面感觉还是有点乱 目录 一...
    小向资源网阅读 7,570评论 0 12
  • 爱你,就爱所有的你。 爱温柔如春雨绵绵的你, 爱朝气如夏日阳光的你, 爱感性如秋叶飘零的你, 爱坚持如冬日傲梅的你...
    书情惬意阅读 398评论 0 0