Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-1039

performance improvement for logging exception

    XMLWordPrintable

Details

    • Icon: Improvement Improvement
    • Resolution: Unresolved
    • Icon: Major Major
    • None
    • 1.1.2
    • logback-classic
    • None
    • test

    Description

      I have tested the performance by below code and found the method computeBySTEP in class PackagingDataCalculator spent a lot of time.

      public class LogbackTest extends TestCase {
          private static final Logger logger = LoggerFactory.getLogger(LogbackTest.class);
      
          @Test
          public void test() {
              Profiler.run(new Runnable() {
      
                  @Override
                  public void run() {
                      logger.error("aaa", new RuntimeException("error"));
                  }
      
              }, 3, 10000, 3).printResult();
          }
      }
      
      

      and here is result:

      ========================================================================================================================
      (unit: milliseconds)
      threadNum=3; loops=10000
      startTime: 2014-12-30 09:34:18.192
      endTime: 2014-12-30 09:34:24.866
      totalSpendedTime: 6674

      maxMethodTime(run): 79
      minMethodTime(run): 0

      <method name>, <avg time>, <min time>, <max time>, <0.01% >=>, <0.1% >=>, <1% >=>, <10% >=>, <20% >=>, <50% >=>, <80% >=>, <90% >=>, <99% >=>, <99.9% >=>, <99.99% >=>
      run, 0.6434, 0, 79, 62, 16, 16, 0, 0, 0, 0, 0, 0, 0, 0,

      ========================================================================================================================

      by modifying the line in class PackagingDataCalculator:
      change:

      HashMap<String, ClassPackagingData> cache = new HashMap<String, ClassPackagingData>();
      

      to:

      static final HashMap<String, ClassPackagingData> cache = new HashMap<String, ClassPackagingData>();
      

      The performance is improved more than 10 times by the result:
      ========================================================================================================================
      (unit: milliseconds)
      threadNum=3; loops=10000
      startTime: 2014-12-30 09:33:53.003
      endTime: 2014-12-30 09:33:53.41
      totalSpendedTime: 407

      maxMethodTime(run): 31
      minMethodTime(run): 0

      <method name>, <avg time>, <min time>, <max time>, <0.01% >=>, <0.1% >=>, <1% >=>, <10% >=>, <20% >=>, <50% >=>, <80% >=>, <90% >=>, <99% >=>, <99.9% >=>, <99.99% >=>
      run, 0.0344, 0, 31, 16, 16, 0, 0, 0, 0, 0, 0, 0, 0, 0,

      ========================================================================================================================

      Attachments

        Activity

          People

            logback-dev Logback dev list
            haiyang haiyang li
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: