com.avaje.ebeaninternal.server.autofetch.DefaultAutoFetchManager Maven / Gradle / Ivy
package com.avaje.ebeaninternal.server.autofetch;
import java.io.File;
import java.io.FileOutputStream;
import java.io.ObjectOutputStream;
import java.io.Serializable;
import java.util.Iterator;
import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;
import java.util.logging.Level;
import javax.persistence.PersistenceException;
import com.avaje.ebean.bean.CallStack;
import com.avaje.ebean.bean.NodeUsageCollector;
import com.avaje.ebean.bean.ObjectGraphNode;
import com.avaje.ebean.bean.ObjectGraphOrigin;
import com.avaje.ebean.config.AutofetchConfig;
import com.avaje.ebean.config.AutofetchMode;
import com.avaje.ebean.config.ServerConfig;
import com.avaje.ebeaninternal.api.ClassUtil;
import com.avaje.ebeaninternal.api.SpiEbeanServer;
import com.avaje.ebeaninternal.api.SpiQuery;
import com.avaje.ebeaninternal.server.deploy.BeanDescriptor;
import com.avaje.ebeaninternal.server.querydefn.OrmQueryDetail;
/**
* The manager of all the usage/query statistics as well as the tuned fetch
* information.
*/
public class DefaultAutoFetchManager implements AutoFetchManager, Serializable {
private static final long serialVersionUID = -6826119882781771722L;
private final String statisticsMonitor = new String();
private final String fileName;
/**
* Map of the usage and query statistics gathered.
*/
private Map statisticsMap = new ConcurrentHashMap();
/**
* Map of the tuned query details per profile query point.
*/
private Map tunedQueryInfoMap = new ConcurrentHashMap();
private transient long defaultGarbageCollectionWait = 100;
/**
* Left without synchronized for now.
*/
private transient int tunedQueryCount;
/**
* Converted from a 0-100 int to a double. Effectively a percentage rate at
* which to collect profiling information.
*/
private transient double profilingRate = 0.1d;
private transient int profilingBase = 10;
private transient int profilingMin = 1;
private transient boolean profiling;
private transient boolean queryTuning;
private transient boolean queryTuningAddVersion;
private transient AutofetchMode mode;
private transient boolean useFileLogging;
/**
* Server that owns this Profile Listener.
*/
private transient SpiEbeanServer server;
/**
* The logger.
*/
private transient DefaultAutoFetchManagerLogging logging;
public DefaultAutoFetchManager(String fileName) {
this.fileName = fileName;
}
/**
* Set up this profile listener before it is active.
*/
public void setOwner(SpiEbeanServer server, ServerConfig serverConfig) {
this.server = server;
this.logging = new DefaultAutoFetchManagerLogging(serverConfig, this);
AutofetchConfig autofetchConfig = serverConfig.getAutofetchConfig();
useFileLogging = autofetchConfig.isUseFileLogging();
queryTuning = autofetchConfig.isQueryTuning();
queryTuningAddVersion = autofetchConfig.isQueryTuningAddVersion();
profiling = autofetchConfig.isProfiling();
profilingMin = autofetchConfig.getProfilingMin();
profilingBase = autofetchConfig.getProfilingBase();
setProfilingRate(autofetchConfig.getProfilingRate());
defaultGarbageCollectionWait = (long) autofetchConfig.getGarbageCollectionWait();
// determine the mode to use when Query.setAutoFetch() was
// not explicitly set
mode = autofetchConfig.getMode();
// log the guts of the autoFetch setup
String msg = "AutoFetch queryTuning[" + queryTuning + "] profiling[" + profiling
+ "] mode[" + mode + "] profiling rate[" + profilingRate
+ "] min[" + profilingMin + "] base[" + profilingBase + "]";
logging.logToJavaLogger(msg);
}
public void clearQueryStatistics() {
server.clearQueryStatistics();
}
/**
* Return the number of queries tuned by AutoFetch.
*/
public int getTotalTunedQueryCount(){
return tunedQueryCount;
}
/**
* Return the size of the TuneQuery map.
*/
public int getTotalTunedQuerySize(){
return tunedQueryInfoMap.size();
}
/**
* Return the size of the profile map.
*/
public int getTotalProfileSize(){
return statisticsMap.size();
}
public int clearTunedQueryInfo() {
// reset the rough count as well
tunedQueryCount = 0;
// clear the map...
int size = tunedQueryInfoMap.size();
tunedQueryInfoMap.clear();
return size;
}
public int clearProfilingInfo() {
int size = statisticsMap.size();
statisticsMap.clear();
return size;
}
public void serialize() {
File autoFetchFile = new File(fileName);
try {
FileOutputStream fout = new FileOutputStream(autoFetchFile);
ObjectOutputStream oout = new ObjectOutputStream(fout);
oout.writeObject(this);
oout.flush();
oout.close();
} catch (Exception e) {
String msg = "Error serializing autofetch file";
logging.logError(Level.SEVERE, msg, e);
}
}
/**
* Return the current Tuned query info for a given origin key.
*/
public TunedQueryInfo getTunedQueryInfo(String originKey) {
return tunedQueryInfoMap.get(originKey);
}
/**
* Return the current Statistics for a given originKey key.
*/
public Statistics getStatistics(String originKey) {
return statisticsMap.get(originKey);
}
public Iterator iterateTunedQueryInfo() {
return tunedQueryInfoMap.values().iterator();
}
public Iterator iterateStatistics() {
return statisticsMap.values().iterator();
}
public boolean isProfiling() {
return profiling;
}
/**
* When the application is running, BEFORE turning off profiling you
* probably should call collectUsageViaGC() as there is a delay (waiting for
* garbage collection) collecting usage profiling information.
*/
public void setProfiling(boolean profiling) {
this.profiling = profiling;
}
public boolean isQueryTuning() {
return queryTuning;
}
public void setQueryTuning(boolean queryTuning) {
this.queryTuning = queryTuning;
}
public double getProfilingRate() {
return profilingRate;
}
public AutofetchMode getMode() {
return mode;
}
public void setMode(AutofetchMode mode) {
this.mode = mode;
}
public void setProfilingRate(double rate) {
if (rate < 0) {
rate = 0d;
} else if (rate > 1) {
rate = 1d;
}
profilingRate = rate;
}
public int getProfilingBase() {
return profilingBase;
}
public void setProfilingBase(int profilingBase) {
this.profilingBase = profilingBase;
}
public int getProfilingMin() {
return profilingMin;
}
public void setProfilingMin(int profilingMin) {
this.profilingMin = profilingMin;
}
/**
* Shutdown the listener.
*
* We should try to collect the usage statistics by calling a System.gc().
* This is necessary for use with short lived applications where garbage
* collection may not otherwise occur at all.
*
*/
public void shutdown() {
collectUsageViaGC(-1);
if (useFileLogging) {
serialize();
}
}
/**
* Ask for a System.gc() so that we gather node usage information.
*
* Really only want to do this sparingly but useful just prior to shutdown
* for short run application where garbage collection may otherwise not
* occur at all.
*
*
* waitMillis will do a thread sleep to give the garbage collection a little
* time to do its thing assuming we are shutting down the VM.
*
*
* If waitMillis is -1 then the defaultGarbageCollectionWait is used which
* defaults to 100 milliseconds.
*
*/
public String collectUsageViaGC(long waitMillis) {
System.gc();
try {
if (waitMillis < 0) {
waitMillis = defaultGarbageCollectionWait;
}
Thread.sleep(waitMillis);
} catch (InterruptedException e) {
String msg = "Error while sleeping after System.gc() request.";
logging.logError(Level.SEVERE, msg, e);
return msg;
}
return updateTunedQueryInfo();
}
/**
* Update the tuned fetch plans from the current usage information.
*/
public String updateTunedQueryInfo() {
if (!profiling) {
// we are not collecting any profiling information at
// the moment so don't try updating the tuned query plans.
return "Not profiling";
}
synchronized (statisticsMonitor) {
Counters counters = new Counters();
Iterator it = statisticsMap.values().iterator();
while (it.hasNext()) {
Statistics queryPointStatistics = it.next();
if (!queryPointStatistics.hasUsage()){
// no usage statistics collected yet...
counters.incrementNoUsage();
} else {
updateTunedQueryFromUsage(counters, queryPointStatistics);
}
}
String summaryInfo = counters.toString();
if (counters.isInteresting()){
// only log it if its interesting
logging.logSummary(summaryInfo);
}
return summaryInfo;
}
}
private static class Counters {
int newPlan;
int modified;
int unchanged;
int noUsage;
void incrementNoUsage(){
noUsage++;
}
void incrementNew(){
newPlan++;
}
void incrementModified(){
modified++;
}
void incrementUnchanged(){
unchanged++;
}
boolean isInteresting() {
return newPlan > 0 || modified > 0;
}
public String toString() {
return "new["+newPlan+"] modified["+modified+"] unchanged["+unchanged+"] nousage["+noUsage+"]";
}
}
private void updateTunedQueryFromUsage(Counters counters, Statistics statistics) {
ObjectGraphOrigin queryPoint = statistics.getOrigin();
String beanType = queryPoint.getBeanType();
try {
Class> beanClass = ClassUtil.forName(beanType, this.getClass());
BeanDescriptor> beanDescriptor = server.getBeanDescriptor(beanClass);
if (beanDescriptor == null){
// previously was an entity but not longer
} else {
// Determine the fetch plan from the latest statistics.
// Use this to compare with current "tuned fetch plan".
OrmQueryDetail newFetchDetail = statistics.buildTunedFetch(beanDescriptor);
// get the current tuned fetch info...
TunedQueryInfo currentFetch = tunedQueryInfoMap.get(queryPoint.getKey());
if (currentFetch == null) {
// its a new fetch plan, add it.
counters.incrementNew();
currentFetch = statistics.createTunedFetch(newFetchDetail);
logging.logNew(currentFetch);
tunedQueryInfoMap.put(queryPoint.getKey(), currentFetch);
} else if (!currentFetch.isSame(newFetchDetail)) {
// the fetch plan has changed, update it.
counters.incrementModified();
logging.logChanged(currentFetch, newFetchDetail);
currentFetch.setTunedDetail(newFetchDetail);
} else {
// the fetch plan has not changed...
counters.incrementUnchanged();
}
currentFetch.setProfileCount(statistics.getCounter());
}
} catch (ClassNotFoundException e) {
// expected after renaming/moving an entity bean
String msg = e.toString()+" updating autoFetch tuned query for " + beanType
+". It isLikely this bean has been renamed or moved";
logging.logError(Level.INFO, msg, null);
statisticsMap.remove(statistics.getOrigin().getKey());
}
}
/**
* Return true if we should try to use autoFetch for this query.
*/
private boolean useAutoFetch(SpiQuery> query) {
if (query.isLoadBeanCache() || query.isSharedInstance()){
// when loading the cache don't tune the query
// as we want full objects loaded into the cache
return false;
}
Boolean autoFetch = query.isAutofetch();
if (autoFetch != null) {
// explicitly set...
return autoFetch.booleanValue();
} else {
// determine using implicit mode...
switch (mode) {
case DEFAULT_ON:
return true;
case DEFAULT_OFF:
return false;
case DEFAULT_ONIFEMPTY:
return query.isDetailEmpty();
default:
throw new PersistenceException("Invalid autoFetchMode " + mode);
}
}
}
/**
* Auto tune the query and enable profiling.
*/
public boolean tuneQuery(SpiQuery> query) {
if (!queryTuning && !profiling) {
return false;
}
if (!useAutoFetch(query)) {
// not using autoFetch for this query
return false;
}
ObjectGraphNode parentAutoFetchNode = query.getParentNode();
if (parentAutoFetchNode != null) {
// This is a +lazy/+query query with profiling on.
// We continue to collect the profiling information.
query.setAutoFetchManager(this);
return true;
}
// create a query point to identify the query
CallStack stack = server.createCallStack();
ObjectGraphNode origin = query.setOrigin(stack);
// get current "tuned fetch" for this query point
TunedQueryInfo tunedFetch = tunedQueryInfoMap.get(origin.getOriginQueryPoint().getKey());
// get the number of times we have collected profiling information
int profileCount = tunedFetch == null ? 0 : tunedFetch.getProfileCount();
if (profiling) {
// we want more profiling information?
if (tunedFetch == null) {
query.setAutoFetchManager(this);
} else if (profileCount < profilingBase) {
query.setAutoFetchManager(this);
} else if (tunedFetch.isPercentageProfile(profilingRate)) {
query.setAutoFetchManager(this);
}
}
if (queryTuning) {
if (tunedFetch != null && profileCount >= profilingMin) {
// deemed to have enough profiling
// information for automatic tuning
if (tunedFetch.autoFetchTune(query)){
// tunedQueryCount++ not thread-safe, could use AtomicInteger.
// But I'm happy if this statistic is a little wrong
// and this is a VERY HOT method
tunedQueryCount++;
}
return true;
}
}
return false;
}
/**
* Gather query execution statistics. This could either be the originating
* query in which case the parentNode will be null, or a lazy loading query
* resulting from traversal of the object graph.
*/
public void collectQueryInfo(ObjectGraphNode node, int beans, int micros) {
if (node != null){
ObjectGraphOrigin origin = node.getOriginQueryPoint();
if (origin != null){
Statistics stats = getQueryPointStats(origin);
stats.collectQueryInfo(node, beans, micros);
}
}
}
/**
* Collect usage statistics from a node in the object graph.
*
* This is sent to use from a EntityBeanIntercept when the finalise method
* is called on the bean.
*
*/
public void collectNodeUsage(NodeUsageCollector usageCollector) {
ObjectGraphOrigin origin = usageCollector.getNode().getOriginQueryPoint();
Statistics stats = getQueryPointStats(origin);
if (logging.isTraceUsageCollection()){
System.out.println("... NodeUsageCollector "+usageCollector);
}
stats.collectUsageInfo(usageCollector);
if (logging.isTraceUsageCollection()){
System.out.println("stats\n"+stats);
}
}
private Statistics getQueryPointStats(ObjectGraphOrigin originQueryPoint) {
synchronized (statisticsMonitor) {
Statistics stats = statisticsMap.get(originQueryPoint.getKey());
if (stats == null) {
stats = new Statistics(originQueryPoint, queryTuningAddVersion);
statisticsMap.put(originQueryPoint.getKey(), stats);
}
return stats;
}
}
public String toString() {
synchronized (statisticsMonitor) {
return statisticsMap.values().toString();
}
}
}