001/** 002 * Logback: the reliable, generic, fast and flexible logging framework. 003 * Copyright (C) 1999-2015, QOS.ch. All rights reserved. 004 * 005 * This program and the accompanying materials are dual-licensed under 006 * either the terms of the Eclipse Public License v1.0 as published by 007 * the Eclipse Foundation 008 * 009 * or (per the licensee's choosing) 010 * 011 * under the terms of the GNU Lesser General Public License version 2.1 012 * as published by the Free Software Foundation. 013 */ 014package ch.qos.logback.classic.pattern; 015 016import java.util.LinkedHashMap; 017import java.util.Map; 018 019import ch.qos.logback.classic.spi.ILoggingEvent; 020import ch.qos.logback.core.util.OptionHelper; 021 022/** 023 * In case abbreviation service is requested, NamedConverter will convert fully 024 * qualified class names to their abbreviated from. NamedConverter instances 025 * will store abbreviated names in an internal LRU cache. 026 * 027 * The cache will double in size if he cache miss rate is consistently above 028 * 30%. Assuming a high miss rate, the doubling until a maximum size of 2048 is 029 * attained. If at this point the cache miss rate is still too high, 030 * NamedConverter will revert to non cached behavior. 031 * 032 * The general assumption here is that a large majority of logger names are 033 * concentrated within a group of approximately 1000 logger names. 034 * 035 * @author Ceki Gulcu 036 * 037 */ 038public abstract class NamedConverter extends ClassicConverter { 039 040 private static final String DISABLE_CACHE_SYSTEM_PROPERTY = "logback.namedConverter.disableCache"; 041 042 private static final int INITIAL_CACHE_SIZE = 512; 043 private static final double LOAD_FACTOR = 0.75; // this is the JDK implementation default 044 045 /** 046 * We don't let the cache map size to go over MAX_ALLOWED_REMOVAL_THRESHOLD 047 * elements 048 */ 049 private static final int MAX_ALLOWED_REMOVAL_THRESHOLD = (int) (2048 * LOAD_FACTOR); 050 051 /** 052 * When the cache miss rate is above 30%, the cache is deemed inefficient. 053 */ 054 private static final double CACHE_MISSRATE_TRIGGER = 0.3d; 055 056 /** 057 * We should have a sample size of minimal length before computing the cache 058 * miss rate. 059 */ 060 private static final int MIN_SAMPLE_SIZE = 1024; 061 062 private static final double NEGATIVE = -1; 063 private volatile boolean cacheEnabled = true; 064 065 private final NameCache cache = new NameCache(INITIAL_CACHE_SIZE); 066 067 private Abbreviator abbreviator = null; 068 069 private volatile int cacheMisses = 0; 070 private volatile int totalCalls = 0; 071 072 /** 073 * Gets fully qualified name from event. 074 * 075 * @param event The LoggingEvent to process, cannot not be null. 076 * @return name, must not be null. 077 */ 078 protected abstract String getFullyQualifiedName(final ILoggingEvent event); 079 080 public void start() { 081 082 String disableCacheProp = OptionHelper.getSystemProperty(DISABLE_CACHE_SYSTEM_PROPERTY); 083 boolean disableCache = OptionHelper.toBoolean(disableCacheProp, false); 084 if (disableCache) { 085 addInfo("Disabling name cache via System.properties"); 086 this.cacheEnabled = false; 087 } 088 089 String optStr = getFirstOption(); 090 if (optStr != null) { 091 try { 092 int targetLen = Integer.parseInt(optStr); 093 if (targetLen == 0) { 094 abbreviator = new ClassNameOnlyAbbreviator(); 095 } else if (targetLen > 0) { 096 abbreviator = new TargetLengthBasedClassNameAbbreviator(targetLen); 097 } 098 } catch (NumberFormatException nfe) { 099 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}