001 /*
002 * Created by IntelliJ IDEA.
003 * User: d@hd.org
004 * Date: 15-May-02
005 * Time: 07:53:03
006
007 Copyright (c) 1996-2012, Damon Hart-Davis
008 All rights reserved.
009
010 Redistribution and use in source and binary forms, with or without
011 modification, are permitted provided that the following conditions are
012 met:
013
014 * Redistributions of source code must retain the above copyright
015 notice, this list of conditions and the following disclaimer.
016
017 * Redistributions in binary form must reproduce the above copyright
018 notice, this list of conditions and the following disclaimer in the
019 documentation and/or other materials provided with the
020 distribution.
021
022 THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS
023 IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED
024 TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A
025 PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
026 OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
027 SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
028 LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
029 DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
030 THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
031 (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
032 OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
033
034 */
035 package org.hd.d.pg2k.svrCore.stats;
036
037 import java.io.PrintStream;
038 import java.util.ArrayList;
039 import java.util.Collections;
040 import java.util.List;
041 import java.util.Map;
042 import java.util.Set;
043 import java.util.WeakHashMap;
044 import java.util.concurrent.ConcurrentHashMap;
045 import java.util.concurrent.ConcurrentMap;
046 import java.util.concurrent.atomic.AtomicLong;
047
048 import org.hd.d.pg2k.svrCore.AbstractSimpleLogger;
049 import org.hd.d.pg2k.svrCore.SimpleLoggerIF;
050 import org.hd.d.pg2k.svrCore.Tuple;
051
052 /**Stats-gathering interface.
053 * This is not designed for especially sensitive information.
054 * <p>
055 * The StatsLogger class is not instantiated.
056 * <p>
057 * The simplest interface requires the caller to hand a config object
058 * in on every call to specify how to handle the stats.
059 * <p>
060 * On each stats-event call, the current event may be dumped immediately
061 * and/or, if a stats summary is (over)due then it may be done now.
062 */
063 public final class StatsLogger
064 {
065 /**No one may instantiate this class. */
066 private StatsLogger() { }
067
068 /**Map from StatsConfig item to collected stats.
069 * The data store outer map is a WeakHashMap
070 * so that if no one has a strong reference
071 * to a given StatsConfig key object then any stats data keyed from
072 * it will be automatically discarded.
073 * <p>
074 * This is held statically and all access to it should be
075 * performed within a lock on the map object if multiple accesses
076 * must be performed atomically.
077 * <p>
078 * This table is a synchronized WeakHashMap from StatsConfig to
079 * a thread-safe map from some Object key to a thread-safe counter.
080 * <p>
081 * We don't perform non-essential operations on the per-set Map
082 * inside the dataStore lock so as to maximise concurrency.
083 * <p>
084 * Note that entries in a WeakHashMap can disappear even while
085 * a lock is held on the map.
086 */
087 private static final Map<StatsConfig,ConcurrentMap<String,AtomicLong>> dataStore =
088 Collections.synchronizedMap(new WeakHashMap<StatsConfig, ConcurrentMap<String,AtomicLong>>());
089
090 /**Holds the configuration for one statistics set.
091 * As this object uses == for equals() [from Object],
092 * it is impossible to forge duplicates for any one stats source.
093 * <p>
094 * While immutable from outside the stats system,
095 * this does note when the last stats summary was done.
096 */
097 public static final class StatsConfig
098 {
099 /**Time at which this stats set was created. */
100 public final long creationTime = System.currentTimeMillis();
101
102 /**Name/token to identify this stats set; never null or zero length. */
103 public final String name;
104
105 /**Logger to log to; null if none. */
106 private final SimpleLoggerIF logger;
107
108 /**If true we log every event, else only summary status. */
109 private final boolean printEveryEvent;
110
111 /**Interval in seconds between dumps of stats info; non-negative.
112 * If zero then periodic dumps are disabled.
113 */
114 private final int dumpIntervalS;
115
116 /**If true, we dump at shorter intervals to start with.
117 * This helps yield useful info when the system is starting up;
118 * until the first true dump interval has been reached
119 * we dump at exponentially-increasing intervals
120 * (driven by actual arrival of events).
121 */
122 private final boolean adaptiveTime;
123
124 /**Time at which last summary dump was done.
125 * Initially zero to indicate no previous dump.
126 * <p>
127 * Atomically read and/or updated by timeForSummary().
128 */
129 private long lastSummaryDumpTime;
130
131 /**If stats summary dump is overdue, returns true and updates time.
132 * This applies the adaptive algorithm if appropriate.
133 */
134 private synchronized boolean timeForSummary()
135 {
136 // If summary dumps are disabled
137 // then return false immediately.
138 if(dumpIntervalS == 0) { return(false); }
139
140 final long now = System.currentTimeMillis();
141 final long sinceLastDump = (now - lastSummaryDumpTime);
142
143 // If adaptive dump-interval algorithm is on,
144 // and this stats collector is still new,
145 // then allow a dump depending on previous dump time...
146 if(adaptiveTime)
147 {
148 final long timeSinceStart = now - creationTime;
149 // Regard stats collection as "new"
150 // if it has not yet reached its "normal" dump time.
151 if(timeSinceStart < (dumpIntervalS*1000L))
152 {
153 // Allow dump if more than half life of this collection
154 // since the last one.
155 if(sinceLastDump > timeSinceStart / 2)
156 {
157 lastSummaryDumpTime = now;
158 return(true);
159 }
160 }
161 }
162
163 // If long enough since last summary,
164 // update time and return true.
165 if(sinceLastDump >= dumpIntervalS * 1000L)
166 {
167 lastSummaryDumpTime = now;
168 return(true);
169 }
170
171 // Not yet time for a new summary dump.
172 return(false);
173 }
174
175 /**Create a new stats sink description.
176 * Uses an adaptive algorithm so as to dump stats more frequently
177 * when a new stat sink has been created.
178 *
179 * @param setName non-null token printed to identify this set
180 * @param ps if non-null, and while not closed, is a stream to
181 * print statistics information to
182 * @param printEvery if true, every event is printed, else
183 * only summary stats are recorded
184 * @param dumpS if positive, dump cumulative stats at intervals
185 * of this many seconds; if zero periodic dumps are disabled
186 */
187 public StatsConfig(final String setName,
188 final PrintStream ps,
189 final boolean printEvery,
190 final int dumpS)
191 { this(setName, ps, printEvery, dumpS, true); }
192
193 /**Create a new stats sink description.
194 * @param setName non-null token printed to identify this set
195 * @param ps if non-null, and while not closed, is a stream to
196 * print statistics information to
197 * @param printEvery if true, every event is printed, else
198 * only summary stats are recorded
199 * @param dumpS if positive, dump cumulative stats at intervals
200 * of this many seconds; if zero periodic dumps are disabled
201 * @param adaptive if true, print initial summaries at shorter
202 * delays so that even short runs of the system yield
203 * some interesting stats
204 */
205 public StatsConfig(final String setName,
206 final PrintStream ps,
207 final boolean printEvery,
208 final int dumpS,
209 final boolean adaptive)
210 {
211 this(setName,
212 (ps == null) ? null : (new AbstractSimpleLogger() { public void log(final String message) { ps.println(message); } }),
213 printEvery,
214 dumpS,
215 adaptive);
216 }
217
218 /**Create a new stats sink description.
219 * @param setName non-null token printed to identify this set
220 * @param logger if non-null, is a logger to
221 * log statistics information to
222 * @param printEvery if true, every event is printed, else
223 * only summary stats are recorded
224 * @param dumpS if positive, dump cumulative stats at intervals
225 * of this many seconds; if zero periodic dumps are disabled
226 * @param adaptive if true, print initial summaries at shorter
227 * delays so that even short runs of the system yield
228 * some interesting stats
229 */
230 public StatsConfig(final String setName,
231 final SimpleLoggerIF logger,
232 final boolean printEvery,
233 final int dumpS,
234 final boolean adaptive)
235 {
236 if((setName == null) || (setName.length() == 0) ||
237 (dumpS < 0))
238 { throw new IllegalArgumentException(); }
239 name = setName;
240 this.logger = logger;
241 printEveryEvent = printEvery;
242 dumpIntervalS = dumpS;
243 adaptiveTime = adaptive;
244 }
245 }
246
247 /**Capture a data point.
248 * Notes, in the statistics set uniquely identified by statsSet,
249 * an occurrence of the event named by ev.
250 * <p>
251 * Neither statsSet nor ev may be null.
252 * <p>
253 * Essentially, instances of ev are counted (in a long counter).
254 * <p>
255 * This tries to be moderately efficient and quick, at least on average,
256 * but may trigger/drive processing such as printing of the event.
257 */
258 public static void captureDataPoint(final StatsConfig statsSet,
259 final String ev)
260 {
261 if((statsSet == null) || (ev == null))
262 { throw new IllegalArgumentException(); }
263
264 // Atomically get this stats set,
265 // creating it if necessary.
266 ConcurrentMap<String,AtomicLong> h;
267 synchronized(dataStore)
268 {
269 // If there is no entry for statsSet then make one.
270 while((h = dataStore.get(statsSet)) == null)
271 { dataStore.put(statsSet, new ConcurrentHashMap<String, AtomicLong>()); }
272 }
273
274 // Get and increment the counter (etc), or create it if necessary.
275 AtomicLong item;
276 while((item = h.get(ev)) == null) { h.putIfAbsent(ev, new AtomicLong()); }
277 item.incrementAndGet();
278
279 // If we are to log every event
280 // then we do so now.
281 final long now = System.currentTimeMillis();
282 final long delta = now - statsSet.creationTime;
283 if(statsSet.printEveryEvent)
284 { printStats(false, statsSet, ev, item, delta); }
285
286 // Check if we are due for a summary dump,
287 // and do one if needed.
288 //
289 // Sort by count (largest last for easiest reading from log files),
290 // then by key value for ties on count.
291 if(statsSet.timeForSummary())
292 {
293 dumpSummary(statsSet);
294 }
295 }
296
297 /**Dump summary of specified stats to configured log. */
298 public static void dumpSummary(final StatsConfig statsSet)
299 {
300 // Get event records for given set; return if none so far.
301 final ConcurrentMap<String, AtomicLong> h = dataStore.get(statsSet);
302 if(null == h) { return; }
303
304 final long now = System.currentTimeMillis();
305 final long delta = now - statsSet.creationTime;
306
307 final Set<String> keySet = h.keySet();
308 final List<Tuple.ComparablePair<Long, String>> values = new ArrayList<Tuple.ComparablePair<Long, String>>(keySet.size());
309 for(final String key : keySet)
310 { values.add(new Tuple.ComparablePair<Long, String>(h.get(key).longValue(), key)); }
311 Collections.sort(values);
312 for(final Tuple.ComparablePair<Long, String> value : values)
313 { printStats(true, statsSet, value.second, value.first, delta); }
314 }
315
316 /**Print stats item to its output sink.
317 * This might be zero or more streams
318 * and zero or more other sinks such as files.
319 * <p>
320 * This includes a delta time in milliseconds from collection creation.
321 */
322 private static void printStats(final boolean summary,
323 final StatsConfig config,
324 final String event,
325 final Number item,
326 final long delta)
327 {
328 // If we're logging to a stream, do so now.
329 if(config.logger != null)
330 {
331 final StringBuilder toPrint = new StringBuilder(81);
332 toPrint.append(config.name).append(": ");
333 toPrint.append(summary ? "SUMMARY" : "EVENT").append(": ");
334 toPrint.append(delta).append("ms: ");
335 toPrint.append("event ").append(event).append(": ");
336 toPrint.append("count ").append(item.longValue());
337
338 config.logger.log(toPrint.toString());
339 }
340 }
341 }