@@ -24,221 +24,218 @@ import com.avaje.ebeaninternal.api.SpiQuery; */ public interface AutoFetchManager extends NodeUsageListener { - /** - * Set the owning ebean server. - */ - void setOwner(SpiEbeanServer server, ServerConfig serverConfig); + /** + * Set the owning ebean server. + */ + void setOwner(SpiEbeanServer server, ServerConfig serverConfig); - /** - * Clear the query execution statistics. - */ - void clearQueryStatistics(); - - /** - * Clear all the tuned query info. - *
- * Should only need do this for testing and playing around. - *
- */ - int clearTunedQueryInfo(); + /** + * Clear the query execution statistics. + */ + void clearQueryStatistics(); - /** - * Clear all the profiling information. - *- * This means the profiling information will need to be re-gathered. - *
- *- * Should only need do this for testing and playing around. - *
- */ - int clearProfilingInfo(); + /** + * Clear all the tuned query info. + *+ * Should only need do this for testing and playing around. + *
+ */ + int clearTunedQueryInfo(); - /** - * On shutdown fire garbage collection and collect statistics. Note that - * usually we add a little delay (100 milliseconds) to give the garbage - * collector plenty of time to do its thing and collect the profile - * information. - */ - void shutdown(); + /** + * Clear all the profiling information. + *+ * This means the profiling information will need to be re-gathered. + *
+ *+ * Should only need do this for testing and playing around. + *
+ */ + int clearProfilingInfo(); - /** - * Return the current tuned fetch information for a given queryPoint key. - */ - TunedQueryInfo getTunedQueryInfo(String queryPointKey); + /** + * On shutdown fire garbage collection and collect statistics. Note that + * usually we add a little delay (100 milliseconds) to give the garbage + * collector plenty of time to do its thing and collect the profile + * information. + */ + void shutdown(); - /** - * Return the current Statistics for a given queryPoint key. - */ - Statistics getStatistics(String queryPointKey); + /** + * Return the current tuned fetch information for a given queryPoint key. + */ + TunedQueryInfo getTunedQueryInfo(String queryPointKey); - /** - * Iterate the tuned fetch info. - *- * This should be a read only iteration. - *
- */ - Iterator- * This should be a read only iteration. - *
- */ - Iterator+ * This should be a read only iteration. + *
+ */ + Iterator+ * This should be a read only iteration. + *
+ */ + Iterator- * We rely on garbage collection to collect the profiling information. This - * means there is a unknown delay between when a query is executed and when - * we actually collect the usage profile information. - *
- *- * Due to this garbage collection delay, when turning off profiling while - * the application is running you should consider calling - * collectUsageViaGC() BEFORE setProfiling(false). This hints to - * the JVM to perform garbage collection, and hopefully collects the - * profiling information. - *
- */ - void setProfiling(boolean enable); + /** + * Return true if profiling is enabled. + */ + boolean isProfiling(); - /** - * Return true if automatic query tuning is enabled. - */ - boolean isQueryTuning(); + /** + * Set to true to enable profiling. + *+ * We rely on garbage collection to collect the profiling information. This + * means there is a unknown delay between when a query is executed and when + * we actually collect the usage profile information. + *
+ *+ * Due to this garbage collection delay, when turning off profiling while + * the application is running you should consider calling + * collectUsageViaGC() BEFORE setProfiling(false). This hints to + * the JVM to perform garbage collection, and hopefully collects the + * profiling information. + *
+ */ + void setProfiling(boolean enable); - /** - * Set to true to enable automatic query tuning. - */ - void setQueryTuning(boolean enable); + /** + * Return true if automatic query tuning is enabled. + */ + boolean isQueryTuning(); - /** - * This controls whether autoFetch is used when it has not been explicitly - * set on a query via {@link Query#setAutofetch(boolean)}. - */ - AutofetchMode getMode(); + /** + * Set to true to enable automatic query tuning. + */ + void setQueryTuning(boolean enable); - /** - * Set the auto fetch mode used when a query has not had - * {@link Query#setAutofetch(boolean)}. - */ - void setMode(AutofetchMode Mode); + /** + * This controls whether autoFetch is used when it has not been explicitly + * set on a query via {@link Query#setAutofetch(boolean)}. + */ + AutofetchMode getMode(); - /** - * Return the profiling rate (int between 0 and 100). - */ - double getProfilingRate(); + /** + * Set the auto fetch mode used when a query has not had + * {@link Query#setAutofetch(boolean)}. + */ + void setMode(AutofetchMode Mode); - /** - * Set the profiling rate (int between 0 and 100). - */ - void setProfilingRate(double rate); + /** + * Return the profiling rate (int between 0 and 100). + */ + double getProfilingRate(); - /** - * Return the max number of queries profiled (per query point). - *- * The number of queries profiled is collected per query point. Once a query - * point has profiled this number of queries it does not profile any more. - *
- */ - int getProfilingBase(); + /** + * Set the profiling rate (int between 0 and 100). + */ + void setProfilingRate(double rate); - /** - * Set a max number of queries to profile per query point. - *- * This number should provide a level of confidence that no more profiling - * is required for this query point. - *
- */ - void setProfilingBase(int profilingMax); + /** + * Return the max number of queries profiled (per query point). + *+ * The number of queries profiled is collected per query point. Once a query + * point has profiled this number of queries it does not profile any more. + *
+ */ + int getProfilingBase(); - /** - * Return the minimum number of queries profiled before autoFetch will start - * automatically tuning the queries. - *- * This could be one which means start autoFetch tuning after the first - * profiling information is collected. - *
- */ - int getProfilingMin(); + /** + * Set a max number of queries to profile per query point. + *+ * This number should provide a level of confidence that no more profiling + * is required for this query point. + *
+ */ + void setProfilingBase(int profilingMax); - /** - * Set the minimum number of queries profiled per query point before - * autoFetch will automatically tune the queries. - *- * Increasing this number will mean more profiling is collected before - * autoFetch starts tuning the query. - *
- */ - void setProfilingMin(int autoFetchMinThreshold); + /** + * Return the minimum number of queries profiled before autoFetch will start + * automatically tuning the queries. + *+ * This could be one which means start autoFetch tuning after the first + * profiling information is collected. + *
+ */ + int getProfilingMin(); - /** - * Fire a garbage collection (hint to the JVM). Assuming garbage collection - * fires this will gather the usage profiling information. - */ - String collectUsageViaGC(long waitMillis); + /** + * Set the minimum number of queries profiled per query point before + * autoFetch will automatically tune the queries. + *+ * Increasing this number will mean more profiling is collected before + * autoFetch starts tuning the query. + *
+ */ + void setProfilingMin(int autoFetchMinThreshold); - /** - * This will take the current profiling information and update the "tuned - * query detail". - *- * This is done periodically and can also be manually invoked. - *
- *- * This returns a string summary of the updates that occurred. - *
- */ - String updateTunedQueryInfo(); + /** + * Fire a garbage collection (hint to the JVM). Assuming garbage collection + * fires this will gather the usage profiling information. + */ + String collectUsageViaGC(long waitMillis); - /** - * Called when a query thinks it should be automatically tuned by autoFetch. - *- * This internally checks that autoFetch is enabled, there is a "tuned query - * detail" to tune the query with and that the autoFetchMinThreshold has - * been reached. - *
- *- * This will also determine if the query should be profiled. - *
- */ - boolean tuneQuery(SpiQuery query); + /** + * This will take the current profiling information and update the "tuned + * query detail". + *+ * This is done periodically and can also be manually invoked. + *
+ *+ * This returns a string summary of the updates that occurred. + *
+ */ + String updateTunedQueryInfo(); - /** - * Collect query profiling information. - *- * This is for the original query as well as any subsequent lazy loading - * queries that are required as the object graph is traversed. - *
- * - * @param node - * the node path in the object graph. - * @param beans - * the number of beans loaded by the query. - * @param micros - * the query executing time in microseconds - */ - void collectQueryInfo(ObjectGraphNode node, long beans, long micros); + /** + * Called when a query thinks it should be automatically tuned by autoFetch. + *+ * This internally checks that autoFetch is enabled, there is a "tuned query + * detail" to tune the query with and that the autoFetchMinThreshold has + * been reached. + *
+ *+ * This will also determine if the query should be profiled. + *
+ */ + boolean tuneQuery(SpiQuery query); - - /** - * Return the number of queries tuned by AutoFetch. - */ - int getTotalTunedQueryCount(); - - /** - * Return the size of the TuneQuery map. - */ - int getTotalTunedQuerySize(); - - /** - * Return the size of the profile map. - */ - int getTotalProfileSize(); + /** + * Collect query profiling information. + *+ * This is for the original query as well as any subsequent lazy loading + * queries that are required as the object graph is traversed. + *
+ * + * @param node the node path in the object graph. + * @param beans the number of beans loaded by the query. + * @param micros the query executing time in microseconds + */ + void collectQueryInfo(ObjectGraphNode node, long beans, long micros); + + + /** + * Return the number of queries tuned by AutoFetch. + */ + int getTotalTunedQueryCount(); + + /** + * Return the size of the TuneQuery map. + */ + int getTotalTunedQuerySize(); + + /** + * Return the size of the profile map. + */ + int getTotalProfileSize(); } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoFetchManagerFactory.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoFetchManagerFactory.java index 8cb8b2e79..b19a4ee37 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoFetchManagerFactory.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoFetchManagerFactory.java @@ -13,83 +13,83 @@ import java.io.ObjectInputStream; public class AutoFetchManagerFactory { - private static final Logger logger = LoggerFactory.getLogger(AutoFetchManagerFactory.class); + private static final Logger logger = LoggerFactory.getLogger(AutoFetchManagerFactory.class); - public static AutoFetchManager create(SpiEbeanServer server, ServerConfig serverConfig, ResourceManager resourceManager) { - - AutoFetchManagerFactory me = new AutoFetchManagerFactory(); - return me.createAutoFetchManager(server, serverConfig, resourceManager); - } - - private AutoFetchManager createAutoFetchManager(SpiEbeanServer server, ServerConfig serverConfig, ResourceManager resourceManager){ - - AutoFetchManager manager = createAutoFetchManager(server.getName(), resourceManager); - manager.setOwner(server, serverConfig); - - return manager; - } - - private AutoFetchManager createAutoFetchManager(String serverName, ResourceManager resourceManager) { + public static AutoFetchManager create(SpiEbeanServer server, ServerConfig serverConfig, ResourceManager resourceManager) { - File autoFetchFile = getAutoFetchFile(serverName, resourceManager); + AutoFetchManagerFactory me = new AutoFetchManagerFactory(); + return me.createAutoFetchManager(server, serverConfig, resourceManager); + } - AutoFetchManager autoFetchManager = null; + private AutoFetchManager createAutoFetchManager(SpiEbeanServer server, ServerConfig serverConfig, ResourceManager resourceManager) { - boolean readFile = !"false".equalsIgnoreCase(System.getProperty("autofetch.readfromfile")); - if (readFile) { - autoFetchManager = deserializeAutoFetch(autoFetchFile); - } + AutoFetchManager manager = createAutoFetchManager(server.getName(), resourceManager); + manager.setOwner(server, serverConfig); - if (autoFetchManager == null) { - // not deserialized from file so create as empty - // It will be populated automatically by querying the - // database meta data - autoFetchManager = new DefaultAutoFetchManager(autoFetchFile.getAbsolutePath()); - } - - return autoFetchManager; - } - - private AutoFetchManager deserializeAutoFetch(File autoFetchFile) { - try { - - if (!autoFetchFile.exists()) { - return null; - } - FileInputStream fi = new FileInputStream(autoFetchFile); - ObjectInputStream ois = new ObjectInputStream(fi); - AutoFetchManager profListener = (AutoFetchManager) ois.readObject(); - ois.close(); - - logger.info("AutoFetch deserialized from file ["+autoFetchFile.getAbsolutePath()+"]"); - - return profListener; + return manager; + } - } catch (Exception ex) { - logger.error("Error loading autofetch file "+autoFetchFile.getAbsolutePath(), ex); - return null; - } - } - - /** - * Return the file name of the autoFetch meta data. - */ - private File getAutoFetchFile(String serverName, ResourceManager resourceManager) { + private AutoFetchManager createAutoFetchManager(String serverName, ResourceManager resourceManager) { - String fileName = ".ebean."+serverName+".autofetch"; + File autoFetchFile = getAutoFetchFile(serverName, resourceManager); - File dir = resourceManager.getAutofetchDirectory(); + AutoFetchManager autoFetchManager = null; - if (!dir.exists()) { - // automatically create the directory if it does not exist. - // this is probably a fairly reasonable thing to do - if (!dir.mkdirs()) { - String m = "Unable to create directory [" + dir + "] for autofetch file ["+ fileName + "]"; - throw new PersistenceException(m); - } - } + boolean readFile = !"false".equalsIgnoreCase(System.getProperty("autofetch.readfromfile")); + if (readFile) { + autoFetchManager = deserializeAutoFetch(autoFetchFile); + } - return new File(dir, fileName); - } + if (autoFetchManager == null) { + // not deserialized from file so create as empty + // It will be populated automatically by querying the + // database meta data + autoFetchManager = new DefaultAutoFetchManager(autoFetchFile.getAbsolutePath()); + } + + return autoFetchManager; + } + + private AutoFetchManager deserializeAutoFetch(File autoFetchFile) { + try { + + if (!autoFetchFile.exists()) { + return null; + } + FileInputStream fi = new FileInputStream(autoFetchFile); + ObjectInputStream ois = new ObjectInputStream(fi); + AutoFetchManager profListener = (AutoFetchManager) ois.readObject(); + ois.close(); + + logger.info("AutoFetch deserialized from file [" + autoFetchFile.getAbsolutePath() + "]"); + + return profListener; + + } catch (Exception ex) { + logger.error("Error loading autofetch file " + autoFetchFile.getAbsolutePath(), ex); + return null; + } + } + + /** + * Return the file name of the autoFetch meta data. + */ + private File getAutoFetchFile(String serverName, ResourceManager resourceManager) { + + String fileName = ".ebean." + serverName + ".autofetch"; + + File dir = resourceManager.getAutofetchDirectory(); + + if (!dir.exists()) { + // automatically create the directory if it does not exist. + // this is probably a fairly reasonable thing to do + if (!dir.mkdirs()) { + String m = "Unable to create directory [" + dir + "] for autofetch file [" + fileName + "]"; + throw new PersistenceException(m); + } + } + + return new File(dir, fileName); + } } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManager.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManager.java index a2ba4dbec..35dd210ba 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManager.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManager.java @@ -1,15 +1,5 @@ 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 javax.persistence.PersistenceException; - import com.avaje.ebean.bean.CallStack; import com.avaje.ebean.bean.NodeUsageCollector; import com.avaje.ebean.bean.ObjectGraphNode; @@ -25,6 +15,15 @@ import com.avaje.ebeaninternal.server.querydefn.OrmQueryDetail; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import javax.persistence.PersistenceException; +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; + /** * The manager of all the usage/query statistics as well as the tuned fetch * information. @@ -33,303 +32,302 @@ public class DefaultAutoFetchManager implements AutoFetchManager, Serializable { private static final Logger logger = LoggerFactory.getLogger(DefaultAutoFetchManager.class); - private static final long serialVersionUID = -6826119882781771722L; + private static final long serialVersionUID = -6826119882781771722L; - @SuppressWarnings("RedundantStringConstructorCall") + @SuppressWarnings("RedundantStringConstructorCall") private final String statisticsMonitor = new String(); - private final String fileName; + private final String fileName; - /** - * Map of the usage and query statistics gathered. - */ - private final Map- * 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() { - if (garbageCollectionOnShutdown) { - collectUsageViaGC(-1); - serialize(); - } - } + public Iterator- * 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(msg, e); - return msg; - } - return updateTunedQueryInfo(); - } + public Iterator+ * 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() { + if (garbageCollectionOnShutdown) { + collectUsageViaGC(-1); + 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(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(); for (Statistics queryPointStatistics : statisticsMap.values()) { if (!queryPointStatistics.hasUsage()) { @@ -340,217 +338,222 @@ public class DefaultAutoFetchManager implements AutoFetchManager, Serializable { } } - String summaryInfo = counters.toString(); + String summaryInfo = counters.toString(); - if (counters.isInteresting()){ - // only log it if its interesting - logging.logSummary(summaryInfo); - } - - return summaryInfo; - } - } + if (counters.isInteresting()) { + // only log it if its interesting + logging.logSummary(summaryInfo); + } - private static class Counters { - - int newPlan; - int modified; - int unchanged; - int noUsage; - - void incrementNoUsage(){ - noUsage++; + 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) { + + // 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(); } - void incrementNew(){ - newPlan++; + + 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.logInfo(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()) { + // 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; + + } 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++; } - 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(); + return true; + } + } - try { - Class beanClass = ClassUtil.forName(beanType, this.getClass()); - BeanDescriptor beanDescriptor = server.getBeanDescriptor(beanClass); - if (beanDescriptor != null){ + return false; + } - // Determine the fetch plan from the latest statistics. - // Use this to compare with current "tuned fetch plan". - OrmQueryDetail newFetchDetail = statistics.buildTunedFetch(beanDescriptor); + /** + * 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, long beans, long micros) { - // get the current tuned fetch info... - TunedQueryInfo currentFetch = tunedQueryInfoMap.get(queryPoint.getKey()); + if (node != null) { + ObjectGraphOrigin origin = node.getOriginQueryPoint(); + if (origin != null) { + Statistics stats = getQueryPointStats(origin); + stats.collectQueryInfo(node, beans, micros); + } + } + } - if (currentFetch == null) { - // its a new fetch plan, add it. - counters.incrementNew(); + /** + * 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) { - currentFetch = statistics.createTunedFetch(newFetchDetail); - logging.logNew(currentFetch); - tunedQueryInfoMap.put(queryPoint.getKey(), currentFetch); + ObjectGraphOrigin origin = usageCollector.getNode().getOriginQueryPoint(); - } 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.logInfo(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()){ - // 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; - - } 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, long beans, long 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); + Statistics stats = getQueryPointStats(origin); if (logger.isTraceEnabled()) { logger.trace("... NodeUsageCollector " + usageCollector); @@ -563,22 +566,22 @@ public class DefaultAutoFetchManager implements AutoFetchManager, Serializable { } } - 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; - } - } + 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(); - } - } + public String toString() { + synchronized (statisticsMonitor) { + return statisticsMap.values().toString(); + } + } } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManagerLogging.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManagerLogging.java index 6823b33ef..f1cbb183b 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManagerLogging.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/DefaultAutoFetchManagerLogging.java @@ -17,27 +17,27 @@ import java.util.concurrent.TimeUnit; */ public class DefaultAutoFetchManagerLogging { - private static final Logger logger = LoggerFactory.getLogger(DefaultAutoFetchManagerLogging.class); + private static final Logger logger = LoggerFactory.getLogger(DefaultAutoFetchManagerLogging.class); - private final DefaultAutoFetchManager manager; + private final DefaultAutoFetchManager manager; - private final int updateFreqInSecs; - - public DefaultAutoFetchManagerLogging(ServerConfig serverConfig, DefaultAutoFetchManager profileListener) { + private final int updateFreqInSecs; - this.manager = profileListener; - this.updateFreqInSecs = serverConfig.getAutofetchConfig().getProfileUpdateFrequency(); - } - - public void init(SpiEbeanServer ebeanServer) { - ebeanServer.getBackgroundExecutor().executePeriodically(new UpdateProfile(), updateFreqInSecs, TimeUnit.SECONDS); - } + public DefaultAutoFetchManagerLogging(ServerConfig serverConfig, DefaultAutoFetchManager profileListener) { - private final class UpdateProfile implements Runnable { - public void run() { - manager.updateTunedQueryInfo(); - } - } + this.manager = profileListener; + this.updateFreqInSecs = serverConfig.getAutofetchConfig().getProfileUpdateFrequency(); + } + + public void init(SpiEbeanServer ebeanServer) { + ebeanServer.getBackgroundExecutor().executePeriodically(new UpdateProfile(), updateFreqInSecs, TimeUnit.SECONDS); + } + + private final class UpdateProfile implements Runnable { + public void run() { + manager.updateTunedQueryInfo(); + } + } public void logInfo(String msg, Throwable e) { logger.info(msg, e); @@ -47,21 +47,21 @@ public class DefaultAutoFetchManagerLogging { logger.error(msg, e); } - public void logSummary(String summaryInfo) { - - String msg = "\"Summary\",\""+summaryInfo+"\",,,,"; - logger.debug(msg); - } + public void logSummary(String summaryInfo) { - public void logChanged(TunedQueryInfo tunedFetch, OrmQueryDetail newQueryDetail) { - - String msg = tunedFetch.getLogOutput(newQueryDetail); - logger.debug(msg); - } + String msg = "\"Summary\",\"" + summaryInfo + "\",,,,"; + logger.debug(msg); + } - public void logNew(TunedQueryInfo tunedFetch) { + public void logChanged(TunedQueryInfo tunedFetch, OrmQueryDetail newQueryDetail) { - String msg = tunedFetch.getLogOutput(null); - logger.debug(msg); - } + String msg = tunedFetch.getLogOutput(newQueryDetail); + logger.debug(msg); + } + + public void logNew(TunedQueryInfo tunedFetch) { + + String msg = tunedFetch.getLogOutput(null); + logger.debug(msg); + } } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/Statistics.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/Statistics.java index eb6f7780f..a9625ca70 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/Statistics.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/Statistics.java @@ -1,10 +1,5 @@ package com.avaje.ebeaninternal.server.autofetch; -import java.io.Serializable; -import java.util.Collection; -import java.util.LinkedHashMap; -import java.util.Map; - import com.avaje.ebean.bean.NodeUsageCollector; import com.avaje.ebean.bean.ObjectGraphNode; import com.avaje.ebean.bean.ObjectGraphOrigin; @@ -13,115 +8,120 @@ import com.avaje.ebean.text.PathProperties.Props; import com.avaje.ebeaninternal.server.deploy.BeanDescriptor; import com.avaje.ebeaninternal.server.querydefn.OrmQueryDetail; +import java.io.Serializable; +import java.util.Collection; +import java.util.LinkedHashMap; +import java.util.Map; + public class Statistics implements Serializable { - private static final long serialVersionUID = -5586783791097230766L; + private static final long serialVersionUID = -5586783791097230766L; - private final ObjectGraphOrigin origin; + private final ObjectGraphOrigin origin; - private final boolean queryTuningAddVersion; - - private int counter; - - private final Map- * This tells us how much profiling we have done for this query. - * For example, after 100 times we may stop collecting more profiling info. - *
- */ - public int getCounter() { - return counter; - } - - /** - * Return true if this has usage statistics. - */ - public boolean hasUsage() { - synchronized (monitor) { - return !nodeUsageMap.isEmpty(); - } - } - - public OrmQueryDetail buildTunedFetch(BeanDescriptor rootDesc){ - - synchronized (monitor) { - if (nodeUsageMap.isEmpty()){ - return null; - } - - PathProperties pathProps = new PathProperties(); + public ObjectGraphOrigin getOrigin() { + return origin; + } + + public TunedQueryInfo createTunedFetch(OrmQueryDetail newFetchDetail) { + synchronized (monitor) { + // NB: create a copy of queryPoint allowing garbage + // collection of source... + return new TunedQueryInfo(origin, newFetchDetail, counter); + } + } + + /** + * Return the number of times the root query has executed. + *+ * This tells us how much profiling we have done for this query. + * For example, after 100 times we may stop collecting more profiling info. + *
+ */ + public int getCounter() { + return counter; + } + + /** + * Return true if this has usage statistics. + */ + public boolean hasUsage() { + synchronized (monitor) { + return !nodeUsageMap.isEmpty(); + } + } + + public OrmQueryDetail buildTunedFetch(BeanDescriptor rootDesc) { + + synchronized (monitor) { + if (nodeUsageMap.isEmpty()) { + return null; + } + + PathProperties pathProps = new PathProperties(); for (StatisticsNodeUsage statsNode : nodeUsageMap.values()) { statsNode.buildTunedFetch(pathProps, rootDesc); } - OrmQueryDetail detail = new OrmQueryDetail(); + OrmQueryDetail detail = new OrmQueryDetail(); - Collection