zoukankan      html  css  js  c++  java
  • 日志打印会严重影响到性能

    以前编程不喜欢对每个功能、重要的方法进行日志的格式化输出,即使要输出,也没按照规范进行输出。前段时间,随着我们平

    台用户量不断增加,出现些问题。当用户遇到问题,就给我们客服打电话。然后客服毫无疑问就来找我们。当我们接收到这样问题的时候,

    我们首先要定位是什么原因造成的。当时就是因为自己方法中输出的日志很少,而且不规范,所以根本找不到具体原因,虽然最后问题解

    决了,但是花费很多不必要的时间。

    那么我们怎样使用好日志这一利器呢?

    1.写好日志:

    我们先来看一下糟糕的日志打印:

    [java] view plain copy
     
    1. @ResponseBody  
    2.     @RequestMapping(value = "unbind.do", method = RequestMethod.POST)  
    3.     public Object unbind(String bankId, String memberId) {  
    4.       
    5.         if (StringUtils.isBlank(bankId) || StringUtils.isBlank(memberId)) {  
    6.             return new Result(false, "解绑参数不合法!");  
    7.         }  
    8.         try {  
    9.             authPayTwoService.unbind(bankId, memberId);  
    10.         } catch (AppException e) {  
    11.             LOG.info("认证支付2.0(unbind)失败:{}",e);  
    12.             return new Result(false, e.getMessage());  
    13.         } catch (Exception e) {  
    14.             LOG.info("认证支付2.0(unbind)]失败:{}",  e);  
    15.             return new Result(false, "解绑银行卡失败,请重试");  
    16.         }  
    17.         return new Result(true, "解绑银行卡成功!");  
    18.     }  



    上面代码是严格不符合规范的,每个公司都有自己的打印要求。首先日志的打印必须是以logger.error、logger.warn或logger.info

    的方式打印出来。日志打印格式应包含[系统来源] 错误描述 [关键信息],日志信息要能打印出能看懂的信息,有前因和后果。方法的入参和

    出参也要考虑打印出来。

    好的日志格式打印

    [java] view plain copy
     
    1. @ResponseBody  
    2.     @RequestMapping(value = "unbind.do", method = RequestMethod.POST)  
    3.     public Object unbind(String bankId, String memberId) {  
    4.         LOG.info("[解绑银行卡--认证支付2.0][params:bankId=" + bankId + ",memberId="  
    5.                 + memberId + "]");  
    6.         if (StringUtils.isBlank(bankId) || StringUtils.isBlank(memberId)) {  
    7.             return new Result(false, "解绑参数不合法!");  
    8.         }  
    9.         try {  
    10.             authPayTwoService.unbind(bankId, memberId);  
    11.         } catch (AppException e) {  
    12.             LOG.error("[解绑银行卡--认证支付2.0(unbind)-mas][error:{}",e);  
    13.             return new Result(false, e.getMessage());  
    14.         } catch (Exception e) {  
    15.             LOG.error("[解绑银行卡--认证支付2.0(unbind)][error:{}",e);  
    16.             return new Result(false, "解绑银行卡失败,请重试");  
    17.         }  
    18.         return new Result(true, "解绑银行卡成功!");  
    19.     }  


    从上面的代码可以很轻松的定位方法、传入的参数及异常是调用接口抛出的异常还是系统级的异常。

    2.良好的日志输出格式

    最近测试同事采用两百并发对项目进行测试。

    格式优化前:

    经过测试查看每秒的并发量平均只有110多如下图:

    通过查看jvm 虚拟机发现很多日志线程出现BLOCKED,如下:

    [java] view plain copy
     
    1. "http-saoma%2F192.168.6.162-8097-132" daemon prio=10 tid=0x00002aaab88e4800 nid=0x2c8e runnable [0x0000000045274000]  
    2.    java.lang.Thread.State: BLOCKED  
    3.     at java.lang.Throwable.getStackTraceElement(Native Method)  
    4.     at java.lang.Throwable.getOurStackTrace(Throwable.java:591)  
    5.     - locked <0x00000007691390d0> (a java.lang.Throwable)  
    6.     at java.lang.Throwable.getStackTrace(Throwable.java:582)  
    7.     at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)  
    8.     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)  
    9.     at java.lang.reflect.Method.invoke(Method.java:597)  
    10.     at org.apache.log4j.spi.LocationInfo.<init>(LocationInfo.java:139)  
    11.     at org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:253)  
    12.     at org.apache.log4j.helpers.PatternParser$LocationPatternConverter.convert(PatternParser.java:500)  
    13.     at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:65)  
    14.     at org.apache.log4j.PatternLayout.format(PatternLayout.java:506)  
    15.     at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)  
    16.     at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileAppender.java:369)  
    17.     at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)  
    18.     at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)  
    19.     - locked <0x0000000780fb1e00> (a org.apache.log4j.DailyRollingFileAppender)  
    20.     at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)  
    21.     at org.apache.log4j.Category.callAppenders(Category.java:206)  
    22.     - locked <0x00000007800020a0> (a org.apache.log4j.spi.RootLogger)  
    23.     at org.apache.log4j.Category.forcedLog(Category.java:391)  
    24.     at org.apache.log4j.Category.log(Category.java:856)  
    25.     at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:497)  


    我们定位org.apache.log4j.spi.LocationInfo类的代码如下:

    [java] view plain copy
     
    1. String s;  
    2.      // Protect against multiple access to sw.  
    3.      synchronized(sw) {  
    4. t.printStackTrace(pw);  
    5. s = sw.toString();  
    6. sw.getBuffer().setLength(0);  
    7.      }  
    8.      //System.out.println("s is ["+s+"].");  
    9.      int ibegin, iend;  
    10.   
    11.      // Given the current structure of the package, the line  
    12.      // containing "org.apache.log4j.Category." should be printed just  
    13.      // before the caller.  
    14.   
    15.      // This method of searching may not be fastest but it's safer  
    16.      // than counting the stack depth which is not guaranteed to be  
    17.      // constant across JVM implementations.  
    18.      ibegin = s.lastIndexOf(fqnOfCallingClass);  



    从上面可以看出在该方法中用了synchronized锁,然后又通过打印堆栈来获取行号。那么肯定会影响到性能的,我们通过看


    此时log4j.properties日志文件配置的输出格式为:


     %d %-5p %c:%L [%t] - %m%n

     

    很明显就是%l输出行号的问题,那么我们把%l去掉结果会不会好很多呢?

    把log4j.properties文件中输出格式改为:

     %d %-5p %c [%t] - %m%n

    输出格式优化后:

     再看每秒的并发量如下图:

    从图中我们可以看出并发量提高了40多,同时jvm线程日志中java.lang.Thread.State: BLOCKED也没有了。看来程序的性能和日志的输

  • 相关阅读:
    Windows Azure Cloud Service (14) 使用Windows Azure诊断收集日志记录数据
    Windows Azure Cloud Service (13) 用Visual Studio 2010 将应用程序部署到Windows Azure平台
    Windows Azure Cloud Service (15) 多个VM Instance场景下如何处理ASP.NET Session
    Windows Azure Storage (5) Windows Azure Drive
    Windows Azure Storage (7) 使用工具管理Windows Azure Storage
    SQL Azure(二) SQL Azure vs SQL Server
    webbrowser的自动提交
    提取视频的背景声音的软件
    Listview列排序的bug原因
    两个奇怪的问题
  • 原文地址:https://www.cnblogs.com/jtlgb/p/8301883.html
Copyright © 2011-2022 走看看