View Javadoc
1   /**
2    * Logback: the reliable, generic, fast and flexible logging framework.
3    * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
4    *
5    * This program and the accompanying materials are dual-licensed under
6    * either the terms of the Eclipse Public License v1.0 as published by
7    * the Eclipse Foundation
8    *
9    *   or (per the licensee's choosing)
10   *
11   * under the terms of the GNU Lesser General Public License version 2.1
12   * as published by the Free Software Foundation.
13   */
14  package ch.qos.logback.classic.pattern;
15  
16  import java.util.LinkedHashMap;
17  import java.util.Map;
18  
19  import ch.qos.logback.classic.spi.ILoggingEvent;
20  import ch.qos.logback.core.util.OptionHelper;
21  
22  /**
23   * In case abbreviation service is requested, NamedConverter will convert fully
24   * qualified class names to their abbreviated from. NamedConverter instances
25   * will store abbreviated names in an internal LRU cache.
26   * 
27   * The cache will double in size if he cache miss rate is consistently above
28   * 30%. Assuming a high miss rate, the doubling until a maximum size of 2048 is
29   * attained. If at this point the cache miss rate is still too high,
30   * NamedConverter will revert to non cached behavior.
31   * 
32   * The general assumption here is that a large majority of logger names are
33   * concentrated within a group of approximately 1000 logger names.
34   * 
35   * @author Ceki Gulcu
36   *
37   */
38  public abstract class NamedConverter extends ClassicConverter {
39  
40      private static final String DISABLE_CACHE_SYSTEM_PROPERTY = "logback.namedConverter.disableCache";
41  
42      private static final int INITIAL_CACHE_SIZE = 512;
43      private static final double LOAD_FACTOR = 0.75; // this is the JDK implementation default
44  
45      /**
46       * We don't let the cache map size to go over MAX_ALLOWED_REMOVAL_THRESHOLD
47       * elements
48       */
49      private static final int MAX_ALLOWED_REMOVAL_THRESHOLD = (int) (2048 * LOAD_FACTOR);
50  
51      /**
52       * When the cache miss rate is above 30%, the cache is deemed inefficient.
53       */
54      private static final double CACHE_MISSRATE_TRIGGER = 0.3d;
55  
56      /**
57       * We should have a sample size of minimal length before computing the cache
58       * miss rate.
59       */
60      private static final int MIN_SAMPLE_SIZE = 1024;
61  
62      private static final double NEGATIVE = -1;
63      private volatile boolean cacheEnabled = true;
64  
65      private final NameCache cache = new NameCache(INITIAL_CACHE_SIZE);
66  
67      private Abbreviator abbreviator = null;
68  
69      private volatile int cacheMisses = 0;
70      private volatile int totalCalls = 0;
71  
72      /**
73       * Gets fully qualified name from event.
74       * 
75       * @param event The LoggingEvent to process, cannot not be null.
76       * @return name, must not be null.
77       */
78      protected abstract String getFullyQualifiedName(final ILoggingEvent event);
79  
80      public void start() {
81  
82          String disableCacheProp = OptionHelper.getSystemProperty(DISABLE_CACHE_SYSTEM_PROPERTY);
83          boolean disableCache = OptionHelper.toBoolean(disableCacheProp, false);
84          if (disableCache) {
85              addInfo("Disabling name cache via System.properties");
86              this.cacheEnabled = false;
87          }
88  
89          String optStr = getFirstOption();
90          if (optStr != null) {
91              try {
92                  int targetLen = Integer.parseInt(optStr);
93                  if (targetLen == 0) {
94                      abbreviator = new ClassNameOnlyAbbreviator();
95                  } else if (targetLen > 0) {
96                      abbreviator = new TargetLengthBasedClassNameAbbreviator(targetLen);
97                  }
98              } catch (NumberFormatException nfe) {
99                  addError("failed to parse integer string [" + optStr + "]", nfe);
100             }
101         }
102         super.start();
103     }
104 
105     public String convert(ILoggingEvent event) {
106         String fqn = getFullyQualifiedName(event);
107 
108         if (abbreviator == null) {
109             return fqn;
110         } else {
111             if (cacheEnabled) {
112                 return viaCache(fqn);
113             } else {
114                 return abbreviator.abbreviate(fqn);
115             }
116         }
117     }
118 
119     /**
120      * This method is synchronized. It is the only place where the cache, a subclass
121      * of LinkedHashMap, is modified.
122      * 
123      * The cache can be cleared via a call to disableCache(). However, the call to
124      * disableCache() is made indirectly from within viaCache(String).
125      * 
126      * @param fqn
127      * @return
128      */
129     private synchronized String viaCache(String fqn) {
130         totalCalls++;
131         String abbreviated = cache.get(fqn);
132         if (abbreviated == null) {
133             cacheMisses++;
134             abbreviated = abbreviator.abbreviate(fqn);
135             cache.put(fqn, abbreviated);
136         }
137         return abbreviated;
138     }
139 
140     private void disableCache() {
141         if (!cacheEnabled)
142             return;
143         this.cacheEnabled = false;
144         cache.clear();
145         addInfo("Disabling cache at totalCalls=" + totalCalls);
146     }
147 
148     public double getCacheMissRate() {
149         return cache.cacheMissCalculator.getCacheMissRate();
150     }
151 
152     public int getCacheMisses() {
153         return cacheMisses;
154     }
155 
156     private class NameCache extends LinkedHashMap<String, String> {
157 
158         private static final long serialVersionUID = 1050866539278406045L;
159 
160         int removalThreshold;
161         CacheMissCalculator cacheMissCalculator = new CacheMissCalculator();
162 
163         NameCache(int initialCapacity) {
164             super(initialCapacity);
165             this.removalThreshold = (int) (initialCapacity * LOAD_FACTOR);
166         }
167 
168         /**
169          * In the JDK tested, this method is called for every map insertion.
170          * 
171          */
172         @Override
173         protected boolean removeEldestEntry(Map.Entry<String, String> entry) {
174             if (shouldDoubleRemovalThreshold()) {
175                 removalThreshold *= 2;
176 
177                 int missRate = (int) (cacheMissCalculator.getCacheMissRate() * 100);
178 
179                 NamedConverter.this.addInfo("Doubling nameCache removalThreshold to " + removalThreshold
180                         + " previous cacheMissRate=" + missRate + "%");
181                 cacheMissCalculator.updateMilestones();
182             }
183 
184             if (size() >= removalThreshold) {
185                 return true;
186             } else
187                 return false;
188         }
189 
190         private boolean shouldDoubleRemovalThreshold() {
191 
192             double rate = cacheMissCalculator.getCacheMissRate();
193 
194             // negative rate indicates insufficient sample size
195             if (rate < 0)
196                 return false;
197 
198             if (rate < CACHE_MISSRATE_TRIGGER)
199                 return false;
200 
201             // cannot double removalThreshold is already at max allowed size
202             if (this.removalThreshold >= MAX_ALLOWED_REMOVAL_THRESHOLD) {
203                 NamedConverter.this.disableCache();
204                 return false;
205             }
206 
207             return true;
208         }
209     }
210 
211     class CacheMissCalculator {
212 
213         int totalsMilestone = 0;
214         int cacheMissesMilestone = 0;
215 
216         void updateMilestones() {
217             this.totalsMilestone = NamedConverter.this.totalCalls;
218             this.cacheMissesMilestone = NamedConverter.this.cacheMisses;
219         }
220 
221         double getCacheMissRate() {
222 
223             int effectiveTotal = NamedConverter.this.totalCalls - totalsMilestone;
224 
225             if (effectiveTotal < MIN_SAMPLE_SIZE) {
226                 // cache miss rate cannot be negative. With a negative value, we signal the
227                 // caller of insufficient sample size.
228                 return NEGATIVE;
229             }
230 
231             int effectiveCacheMisses = NamedConverter.this.cacheMisses - cacheMissesMilestone;
232             return (1.0d * effectiveCacheMisses / effectiveTotal);
233         }
234     }
235 
236 }