[GitHub] [hadoop] ZanderXu commented on pull request #4529: HDFS-16648. Add isDebugEnabled check for debug logs in some classes

[GitBox]

ZanderXu commented on PR #4529:
URL: https://github.com/apache/hadoop/pull/4529#issuecomment-1175795921

   > What are we saving by doing this?
   In [PR-4480](https://github.com/apache/hadoop/pull/4480#event-6923776715), I 
do a performance stress test about it. And found that adding isDebugEnabled 
before strings concatenation is helpful for performance.
   Please refer to the stress test code and results. 
   Test code:
   ```
       org.slf4j.Logger LOG = LoggerFactory.getLogger("Test");
       Block b = new Block();
       DatanodeInfo dn = new DatanodeInfo(EMPTY_DATANODE_ID);
       List<DatanodeInfo> staleNodes = new ArrayList<>();
       staleNodes.add(dn);
       long beginTime1 = Time.monotonicNowNanos();
       for (int i = 0; i < 100000000; i++) {
         LOG.debug("BLOCK* invalidateBlocks: postponing " +
                 "invalidation of {} on {} because {} replica(s) are located on 
" +
                 "nodes with potentially out-of-date block reports",
             b, dn, staleNodes);
       }
       long endTime1 = Time.monotonicNowNanos();
       LOG.info("Time1: {}", endTime1 - beginTime1);
   
       long beginTime2 = Time.monotonicNowNanos();
       for (int i = 0; i < 100000000; i++) {
         if (LOG.isDebugEnabled()) {
           LOG.debug("BLOCK* invalidateBlocks: postponing " +
                   "invalidation of {} on {} because {} replica(s) are located 
on " +
                   "nodes with potentially out-of-date block reports",
               b, dn, staleNodes);
         }
       }
       long endTime2 = Time.monotonicNowNanos();
       LOG.info("Time2: {}", endTime2 - beginTime2);
   
       long beginTime3 = Time.monotonicNowNanos();
       for (int i = 0; i < 100000000; i++) {
         LOG.debug("BLOCK* invalidateBlocks: postponing invalidation of {}", b);
       }
       long endTime3 = Time.monotonicNowNanos();
       LOG.info("Time3: {}", endTime3 - beginTime3);
   ```
    And the result is:
   | - | Time1(ns) | Time2(ns) | Time3(ns) |
   | :-----| ----: | :----: | :----: |
   | First Run | 353681417 | 287066916 | 270287253 |
   | Second Run | 356797081 | 308013207 | 266873810 |
   | Third Run | 366995010 | 287111940 | 259907404 |
   | Avg | 359157836 | 294064021 | 265689489 |
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: common-issues-unsubscr...@hadoop.apache.org

For queries about this service, please contact Infrastructure at:
us...@infra.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: common-issues-unsubscr...@hadoop.apache.org
For additional commands, e-mail: common-issues-h...@hadoop.apache.org