Uploaded image for project: 'Accumulo'
  1. Accumulo
  2. ACCUMULO-4036

remove verbose block cache eviction logging

    Details

    • Type: Improvement
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 1.7.0
    • Fix Version/s: 1.6.5, 1.7.1, 1.8.0
    • Component/s: core
    • Labels:
      None

      Description

      For many scans and queries we get logs like the following at pretty extreme frequencies:

      2015-10-20 17:33:50,458 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578760 bytes
      2015-10-20 17:33:50,458 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643840 bytes.  Priority Sizes: Single=7.152191MB (7499616), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,465 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578576 bytes
      2015-10-20 17:33:50,465 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643584 bytes.  Priority Sizes: Single=7.249962MB (7602136), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,470 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578616 bytes
      2015-10-20 17:33:50,470 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643872 bytes.  Priority Sizes: Single=7.2499924MB (7602168), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,477 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578344 bytes
      2015-10-20 17:33:50,477 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643808 bytes.  Priority Sizes: Single=7.1517944MB (7499200), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,483 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578408 bytes
      2015-10-20 17:33:50,483 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643648 bytes.  Priority Sizes: Single=7.1518555MB (7499264), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,488 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578408 bytes
      2015-10-20 17:33:50,488 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643672 bytes.  Priority Sizes: Single=7.1518555MB (7499264), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,494 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578560 bytes
      2015-10-20 17:33:50,494 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643472 bytes.  Priority Sizes: Single=7.1520004MB (7499416), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      2015-10-20 17:33:50,500 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction started.  Attempting to free 1578872 bytes
      2015-10-20 17:33:50,500 [cache.LruBlockCache] [LruBlockCache.EvictionThread] DEBUG: Block cache LRU eviction completed. Freed 1643840 bytes.  Priority Sizes: Single=7.152298MB (7499728), Multi=5.60128MB (5873368),Memory=0.0MB (0)
      

      In this case, it's a message every few milliseconds. Does anybody need these log messages? If so, could/should they be rolled up into stats other than our cache hit stats?

        Activity

        Hide
        elserj Josh Elser added a comment -

        +1

        If we can have some meaningful metrics (at INFO) that'd be great, but I don't see much benefit at DEBUG for the above.

        Show
        elserj Josh Elser added a comment - +1 If we can have some meaningful metrics (at INFO) that'd be great, but I don't see much benefit at DEBUG for the above.
        Hide
        elserj Josh Elser added a comment -

        Fixed by demoting the debug messages to trace. Switched some commons-logging to slf4j on the older branches.

        Show
        elserj Josh Elser added a comment - Fixed by demoting the debug messages to trace. Switched some commons-logging to slf4j on the older branches.

          People

          • Assignee:
            elserj Josh Elser
            Reporter:
            afuchs Adam Fuchs
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Time Tracking

              Estimated:
              Original Estimate - Not Specified
              Not Specified
              Remaining:
              Remaining Estimate - 0h
              0h
              Logged:
              Time Spent - 20m
              20m

                Development