diff options
Diffstat (limited to 'dblib/common/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java')
| -rw-r--r-- | dblib/common/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java | 516 |
1 files changed, 516 insertions, 0 deletions
diff --git a/dblib/common/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java b/dblib/common/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java new file mode 100644 index 0000000..23fa3fa --- /dev/null +++ b/dblib/common/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java @@ -0,0 +1,516 @@ +/*- + * ============LICENSE_START======================================================= + * openecomp + * ================================================================================ + * Copyright (C) 2016 - 2017 AT&T + * ================================================================================ + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * ============LICENSE_END========================================================= + */ + +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.tomcat.jdbc.pool.interceptor; + +import java.text.SimpleDateFormat; +import java.util.ArrayList; +import java.util.Collections; +import java.util.Comparator; +import java.util.Locale; +import java.util.Map; +import java.util.TimeZone; +import java.util.concurrent.ConcurrentHashMap; + +import javax.management.openmbean.CompositeDataSupport; +import javax.management.openmbean.CompositeType; +import javax.management.openmbean.OpenDataException; +import javax.management.openmbean.OpenType; +import javax.management.openmbean.SimpleType; + +import org.apache.juli.logging.Log; +import org.apache.juli.logging.LogFactory; +import org.apache.tomcat.jdbc.pool.ConnectionPool; +import org.apache.tomcat.jdbc.pool.PoolProperties.InterceptorProperty; +import org.apache.tomcat.jdbc.pool.PooledConnection; + +/** + * Slow query report interceptor. Tracks timing of query executions. + * @version 1.0 + */ +public class SlowQueryReport extends AbstractQueryReport { + //logger + private static final Log log = LogFactory.getLog(SlowQueryReport.class); + + /** + * we will be keeping track of query stats on a per pool basis + */ + protected static final ConcurrentHashMap<String,ConcurrentHashMap<String,QueryStats>> perPoolStats = + new ConcurrentHashMap<>(); + /** + * the queries that are used for this interceptor. + */ + protected volatile ConcurrentHashMap<String,QueryStats> queries = null; + /** + * Maximum number of queries we will be storing + */ + protected int maxQueries= 1000; //don't store more than this amount of queries + + /** + * Flag to enable disable logging of slow queries + */ + protected boolean logSlow = true; + + /** + * Flag to enable disable logging of failed queries + */ + protected boolean logFailed = false; + + /** + * Sort QueryStats by last invocation time + */ + protected final Comparator<QueryStats> queryStatsComparator = new QueryStatsComparator(); + + /** + * Returns the query stats for a given pool + * @param poolname - the name of the pool we want to retrieve stats for + * @return a hash map containing statistics for 0 to maxQueries + */ + public static ConcurrentHashMap<String,QueryStats> getPoolStats(String poolname) { + return perPoolStats.get(poolname); + } + + /** + * Creates a slow query report interceptor + */ + public SlowQueryReport() { + super(); + } + + public void setMaxQueries(int maxQueries) { + this.maxQueries = maxQueries; + } + + + @Override + protected String reportFailedQuery(String query, Object[] args, String name, long start, Throwable t) { + String sql = super.reportFailedQuery(query, args, name, start, t); + if (this.maxQueries > 0 ) { + long now = System.currentTimeMillis(); + long delta = now - start; + QueryStats qs = this.getQueryStats(sql); + if (qs != null) { + qs.failure(delta, now); + if (isLogFailed() && log.isWarnEnabled()) { + log.warn("Failed Query Report SQL="+sql+"; time="+delta+" ms;"); + } + } + } + return sql; + } + + @Override + protected String reportQuery(String query, Object[] args, final String name, long start, long delta) { + String sql = super.reportQuery(query, args, name, start, delta); + if (this.maxQueries > 0 ) { + QueryStats qs = this.getQueryStats(sql); + if (qs != null) qs.add(delta, start); + } + return sql; + } + + @Override + protected String reportSlowQuery(String query, Object[] args, String name, long start, long delta) { + String sql = super.reportSlowQuery(query, args, name, start, delta); + if (this.maxQueries > 0 ) { + QueryStats qs = this.getQueryStats(sql); + if (qs != null) { + qs.add(delta, start); + if (isLogSlow() && log.isWarnEnabled()) { + log.warn("Slow Query Report SQL="+sql+"; time="+delta+" ms;"); + } + } + } + return sql; + } + + /** + * invoked when the connection receives the close request + * Not used for now. + */ + @Override + public void closeInvoked() { + // NOOP + } + + @Override + public void prepareStatement(String sql, long time) { + if (this.maxQueries > 0 ) { + QueryStats qs = getQueryStats(sql); + if (qs != null) qs.prepare(time); + } + } + + @Override + public void prepareCall(String sql, long time) { + if (this.maxQueries > 0 ) { + QueryStats qs = getQueryStats(sql); + if (qs != null) qs.prepare(time); + } + } + + /** + * {@inheritDoc} + */ + @Override + public void poolStarted(ConnectionPool pool) { + super.poolStarted(pool); + //see if we already created a map for this pool + queries = SlowQueryReport.perPoolStats.get(pool.getName()); + if (queries==null) { + //create the map to hold our stats + //however TODO we need to improve the eviction + //selection + queries = new ConcurrentHashMap<>(); + if (perPoolStats.putIfAbsent(pool.getName(), queries)!=null) { + //there already was one + queries = SlowQueryReport.perPoolStats.get(pool.getName()); + } + } + } + + /** + * {@inheritDoc} + */ + @Override + public void poolClosed(ConnectionPool pool) { + perPoolStats.remove(pool.getName()); + super.poolClosed(pool); + } + + protected QueryStats getQueryStats(String sql) { + if (sql==null) sql = ""; + ConcurrentHashMap<String,QueryStats> queries = SlowQueryReport.this.queries; + if (queries==null) { + if (log.isWarnEnabled()) log.warn("Connection has already been closed or abandoned"); + return null; + } + QueryStats qs = queries.get(sql); + if (qs == null) { + qs = new QueryStats(sql); + if (queries.putIfAbsent(sql,qs)!=null) { + qs = queries.get(sql); + } else { + //we added a new element, see if we need to remove the oldest + if (queries.size() > maxQueries) { + removeOldest(queries); + } + } + } + return qs; + } + + /** + * Sort QueryStats by last invocation time + * @param queries The queries map + */ + protected void removeOldest(ConcurrentHashMap<String,QueryStats> queries) { + ArrayList<QueryStats> list = new ArrayList<>(queries.values()); + Collections.sort(list, queryStatsComparator); + int removeIndex = 0; + while (queries.size() > maxQueries) { + String sql = list.get(removeIndex).getQuery(); + queries.remove(sql); + if (log.isDebugEnabled()) log.debug("Removing slow query, capacity reached:"+sql); + removeIndex++; + } + } + + + @Override + public void reset(ConnectionPool parent, PooledConnection con) { + super.reset(parent, con); + if (parent!=null) + queries = SlowQueryReport.perPoolStats.get(parent.getName()); + else + queries = null; + } + + + public boolean isLogSlow() { + return logSlow; + } + + public void setLogSlow(boolean logSlow) { + this.logSlow = logSlow; + } + + public boolean isLogFailed() { + return logFailed; + } + + public void setLogFailed(boolean logFailed) { + this.logFailed = logFailed; + } + + @Override + public void setProperties(Map<String, InterceptorProperty> properties) { + super.setProperties(properties); + final String threshold = "threshold"; + final String maxqueries= "maxQueries"; + final String logslow = "logSlow"; + final String logfailed = "logFailed"; + InterceptorProperty p1 = properties.get(threshold); + InterceptorProperty p2 = properties.get(maxqueries); + InterceptorProperty p3 = properties.get(logslow); + InterceptorProperty p4 = properties.get(logfailed); + if (p1!=null) { + setThreshold(Long.parseLong(p1.getValue())); + } + if (p2!=null) { + setMaxQueries(Integer.parseInt(p2.getValue())); + } + if (p3!=null) { + setLogSlow(Boolean.parseBoolean(p3.getValue())); + } + if (p4!=null) { + setLogFailed(Boolean.parseBoolean(p4.getValue())); + } + } + + + public static class QueryStats { + static final String[] FIELD_NAMES = new String[] { + "query", + "nrOfInvocations", + "maxInvocationTime", + "maxInvocationDate", + "minInvocationTime", + "minInvocationDate", + "totalInvocationTime", + "failures", + "prepareCount", + "prepareTime", + "lastInvocation" + }; + + static final String[] FIELD_DESCRIPTIONS = new String[] { + "The SQL query", + "The number of query invocations, a call to executeXXX", + "The longest time for this query in milliseconds", + "The time and date for when the longest query took place", + "The shortest time for this query in milliseconds", + "The time and date for when the shortest query took place", + "The total amount of milliseconds spent executing this query", + "The number of failures for this query", + "The number of times this query was prepared (prepareStatement/prepareCall)", + "The total number of milliseconds spent preparing this query", + "The date and time of the last invocation" + }; + + static final OpenType<?>[] FIELD_TYPES = new OpenType[] { + SimpleType.STRING, + SimpleType.INTEGER, + SimpleType.LONG, + SimpleType.LONG, + SimpleType.LONG, + SimpleType.LONG, + SimpleType.LONG, + SimpleType.LONG, + SimpleType.INTEGER, + SimpleType.LONG, + SimpleType.LONG + }; + + private final String query; + private volatile int nrOfInvocations; + private volatile long maxInvocationTime = Long.MIN_VALUE; + private volatile long maxInvocationDate; + private volatile long minInvocationTime = Long.MAX_VALUE; + private volatile long minInvocationDate; + private volatile long totalInvocationTime; + private volatile long failures; + private volatile int prepareCount; + private volatile long prepareTime; + private volatile long lastInvocation = 0; + + public static String[] getFieldNames() { + return FIELD_NAMES; + } + + public static String[] getFieldDescriptions() { + return FIELD_DESCRIPTIONS; + } + + public static OpenType<?>[] getFieldTypes() { + return FIELD_TYPES; + } + + @Override + public String toString() { + SimpleDateFormat sdf = + new SimpleDateFormat("d MMM yyyy HH:mm:ss z", Locale.US); + sdf.setTimeZone(TimeZone.getTimeZone("GMT")); + StringBuilder buf = new StringBuilder("QueryStats[query:"); + buf.append(query); + buf.append(", nrOfInvocations:"); + buf.append(nrOfInvocations); + buf.append(", maxInvocationTime:"); + buf.append(maxInvocationTime); + buf.append(", maxInvocationDate:"); + buf.append(sdf.format(new java.util.Date(maxInvocationDate))); + buf.append(", minInvocationTime:"); + buf.append(minInvocationTime); + buf.append(", minInvocationDate:"); + buf.append(sdf.format(new java.util.Date(minInvocationDate))); + buf.append(", totalInvocationTime:"); + buf.append(totalInvocationTime); + buf.append(", averageInvocationTime:"); + buf.append((float)totalInvocationTime / (float)nrOfInvocations); + buf.append(", failures:"); + buf.append(failures); + buf.append(", prepareCount:"); + buf.append(prepareCount); + buf.append(", prepareTime:"); + buf.append(prepareTime); + buf.append("]"); + return buf.toString(); + } + + public CompositeDataSupport getCompositeData(final CompositeType type) throws OpenDataException{ + Object[] values = new Object[] { + query, + Integer.valueOf(nrOfInvocations), + Long.valueOf(maxInvocationTime), + Long.valueOf(maxInvocationDate), + Long.valueOf(minInvocationTime), + Long.valueOf(minInvocationDate), + Long.valueOf(totalInvocationTime), + Long.valueOf(failures), + Integer.valueOf(prepareCount), + Long.valueOf(prepareTime), + Long.valueOf(lastInvocation) + }; + return new CompositeDataSupport(type,FIELD_NAMES,values); + } + + public QueryStats(String query) { + this.query = query; + } + + public void prepare(long invocationTime) { + prepareCount++; + prepareTime+=invocationTime; + + } + + public void add(long invocationTime, long now) { + //not thread safe, but don't sacrifice performance for this kind of stuff + maxInvocationTime = Math.max(invocationTime, maxInvocationTime); + if (maxInvocationTime == invocationTime) { + maxInvocationDate = now; + } + minInvocationTime = Math.min(invocationTime, minInvocationTime); + if (minInvocationTime==invocationTime) { + minInvocationDate = now; + } + nrOfInvocations++; + totalInvocationTime+=invocationTime; + lastInvocation = now; + } + + public void failure(long invocationTime, long now) { + add(invocationTime,now); + failures++; + + } + + public String getQuery() { + return query; + } + + public int getNrOfInvocations() { + return nrOfInvocations; + } + + public long getMaxInvocationTime() { + return maxInvocationTime; + } + + public long getMaxInvocationDate() { + return maxInvocationDate; + } + + public long getMinInvocationTime() { + return minInvocationTime; + } + + public long getMinInvocationDate() { + return minInvocationDate; + } + + public long getTotalInvocationTime() { + return totalInvocationTime; + } + + @Override + public int hashCode() { + return query.hashCode(); + } + + @Override + public boolean equals(Object other) { + if (other instanceof QueryStats) { + QueryStats qs = (QueryStats)other; + return qs.query.equals(this.query); + } + return false; + } + + public boolean isOlderThan(QueryStats other) { + return this.lastInvocation < other.lastInvocation; + } + } + + /** Compare QueryStats by their lastInvocation value. QueryStats that + * have never been updated, have a lastInvocation value of {@code 0} + * which should be handled as the newest possible invocation. + */ + private static class QueryStatsComparator implements Comparator<QueryStats> { + + @Override + public int compare(QueryStats stats1, QueryStats stats2) { + return Long.compare(handleZero(stats1.lastInvocation), + handleZero(stats2.lastInvocation)); + } + + private static long handleZero(long value) { + return value == 0 ? Long.MAX_VALUE : value; + } + + } + +} |