程序中log打印的梳理

程序中记录日志一般有两个目的：Troubleshooting和显示程序运行状态。好的日志记录方式可以提供我们足够多定位问题的依据。 

这周看过很多代码，对里面的日志记录方式有些想法，今天是周末，也想总结下我对这个问题的看法。日志记录大家都会认为简单，但如何通过日志可以高效定位问题可不是简单的事情。这里我会写下面三个方面的内容，主要是举例为主，提醒我以后得注意这些方面 

• 怎样记日志可以方便Troubleshooting
• 程序运行状态可以记哪些
• 应该避免怎样的日志方式

方便Troubleshooting的日志： 

对外部的调用封装：  
程序中对外部系统与模块的依赖调用前后都记下日志，方便接口调试。出问题时也可以很快理清是哪块的问题  

Java代码

1. LOG.debug("Calling external system:" + parameters);  
2. Object result = null;  
3. try {  
4.     result = callRemoteSystem(params);  
5.     LOG.debug("Called successfully. result is " + result);  
6. } catch (Exception e) {  
7.     LOG.warn("Failed at calling xxx system . exception : " + e);  
8. }  

状态变化： 
程序中重要的状态信息的变化应该记录下来，方便查问题时还原现场，推断程序运行过程  

Java代码

1. boolean isRunning;  
2.   
3. isRunning = true;  
4. LOG.info("System is running");  
5.   
6. //...  
7.   
8. isRunning = false;  
9. LOG.info("System was interrupted by " + Thread.currentThread().getName());  

系统入口与出口： 
这个粒度可以是重要方法级或模块级。记录它的输入与输出，方便定位  

Java代码

1. void execute(Object input) {  
2.     LOG.debug("Invoke parames : " + input);  
3.     Object result = null;  
4.       
5.     //business logical  
6.       
7.     LOG.debug("Method result : " + result);  
8. }  

业务异常： 
任何业务异常都应该记下来  

Java代码

1. try {  
2.     //business logical  
3. } catch (IOException e) {  
4.     LOG.warn("Description xxx" , e);  
5. } catch (BusinessException e) {  
6.     LOG.warn("Let me know anything");  
7. } catch (Exception e) {  
8.     LOG.error("Description xxx", e);  
9. }  
10.   
11. void invoke(Object primaryParam) {  
12.     if (primaryParam == null) {  
13.         LOG.warn("Why this primary param is null?");  
14.         return;  
15.     }  
16. }  

非预期执行： 
为程序在“有可能”执行到的地方打印日志。如果我想删除一个文件，结果返回成功。但事实上，那个文件在你想删除之前就不存在了。最终结果是一致的，但程序得让我们知道这种情况，要查清为什么文件在删除之前就已经不存在呢  

Java代码

1. int myValue = xxxx;  
2. int absResult = Math.abs(myValue);  
3. if (absResult < 0) {  
4.     LOG.info("Original int " + myValue + "has nagetive abs " + absResult);  
5. }  

很少出现的else情况： 
else可能吞掉你的请求，或是赋予难以理解的最终结果  

Java代码 

1. Object result = null;  
2. if (running) {  
3.    result = xxx;  
4. } else {  
5.    result = yyy;  
6.    LOG.debug("System does not running, we change the final result");  
7. }  

程序运行状态 
程序在运行时就像一个机器人，我们可以从它的日志看出它正在做什么，是不是按预期的设计在做，所以这些正常的运行状态是要有的。 

程序运行时间：  

Java代码

1. long startTime = System.currentTime();  
2.   
3. // business logical  
4.   
5. LOG.info("execution cost : " + (System.currentTime() - startTime) + "ms");　  

大批量数据的执行进度 ： 

Java代码

1. LOG.debug("current progress: " + (currentPos * 100 / totalAmount) + "%");  

关键变量及正在做哪些重要的事情： 
执行关键的逻辑，做IO操作等等  

Java代码

1. String getJVMPid() {  
2.    String pid = "";  
3.    // Obtains JVM process ID  
4.    LOG.info("JVM pid is " + pid);  
5.    return pid;  
6. }  
7.   
8. void invokeRemoteMethod(Object params) {  
9.     LOG.info("Calling remote method : " + params);  
10.     //Calling remote server  
11. }  

避免的日志方式 

无意义的Log： 
日志不包含有意义的信息: 你肯定想知道的是哪个文件不存在吧  

Java代码

1. File file = new File("xxx");  
2. if (!file.isExist()) {  
3.     LOG.warn("File does not exist"); //Useless message  
4. }  

混淆信息的Log： 
日志应该是清晰准确的: 当看到日志的时候，你知道是因为连接池取不到连接导致的问题么？  

Java代码

1. Connection connection = ConnectionFactory.getConnection();  
2. if (connection == null) {  
3.     LOG.warn("System initialized unsuccessfully");  
4. }