From 5c1de0a886c5b4ece437f6e74de698eb12ff7608 Mon Sep 17 00:00:00 2001 From: Robin Bygrave Date: Wed, 2 Sep 2015 09:28:17 +1200 Subject: [PATCH] WIP Autotune refactor --- .../server/autofetch/AutoTuneCollection.java | 101 ++++++++++ .../server/autofetch/AutoTuneStorage.java | 17 ++ .../server/autofetch/ProfilingListener.java | 12 ++ .../service/AutoTuneServiceFactory.java | 86 +------- .../service/BaseAutoTuneService.java | 26 +-- .../autofetch/service/BaseQueryTuner.java | 46 +---- .../DefaultAutoFetchManagerLogging.java | 67 ------- .../autofetch/service/ProfileManager.java | 51 ++--- .../autofetch/service/ProfileOrigin.java | 186 +++++++++--------- .../service/ProfileOriginNodeUsage.java | 18 +- .../autofetch/service/ProfileOriginQuery.java | 29 +-- .../autofetch/service/TunedQueryInfo.java | 136 +------------ .../server/core/InternalConfiguration.java | 2 +- .../server/querydefn/OrmQueryDetail.java | 2 +- .../server/autofetch/TunedQueryInfoTest.java | 20 +- .../cache/TestL2CacheWithSharedBean.java | 4 +- 16 files changed, 307 insertions(+), 496 deletions(-) create mode 100644 src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneCollection.java create mode 100644 src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneStorage.java delete mode 100644 src/main/java/com/avaje/ebeaninternal/server/autofetch/service/DefaultAutoFetchManagerLogging.java diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneCollection.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneCollection.java new file mode 100644 index 000000000..e26b892f1 --- /dev/null +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneCollection.java @@ -0,0 +1,101 @@ +package com.avaje.ebeaninternal.server.autofetch; + +import com.avaje.ebean.bean.ObjectGraphOrigin; +import com.avaje.ebeaninternal.server.querydefn.OrmQueryDetail; + +import java.util.ArrayList; +import java.util.List; + +/** + * Profiling information collected. + */ +public class AutoTuneCollection { + + List entries = new ArrayList(); + + public Entry add(ObjectGraphOrigin origin, OrmQueryDetail detail) { + Entry entry = new Entry(origin, detail); + entries.add(entry); + return entry; + } + + /** + * Profiling entry at a given origin point. + */ + public static class Entry { + + /** + * Profiling origin point. + */ + private final ObjectGraphOrigin origin; + + /** + * The tuned query detail. + */ + private final OrmQueryDetail detail; + + /** + * Summary execution statistics for queries related to this origin point. + */ + private final List queries = new ArrayList(); + + public Entry(ObjectGraphOrigin origin, OrmQueryDetail detail) { + this.origin = origin; + this.detail = detail; + } + + public void addQuery(EntryQuery entryQuery) { + queries.add(entryQuery); + } + + public ObjectGraphOrigin getOrigin() { + return origin; + } + + public OrmQueryDetail getDetail() { + return detail; + } + + public List getQueries() { + return queries; + } + + } + + /** + * Summary query execution statistics for the origin point. + */ + public static class EntryQuery { + + final String path; + final long exeCount; + final long totalBeanLoaded; + final long totalMicros; + + public EntryQuery(String path, long exeCount, long totalBeanLoaded, long totalMicros) { + this.path = path; + this.exeCount = exeCount; + this.totalBeanLoaded = totalBeanLoaded; + this.totalMicros = totalMicros; + } + + /** + * Return the relative path with empty string for the origin query. + */ + public String getPath() { + return path; + } + + public long getExeCount() { + return exeCount; + } + + public long getTotalBeanLoaded() { + return totalBeanLoaded; + } + + public long getTotalMicros() { + return totalMicros; + } + } +} diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneStorage.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneStorage.java new file mode 100644 index 000000000..831cdeee2 --- /dev/null +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/AutoTuneStorage.java @@ -0,0 +1,17 @@ +package com.avaje.ebeaninternal.server.autofetch; + +/** + * + */ +public interface AutoTuneStorage { + + /** + * Load and return the tuning information. + */ + AutoTuneCollection load(); + + /** + * Store the collected profiling information. + */ + void store(AutoTuneCollection profiling); +} diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/ProfilingListener.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/ProfilingListener.java index 9885f7435..ca496456f 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/ProfilingListener.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/ProfilingListener.java @@ -8,6 +8,18 @@ import com.avaje.ebean.bean.ObjectGraphNode; */ public interface ProfilingListener extends NodeUsageListener { + /** + * Collect summary statistics for a query executed for the given node. + * + * @param node the node relative to the origin point + * @param beans the number of beans loaded by the query + * @param micros the query execution in microseconds + */ void collectQueryInfo(ObjectGraphNode node, long beans, long micros); + /** + * Return true if this request should be profiled (based on the + * profiling ratio and collection count for this origin). + */ + boolean isProfileRequest(ObjectGraphNode origin); } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/AutoTuneServiceFactory.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/AutoTuneServiceFactory.java index 1e6c2d1cd..c0327c4fb 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/AutoTuneServiceFactory.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/AutoTuneServiceFactory.java @@ -3,94 +3,12 @@ package com.avaje.ebeaninternal.server.autofetch.service; import com.avaje.ebean.config.ServerConfig; import com.avaje.ebeaninternal.api.SpiEbeanServer; import com.avaje.ebeaninternal.server.autofetch.AutoTuneService; -import com.avaje.ebeaninternal.server.resource.ResourceManager; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -import javax.persistence.PersistenceException; -import java.io.File; -import java.io.FileInputStream; -import java.io.ObjectInputStream; public class AutoTuneServiceFactory { - private static final Logger logger = LoggerFactory.getLogger(AutoTuneServiceFactory.class); + public static AutoTuneService create(SpiEbeanServer server, ServerConfig serverConfig) { - public static AutoTuneService create(SpiEbeanServer server, ServerConfig serverConfig, ResourceManager resourceManager) { - - AutoTuneServiceFactory me = new AutoTuneServiceFactory(); - return me.createAutoFetchManager(server, serverConfig, resourceManager); - } - - private AutoTuneService createAutoFetchManager(SpiEbeanServer server, ServerConfig serverConfig, ResourceManager resourceManager) { - - AutoTuneService manager = createAutoFetchManager(server.getName(), resourceManager); - manager.setOwner(server, serverConfig); - - return manager; - } - - private AutoTuneService createAutoFetchManager(String serverName, ResourceManager resourceManager) { - - File autoFetchFile = getAutoFetchFile(serverName, resourceManager); - - AutoTuneService autoFetchManager = null; - - boolean readFile = !"false".equalsIgnoreCase(System.getProperty("autofetch.readfromfile")); - if (readFile) { - autoFetchManager = deserializeAutoFetch(autoFetchFile); - } - - if (autoFetchManager == null) { - // not deserialized from file so create as empty - // It will be populated automatically by querying the - // database meta data - autoFetchManager = new BaseAutoTuneService(autoFetchFile.getAbsolutePath()); - } - - return autoFetchManager; - } - - private AutoTuneService deserializeAutoFetch(File autoFetchFile) { - try { - - if (!autoFetchFile.exists()) { - return null; - } - FileInputStream fi = new FileInputStream(autoFetchFile); - ObjectInputStream ois = new ObjectInputStream(fi); - AutoTuneService profListener = (AutoTuneService) 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); + return new BaseAutoTuneService(server, serverConfig); } } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseAutoTuneService.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseAutoTuneService.java index 81ee660b7..9b4923276 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseAutoTuneService.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseAutoTuneService.java @@ -5,14 +5,10 @@ import com.avaje.ebean.config.ServerConfig; import com.avaje.ebeaninternal.api.SpiEbeanServer; import com.avaje.ebeaninternal.api.SpiQuery; import com.avaje.ebeaninternal.server.autofetch.AutoTuneService; +import com.avaje.ebeaninternal.server.autofetch.AutoTuneCollection; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import java.io.File; -import java.io.FileOutputStream; -import java.io.ObjectOutputStream; -import java.io.Serializable; - /** * Implementation of the AutoTuneService which is comprised of profiling and query tuning. */ @@ -26,11 +22,13 @@ public class BaseAutoTuneService implements AutoTuneService { private final BaseQueryTuner queryTuner; + private final ProfileManager profileManager; + public BaseAutoTuneService(SpiEbeanServer server, ServerConfig serverConfig) { AutofetchConfig config = serverConfig.getAutofetchConfig(); - ProfileManager profileManager = new ProfileManager(config, server); + this.profileManager = new ProfileManager(config, server); this.queryTuner = new BaseQueryTuner(config, server, profileManager); this.garbageCollectionOnShutdown = config.isGarbageCollectionOnShutdown(); @@ -42,24 +40,12 @@ public class BaseAutoTuneService implements AutoTuneService { */ public void startup() { -// 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(msg, e); -// } } private void saveProfiling() { + AutoTuneCollection autoTuneCollection = profileManager.profilingCollection(false); + } /** diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseQueryTuner.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseQueryTuner.java index a60f73fd9..6ad1fe2c0 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseQueryTuner.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/BaseQueryTuner.java @@ -19,16 +19,6 @@ public class BaseQueryTuner { private final boolean queryTuning; - /** - * Converted from a 0-100 int to a double. Effectively a percentage rate at - * which to collect profiling information. - */ - private final double profilingRate; - - private final int profilingBase; - - private final int profilingMin; - private boolean profiling; private final AutofetchMode mode; @@ -49,9 +39,6 @@ public class BaseQueryTuner { this.mode = config.getMode(); this.queryTuning = config.isQueryTuning(); this.profiling = config.isProfiling(); - this.profilingRate = config.getProfilingRate(); - this.profilingBase = config.getProfilingBase(); - this.profilingMin = config.getProfilingMin(); } /** @@ -70,13 +57,12 @@ public class BaseQueryTuner { return false; } - if (!useAutoFetch(query)) { + if (!useAutoTune(query)) { // not using autoFetch for this query return false; } - ObjectGraphNode parentAutoFetchNode = query.getParentNode(); - if (parentAutoFetchNode != null) { + if (query.getParentNode() != null) { // This is a +lazy/+query query with profiling on. // We continue to collect the profiling information. query.setProfilingListener(profilingListener); @@ -87,37 +73,25 @@ public class BaseQueryTuner { 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.setProfilingListener(profilingListener); - - } else if (profileCount < profilingBase) { - query.setProfilingListener(profilingListener); - - } else if (tunedFetch.isPercentageProfile(profilingRate)) { + if (profilingListener.isProfileRequest(origin)) { + // collect more profiling based on profiling rate etc query.setProfilingListener(profilingListener); } } - if (queryTuning && tunedFetch != null && profileCount >= profilingMin) { - // deemed to have enough profiling information for automatic tuning - return tunedFetch.autoFetchTune(query); + if (queryTuning) { + // get current "tuned fetch" for this query point + TunedQueryInfo tuneInfo = tunedQueryInfoMap.get(origin.getOriginQueryPoint().getKey()); + return tuneInfo != null && tuneInfo.tuneQuery(query); } - return false; } /** - * Return true if we should try to use autoFetch for this query. + * Return true if we should try to tune this query. */ - private boolean useAutoFetch(SpiQuery query) { + private boolean useAutoTune(SpiQuery query) { if (query.isLoadBeanCache()) { // when loading the cache don't tune the query diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/DefaultAutoFetchManagerLogging.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/DefaultAutoFetchManagerLogging.java deleted file mode 100644 index 8ba42bb6b..000000000 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/DefaultAutoFetchManagerLogging.java +++ /dev/null @@ -1,67 +0,0 @@ -package com.avaje.ebeaninternal.server.autofetch.service; - -import com.avaje.ebean.config.ServerConfig; -import com.avaje.ebeaninternal.api.SpiEbeanServer; -import com.avaje.ebeaninternal.server.querydefn.OrmQueryDetail; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -import java.util.concurrent.TimeUnit; - -/** - * Handles the logging aspects for the DefaultAutoFetchListener. - *

- * Note that java util logging loggers generally should not be serialised and - * that is one of the main reasons for pulling out the logging to this class. - *

- */ -public class DefaultAutoFetchManagerLogging { - - private static final Logger logger = LoggerFactory.getLogger(DefaultAutoFetchManagerLogging.class); - - private final BaseAutoTuneService manager; - - private final int updateFreqInSecs; - - public DefaultAutoFetchManagerLogging(ServerConfig serverConfig, BaseAutoTuneService profileListener) { - - 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); - } - - public void logError(String msg, Throwable e) { - logger.error(msg, e); - } - - public void logSummary(String summaryInfo) { - - String msg = "\"Summary\",\"" + summaryInfo + "\",,,,"; - logger.debug(msg); - } - - public void logChanged(TunedQueryInfo tunedFetch, OrmQueryDetail newQueryDetail) { - - 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/service/ProfileManager.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileManager.java index a9bada622..b76e66e47 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileManager.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileManager.java @@ -5,9 +5,9 @@ import com.avaje.ebean.bean.ObjectGraphNode; import com.avaje.ebean.bean.ObjectGraphOrigin; import com.avaje.ebean.config.AutofetchConfig; import com.avaje.ebeaninternal.api.SpiEbeanServer; +import com.avaje.ebeaninternal.server.autofetch.AutoTuneCollection; import com.avaje.ebeaninternal.server.autofetch.ProfilingListener; import com.avaje.ebeaninternal.server.deploy.BeanDescriptor; -import com.avaje.ebeaninternal.server.querydefn.OrmQueryDetail; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -23,7 +23,13 @@ public class ProfileManager implements ProfilingListener { private final boolean queryTuningAddVersion; - private final boolean profiling; + /** + * Converted from a 0-100 int to a double. Effectively a percentage rate at + * which to collect profiling information. + */ + private final double profilingRate; + + private final int profilingBase; /** * Map of the usage and query statistics gathered. @@ -36,10 +42,18 @@ public class ProfileManager implements ProfilingListener { public ProfileManager(AutofetchConfig config, SpiEbeanServer server) { this.server = server; - this.profiling = config.isProfiling(); + this.profilingRate = config.getProfilingRate(); + this.profilingBase = config.getProfilingBase(); this.queryTuningAddVersion = config.isQueryTuningAddVersion(); } + @Override + public boolean isProfileRequest(ObjectGraphNode origin) { + + ProfileOrigin profileOrigin = profileMap.get(origin.getOriginQueryPoint().getKey()); + return profileOrigin == null || profileOrigin.isProfile(); + } + /** * Gather query execution statistics. This could either be the originating * query in which case the parentNode will be null, or a lazy loading query @@ -73,40 +87,29 @@ public class ProfileManager implements ProfilingListener { synchronized (monitor) { ProfileOrigin stats = profileMap.get(originQueryPoint.getKey()); if (stats == null) { - stats = new ProfileOrigin(originQueryPoint, queryTuningAddVersion); + stats = new ProfileOrigin(originQueryPoint, queryTuningAddVersion, profilingBase, profilingRate); profileMap.put(originQueryPoint.getKey(), stats); } return stats; } } - /** - * Update the tuned fetch plans from the current usage information. + * Collect all the profiling information. */ - public void updateTunedQueryInfo() { + public AutoTuneCollection profilingCollection(boolean reset) { - if (!profiling) { - // we are not collecting any profiling information at - // the moment so don't try updating the tuned query plans. - return;// "Not profiling"; - } + AutoTuneCollection req = new AutoTuneCollection(); - synchronized (monitor) { + for (ProfileOrigin origin : profileMap.values()) { - for (ProfileOrigin origin : profileMap.values()) { - if (origin.hasUsage()) { - OrmQueryDetail ormQueryDetail = updateTunedQueryFromUsage(origin); - - } + BeanDescriptor desc = server.getBeanDescriptorById(origin.getOrigin().getBeanType()); + if (desc != null) { + origin.profilingCollection(desc, req, reset); } } + + return req; } - - private OrmQueryDetail updateTunedQueryFromUsage(ProfileOrigin statistics) { - - BeanDescriptor desc = server.getBeanDescriptorById(statistics.getOrigin().getBeanType()); - return desc == null ? null : statistics.buildTunedFetch(desc); - } } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOrigin.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOrigin.java index 959b740a2..84f758c0b 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOrigin.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOrigin.java @@ -5,106 +5,127 @@ import com.avaje.ebean.bean.ObjectGraphNode; import com.avaje.ebean.bean.ObjectGraphOrigin; import com.avaje.ebean.text.PathProperties; import com.avaje.ebean.text.PathProperties.Props; +import com.avaje.ebeaninternal.server.autofetch.AutoTuneCollection; 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; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.atomic.AtomicLong; -public class ProfileOrigin implements Serializable { +public class ProfileOrigin { - - private static final long serialVersionUID = -5586783791097230766L; + private static final long RESET_COUNT = -1000000000L; private final ObjectGraphOrigin origin; private final boolean queryTuningAddVersion; - private int counter; + private final int profilingBase; - private final Map queryStatsMap = new LinkedHashMap(); + private final double profilingRate; - private final Map nodeUsageMap = new LinkedHashMap(); + private final Map queryStatsMap = new ConcurrentHashMap(); - @SuppressWarnings("RedundantStringConstructorCall") - private final String monitor = new String(); + private final Map nodeUsageMap = new ConcurrentHashMap(); - public ProfileOrigin(ObjectGraphOrigin origin, boolean queryTuningAddVersion) { + private final Object monitor = new Object(); + + private final AtomicLong requestCount = new AtomicLong(); + + private final AtomicLong profileCount = new AtomicLong(); + + public ProfileOrigin(ObjectGraphOrigin origin, boolean queryTuningAddVersion, int profilingBase, double profilingRate) { this.origin = origin; this.queryTuningAddVersion = queryTuningAddVersion; + this.profilingBase = profilingBase; + this.profilingRate = profilingRate; } + /** + * Return true if this query should be profiled based on a percentage rate. + */ + public boolean isProfile() { + + long count = requestCount.incrementAndGet(); + if (count < profilingBase) { + return true; + } + long hits = profileCount.get(); + if (profilingRate > (double) hits / count) { + profileCount.incrementAndGet(); + return true; + } else { + return false; + } + } + + /** + * Collect profiling information with the option to reset the underlying profiling detail. + */ + public void profilingCollection(BeanDescriptor rootDesc, AutoTuneCollection req, boolean reset) { + + synchronized (monitor) { + if (nodeUsageMap.isEmpty()) { + return; + } + + OrmQueryDetail detail = buildDetail(rootDesc); + AutoTuneCollection.Entry entry = req.add(origin, detail); + + Collection values = queryStatsMap.values(); + for (ProfileOriginQuery queryEntry : values) { + entry.addQuery(queryEntry.createEntryQuery(reset)); + } + if (reset) { + nodeUsageMap.clear(); + if (requestCount.get() > RESET_COUNT) { + requestCount.set(profilingBase); + profileCount.set(0); + } + } + } + } + + private OrmQueryDetail buildDetail(BeanDescriptor rootDesc) { + PathProperties pathProps = new PathProperties(); + + for (ProfileOriginNodeUsage statsNode : nodeUsageMap.values()) { + statsNode.buildTunedFetch(pathProps, rootDesc); + } + + OrmQueryDetail detail = new OrmQueryDetail(); + + Collection pathProperties = pathProps.getPathProps(); + for (Props props : pathProperties) { + if (!props.isEmpty()) { + detail.addFetch(props.getPath(), props.getPropertiesAsString(), null); + } + } + + detail.sortFetchPaths(rootDesc); + return detail; + } + + /** + * Return the origin. + */ 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. + * Collect query execution summary statistics. *

- * This tells us how much profiling we have done for this query. - * For example, after 100 times we may stop collecting more profiling info. + * This can give us a quick overview into bad lazy loading areas etc. *

*/ - 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 (ProfileOriginNodeUsage statsNode : nodeUsageMap.values()) { - statsNode.buildTunedFetch(pathProps, rootDesc); - } - - OrmQueryDetail detail = new OrmQueryDetail(); - - Collection pathProperties = pathProps.getPathProps(); - for (Props props : pathProperties) { - if (!props.isEmpty()) { - detail.addFetch(props.getPath(), props.getPropertiesAsString(), null); - } - } - - detail.sortFetchPaths(rootDesc); - return detail; - } - } - - public void collectQueryInfo(ObjectGraphNode node, long beansLoaded, long micros) { String key = node.getPath(); if (key == null) { key = ""; - // this is basically the number of times the root query - // has executed which gives us an indication of how - // much profiling information we have gathered. - counter++; } ProfileOriginQuery stats = queryStatsMap.get(key); @@ -116,7 +137,6 @@ public class ProfileOrigin implements Serializable { stats.add(beansLoaded, micros); } - /** * Collect the usage information for from a instance for this node. */ @@ -126,7 +146,7 @@ public class ProfileOrigin implements Serializable { ObjectGraphNode node = profile.getNode(); ProfileOriginNodeUsage nodeStats = getNodeStats(node.getPath()); - nodeStats.publish(profile); + nodeStats.collectUsageInfo(profile); } } @@ -142,32 +162,4 @@ public class ProfileOrigin implements Serializable { } } -// public String getUsageDebug() { -// synchronized (monitor) { -// StringBuilder sb = new StringBuilder(); -// sb.append("root[").append(origin.getBeanType()).append("] "); -// for (ProfileOriginNodeUsage node : nodeUsageMap.values()) { -// sb.append(node.toString()).append("\n"); -// } -// return sb.toString(); -// } -// } -// -// public String getQueryStatDebug() { -// synchronized (monitor) { -// StringBuilder sb = new StringBuilder(); -// for (ProfileOriginQuery queryStat : queryStatsMap.values()) { -// sb.append(queryStat.toString()).append("\n"); -// } -// return sb.toString(); -// } -// } -// -// public String toString() { -// -// synchronized (monitor) { -// return getUsageDebug(); -// } -// } - } diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginNodeUsage.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginNodeUsage.java index a051bc31f..632ac8097 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginNodeUsage.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginNodeUsage.java @@ -10,22 +10,17 @@ import com.avaje.ebeaninternal.server.query.SplitName; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import java.io.Serializable; -import java.util.HashSet; import java.util.LinkedHashSet; import java.util.Set; /** * Collects usages statistics for a given node in the object graph. */ -public class ProfileOriginNodeUsage implements Serializable { - - private static final long serialVersionUID = -1663951463963779547L; +public class ProfileOriginNodeUsage { private static final Logger logger = LoggerFactory.getLogger(ProfileOriginNodeUsage.class); - @SuppressWarnings("RedundantStringConstructorCall") - private final String monitor = new String(); + private final Object monitor = new Object(); private final String path; @@ -53,7 +48,7 @@ public class ProfileOriginNodeUsage implements Serializable { ElPropertyValue elGetValue = rootDesc.getElGetValue(path); if (elGetValue == null) { desc = null; - logger.warn("Autofetch: Can't find join for path[" + path + "] for " + rootDesc.getName()); + logger.warn("AutoTune: Can't find join for path[" + path + "] for " + rootDesc.getName()); } else { BeanProperty beanProperty = elGetValue.getBeanProperty(); @@ -66,7 +61,7 @@ public class ProfileOriginNodeUsage implements Serializable { for (String propName : aggregateUsed) { BeanProperty beanProp = desc.getBeanPropertyFromPath(propName); if (beanProp == null) { - logger.warn("Autofetch: Can't find property[" + propName + "] for " + desc.getName()); + logger.warn("AutoTune: Can't find property[" + propName + "] for " + desc.getName()); } else { if (beanProp instanceof BeanPropertyAssoc) { @@ -95,7 +90,10 @@ public class ProfileOriginNodeUsage implements Serializable { } } - public void publish(NodeUsageCollector profile) { + /** + * Collect usage from a node. + */ + public void collectUsageInfo(NodeUsageCollector profile) { synchronized (monitor) { diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginQuery.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginQuery.java index b4d2b6bfa..344d040dc 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginQuery.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/ProfileOriginQuery.java @@ -1,9 +1,12 @@ package com.avaje.ebeaninternal.server.autofetch.service; +import com.avaje.ebeaninternal.server.autofetch.AutoTuneCollection; +import com.avaje.ebeaninternal.server.util.LongAdder; + import java.io.Serializable; /** - * Used to accumulate query execution statistics. + * Used to accumulate query execution statistics for paths relative to the origin query. */ public class ProfileOriginQuery implements Serializable { @@ -11,26 +14,30 @@ public class ProfileOriginQuery implements Serializable { private final String path; - private long exeCount; + private final LongAdder exeCount = new LongAdder(); - private long totalBeanLoaded; + private final LongAdder totalBeanLoaded = new LongAdder(); - private long totalMicros; + private final LongAdder totalMicros = new LongAdder(); public ProfileOriginQuery(String path) { this.path = path; } public void add(long beansLoaded, long micros) { - exeCount++; - totalBeanLoaded += beansLoaded; - totalMicros += micros; + exeCount.increment(); + totalBeanLoaded.add(beansLoaded); + totalMicros.add(micros); } - public String toString() { - long avgMicros = exeCount == 0 ? 0 : totalMicros / exeCount; + public AutoTuneCollection.EntryQuery createEntryQuery(boolean reset){ - return "queryExe path[" + path + "] count[" + exeCount + "] totalBeansLoaded[" + totalBeanLoaded + "] avgMicros[" - + avgMicros + "] totalMicros[" + totalMicros + "]"; + if (reset) { + return new AutoTuneCollection.EntryQuery(path, exeCount.sumThenReset(), totalBeanLoaded.sumThenReset(), totalMicros.sumThenReset()); + + } else { + return new AutoTuneCollection.EntryQuery(path, exeCount.sum(), totalBeanLoaded.sum(), totalMicros.sum()); + } } + } \ No newline at end of file diff --git a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/TunedQueryInfo.java b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/TunedQueryInfo.java index 8a6a5d046..b1e554cbd 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/TunedQueryInfo.java +++ b/src/main/java/com/avaje/ebeaninternal/server/autofetch/service/TunedQueryInfo.java @@ -12,90 +12,13 @@ import java.io.Serializable; */ public class TunedQueryInfo implements Serializable { - private static final long serialVersionUID = 7381493228797997282L; - private final ObjectGraphOrigin origin; - /** - * The tuned query details with joins and properties. - */ - private OrmQueryDetail tunedDetail; + private final OrmQueryDetail tunedDetail; - /** - * The number of times profiling has been collected for this query point. - */ - private int profileCount; - - private Long lastTuneTime = (long) 0; - - @SuppressWarnings("RedundantStringConstructorCall") - private final String rateMonitor = new String(); - - /** - * The number of queries tuned by this object. - * Could use AtomicInteger perhaps. - */ - private transient int tunedCount; - - private transient int rateTotal; - - private transient int rateHits; - - private transient double lastRate; - - public TunedQueryInfo(ObjectGraphOrigin queryPoint, OrmQueryDetail tunedDetail, int profileCount) { + public TunedQueryInfo(ObjectGraphOrigin queryPoint, OrmQueryDetail tunedDetail) { this.origin = queryPoint; this.tunedDetail = tunedDetail; - this.profileCount = profileCount; - } - - /** - * Return true if this query should be profiled based on a percentage rate. - */ - public boolean isPercentageProfile(double rate) { - - synchronized (rateMonitor) { - - if (lastRate != rate) { - // the rate has changed so resetting - lastRate = rate; - rateTotal = 0; - rateHits = 0; - } - - rateTotal++; - if (rate > (double) rateHits / rateTotal) { - rateHits++; - return true; - } else { - return false; - } - } - } - - /** - * Set the number of times profiling has been collected for this query - * point. - */ - public void setProfileCount(int profileCount) { - // int assignment is atomic - this.profileCount = profileCount; - } - - /** - * Set the tuned query detail. - */ - public void setTunedDetail(OrmQueryDetail tunedDetail) { - // assignment is atomic - this.tunedDetail = tunedDetail; - this.lastTuneTime = System.currentTimeMillis(); - } - - /** - * Return true if the fetches are essentially the same. - */ - public boolean isSame(OrmQueryDetail newQueryDetail) { - return tunedDetail != null && tunedDetail.isAutoFetchEqual(newQueryDetail); } /** @@ -103,13 +26,12 @@ public class TunedQueryInfo implements Serializable { * * @return true if the query was tuned, otherwise false. */ - public boolean autoFetchTune(SpiQuery query) { + public boolean tuneQuery(SpiQuery query) { if (tunedDetail == null) { return false; } boolean tuned; - //Note: tunedDetail is immutable by convention if (query.isDetailEmpty()) { tuned = true; // tune by 'replacement' @@ -120,62 +42,10 @@ public class TunedQueryInfo implements Serializable { } if (tuned) { query.setAutoFetchTuned(true); - // a case for AtomicInteger but good enough for statistics - tunedCount++; } return tuned; } - /** - * Return the time of the last tune. - */ - public Long getLastTuneTime() { - return lastTuneTime; - } - - /** - * Return the number of queries tuned by this object. - */ - public int getTunedCount() { - return tunedCount; - } - - /** - * Return the number of times profiling has been collected for this query - * point. - */ - public int getProfileCount() { - return profileCount; - } - - public OrmQueryDetail getTunedDetail() { - return tunedDetail; - } - - public ObjectGraphOrigin getOrigin() { - return origin; - } - - public String getLogOutput(OrmQueryDetail newQueryDetail) { - - boolean changed = newQueryDetail != null; - - StringBuilder sb = new StringBuilder(150); - sb.append(changed ? "\"Changed\"," : "\"New\","); - sb.append("\"").append(origin.getBeanType()).append("\","); - sb.append("\"").append(origin.getKey()).append("\","); - if (changed) { - sb.append("\"to: ").append(newQueryDetail.toString()).append("\","); - sb.append("\"from: ").append(tunedDetail.toString()).append("\","); - } else { - sb.append("\"to: ").append(tunedDetail.toString()).append("\","); - sb.append("\"\","); - } - sb.append("\"").append(origin.getFirstStackElement()).append("\""); - - return sb.toString(); - } - public String toString() { return origin.getBeanType() + " " + origin.getKey() + " " + tunedDetail; } diff --git a/src/main/java/com/avaje/ebeaninternal/server/core/InternalConfiguration.java b/src/main/java/com/avaje/ebeaninternal/server/core/InternalConfiguration.java index c1148d0cf..62c1e2470 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/core/InternalConfiguration.java +++ b/src/main/java/com/avaje/ebeaninternal/server/core/InternalConfiguration.java @@ -236,7 +236,7 @@ public class InternalConfiguration { } public AutoTuneService createAutoFetchManager(SpiEbeanServer server) { - return AutoTuneServiceFactory.create(server, serverConfig, resourceManager); + return AutoTuneServiceFactory.create(server, serverConfig); } public RelationalQueryEngine createRelationalQueryEngine() { diff --git a/src/main/java/com/avaje/ebeaninternal/server/querydefn/OrmQueryDetail.java b/src/main/java/com/avaje/ebeaninternal/server/querydefn/OrmQueryDetail.java index b7a2885d8..a65edfa16 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/querydefn/OrmQueryDetail.java +++ b/src/main/java/com/avaje/ebeaninternal/server/querydefn/OrmQueryDetail.java @@ -82,7 +82,7 @@ public class OrmQueryDetail implements Serializable { /** * Return true if equal in terms of autofetch (select and joins). */ - public boolean isAutoFetchEqual(OrmQueryDetail otherDetail) { + public boolean isAutoTuneEqual(OrmQueryDetail otherDetail) { return autofetchPlanHash() == otherDetail.autofetchPlanHash(); } diff --git a/src/test/java/com/avaje/ebeaninternal/server/autofetch/TunedQueryInfoTest.java b/src/test/java/com/avaje/ebeaninternal/server/autofetch/TunedQueryInfoTest.java index eaf1ec8be..a27881bc5 100644 --- a/src/test/java/com/avaje/ebeaninternal/server/autofetch/TunedQueryInfoTest.java +++ b/src/test/java/com/avaje/ebeaninternal/server/autofetch/TunedQueryInfoTest.java @@ -41,11 +41,11 @@ public class TunedQueryInfoTest extends BaseTestCase { OrmQueryDetail tunedDetail = new OrmQueryDetail(); tunedDetail.select(null); - TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail, 0); + TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail); Query query = server.find(Order.class).setId(1); - tunedInfo.autoFetchTune((SpiQuery)query); + tunedInfo.tuneQuery((SpiQuery) query); Order order = query.findUnique(); EntityBean eb = (EntityBean)order; @@ -69,11 +69,11 @@ public class TunedQueryInfoTest extends BaseTestCase { OrmQueryDetail tunedDetail = new OrmQueryDetail(); tunedDetail.select(""); - TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail, 0); + TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail); Query query = server.find(Order.class).setId(1); - tunedInfo.autoFetchTune((SpiQuery)query); + tunedInfo.tuneQuery((SpiQuery) query); Order order = query.findUnique(); EntityBean eb = (EntityBean)order; @@ -96,11 +96,11 @@ public class TunedQueryInfoTest extends BaseTestCase { OrmQueryDetail tunedDetail = new OrmQueryDetail(); tunedDetail.select("somethingThatDoesNotExist"); - TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail, 0); + TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail); Query query = server.find(Order.class).setId(1); - tunedInfo.autoFetchTune((SpiQuery)query); + tunedInfo.tuneQuery((SpiQuery) query); LoggedSqlCollector.start(); @@ -132,11 +132,11 @@ public class TunedQueryInfoTest extends BaseTestCase { OrmQueryDetail tunedDetail = new OrmQueryDetail(); tunedDetail.select("status, customer"); - TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail, 0); + TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail); Query query = server.find(Order.class).setId(1); - tunedInfo.autoFetchTune((SpiQuery)query); + tunedInfo.tuneQuery((SpiQuery) query); LoggedSqlCollector.start(); @@ -167,11 +167,11 @@ public class TunedQueryInfoTest extends BaseTestCase { OrmQueryDetail tunedDetail = new OrmQueryDetail(); tunedDetail.select("status"); - TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail, 0); + TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail); Query query = server.find(Order.class).setId(1); - tunedInfo.autoFetchTune((SpiQuery)query); + tunedInfo.tuneQuery((SpiQuery) query); LoggedSqlCollector.start(); diff --git a/src/test/java/com/avaje/tests/cache/TestL2CacheWithSharedBean.java b/src/test/java/com/avaje/tests/cache/TestL2CacheWithSharedBean.java index a31184917..c3367d686 100644 --- a/src/test/java/com/avaje/tests/cache/TestL2CacheWithSharedBean.java +++ b/src/test/java/com/avaje/tests/cache/TestL2CacheWithSharedBean.java @@ -28,11 +28,11 @@ public class TestL2CacheWithSharedBean extends BaseTestCase { OrmQueryDetail tunedDetail = new OrmQueryDetail(); tunedDetail.select("name"); - TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail, 0); + TunedQueryInfo tunedInfo = new TunedQueryInfo(null, tunedDetail); Query query = Ebean.find(FeatureDescription.class).setId(f1.getId()); - tunedInfo.autoFetchTune((SpiQuery) query); + tunedInfo.tuneQuery((SpiQuery) query); query.findUnique(); // PUT into cache