#1924 - Refactor for Transaction profiling - base on ProfileLocation / remove profileId

This commit is contained in:
rob bygrave
2020-02-01 11:31:43 +13:00
parent 840cb2ee7b
commit 9eab67d82e
31 changed files with 144 additions and 214 deletions
+17 -2
View File
@@ -31,9 +31,9 @@ public interface ProfileLocation {
}
/**
* Obtain the location description.
* Obtain the description returning true if this is the initial call.
*/
String obtain();
boolean obtain();
/**
* Return a short version of the location description.
@@ -45,8 +45,23 @@ public interface ProfileLocation {
*/
String label();
/**
* Return the full location.
*/
String fullLocation();
/**
* Add execution time.
*/
void add(long executionTime);
/**
* Return true if this request should be traced.
*/
boolean trace();
/**
* Set the number of times to trace the transactions for this profile location.
*/
void setTraceCount(int traceCount);
}
-11
View File
@@ -1524,17 +1524,6 @@ public interface Query<T> {
return setUseQueryCache(enabled ? CacheMode.ON : CacheMode.OFF);
}
/**
* Set an id to identify this query for profiling purposes.
* <p>
* The profileId is expected to be unique for a given bean type.
* </p>
* <p>
* Note that the profileId is treated as a short internally and has a MAX value of 32,767.
* </p>
*/
Query<T> setProfileId(int profileId);
/**
* Set the profile location of this query. This is used to relate query execution metrics
* back to a location like a specific line of code.
@@ -25,11 +25,6 @@ public interface BeanType<T> {
@Nonnull
String getName();
/**
* Return the profileId of the bean type.
*/
short getProfileId();
/**
* Return the full name of the bean type.
*/
@@ -1,5 +1,6 @@
package io.ebeaninternal.api;
import io.ebean.ProfileLocation;
import io.ebeaninternal.server.transaction.ProfileStream;
import io.ebeaninternal.server.transaction.TransactionProfile;
@@ -24,7 +25,7 @@ public interface SpiProfileHandler {
* Create a profiling stream if we are profiling this transaction.
* Return null if we are not profiling this transaction.
*
* @param profileId The transaction profileId
* @param location The profile location
*/
ProfileStream createProfileStream(int profileId);
ProfileStream createProfileStream(ProfileLocation location);
}
@@ -191,7 +191,7 @@ public interface SpiQuery<T> extends Query<T>, TxnProfileEventCodes {
/**
* Return the id used to identify a particular query for the given bean type.
*/
short getProfileId();
String getProfileId();
/**
* Return the profile location for this query.
@@ -90,8 +90,8 @@ public abstract class PersistRequest extends BeanRequest implements BatchPostExe
*/
public abstract int executeNow();
void profileBase(String event, long offset, short beanTypeId, int beanCount) {
transaction.profileStream().addPersistEvent(event, offset, beanTypeId, beanCount);
void profileBase(String event, long offset, String beanName, int beanCount) {
transaction.profileStream().addPersistEvent(event, offset, beanName, beanCount);
}
@Override
@@ -244,7 +244,7 @@ public final class PersistRequestBean<T> extends PersistRequest implements BeanP
*/
@Override
public void profile(long offset, int flushCount) {
profileBase(type.profileEventId, offset, beanDescriptor.getProfileId(), flushCount);
profileBase(type.profileEventId, offset, beanDescriptor.getName(), flushCount);
}
/**
@@ -1332,7 +1332,7 @@ public final class PersistRequestBean<T> extends PersistRequest implements BeanP
*/
@Override
public void profile() {
profileBase(type.profileEventId, profileOffset, beanDescriptor.getProfileId(), 1);
profileBase(type.profileEventId, profileOffset, beanDescriptor.getName(), 1);
}
/**
@@ -40,7 +40,7 @@ public final class PersistRequestCallableSql extends PersistRequest {
@Override
public void profile(long offset, int flushCount) {
profileBase(EVT_CALLABLESQL, offset, (short)0, flushCount);
profileBase(EVT_CALLABLESQL, offset, "", flushCount);
}
@Override
@@ -34,7 +34,7 @@ public final class PersistRequestOrmUpdate extends PersistRequest {
@Override
public void profile(long offset, int flushCount) {
profileBase(EVT_ORMUPDATE, offset, beanDescriptor.getProfileId(), flushCount);
profileBase(EVT_ORMUPDATE, offset, beanDescriptor.getName(), flushCount);
}
public BeanDescriptor<?> getBeanDescriptor() {
@@ -51,7 +51,7 @@ public final class PersistRequestUpdateSql extends PersistRequest {
@Override
public void profile(long offset, int flushCount) {
profileBase(EVT_UPDATESQL, offset, (short) 0, flushCount);
profileBase(EVT_UPDATESQL, offset, "", flushCount);
}
/**
@@ -139,8 +139,6 @@ public class BeanDescriptor<T> implements BeanType<T>, STreeType {
private final Map<String, String> namedQuery;
private final short profileBeanId;
private final boolean multiValueSupported;
private boolean batchEscalateOnCascadeInsert;
private boolean batchEscalateOnCascadeDelete;
@@ -441,7 +439,6 @@ public class BeanDescriptor<T> implements BeanType<T>, STreeType {
this.name = InternString.intern(deploy.getName());
this.baseTableAlias = "t0";
this.fullName = InternString.intern(deploy.getFullName());
this.profileBeanId = deploy.getProfileId();
this.beanType = deploy.getBeanType();
this.rootBeanType = PersistenceContextUtil.root(beanType);
this.prototypeEntityBean = createPrototypeEntityBean(beanType);
@@ -571,14 +568,6 @@ public class BeanDescriptor<T> implements BeanType<T>, STreeType {
}
}
/**
* Return the id used in profiling to identify the bean type.
*/
@Override
public short getProfileId() {
return profileBeanId;
}
/**
* Derive an array of property positions for properties that are initialised in the constructor.
* These properties need to be unloaded when populating beans for queries.
@@ -787,13 +787,6 @@ public class BeanDescriptorManager implements BeanDescriptorMap {
.collect(Collectors.toList());
deployDescriptors.sort(Comparator.comparing(DeployBeanDescriptor::getFullName));
short id = 0;
for (DeployBeanDescriptor<?> desc : deployDescriptors) {
if (!desc.isEmbedded()) {
desc.setProfileId(++id);
}
}
}
/**
@@ -214,8 +214,6 @@ public class DeployBeanDescriptor<T> {
private DeployBeanProperty idProperty;
private TableJoin primaryKeyJoin;
private short profileId;
private Object jacksonAnnotatedClass;
/**
@@ -688,20 +686,6 @@ public class DeployBeanDescriptor<T> {
setBaseTable(new TableName(viewName), "", "");
}
/**
* Set the profileId to identity this bean type.
*/
public void setProfileId(short profileId) {
this.profileId = profileId;
}
/**
* Return the profileId to identify this bean type.
*/
public short getProfileId() {
return profileId;
}
/**
* Set the base table. Only properties mapped to the base table are by default persisted.
*/
@@ -28,8 +28,8 @@ final class BasicProfileLocation implements ProfileLocation {
}
@Override
public String obtain() {
return fullLocation;
public boolean obtain() {
return false;
}
@Override
@@ -42,6 +42,21 @@ final class BasicProfileLocation implements ProfileLocation {
return location;
}
@Override
public String fullLocation() {
return fullLocation;
}
@Override
public boolean trace() {
return false;
}
@Override
public void setTraceCount(int traceCount) {
// do nothing
}
private String shortDesc(String location) {
int lastPer = location.lastIndexOf('.');
if (lastPer > -1) {
@@ -19,6 +19,8 @@ class DProfileLocation implements ProfileLocation {
private final int lineNumber;
private int traceCount;
DProfileLocation() {
this(0);
}
@@ -41,17 +43,18 @@ class DProfileLocation implements ProfileLocation {
}
@Override
public String obtain() {
public boolean obtain() {
// atomic assignments so happy enough with this (racing but atomic)
if (fullLocation == null) {
final String loc = create();
final String shortDesc = shortDesc(loc);
label = UtilLocation.label(shortDesc);
location = shortDesc;
fullLocation = loc;
initWith(label);
if (fullLocation != null) {
return false;
}
return fullLocation;
final String loc = create();
final String shortDesc = shortDesc(loc);
label = UtilLocation.label(shortDesc);
location = shortDesc;
fullLocation = loc;
initWith(label);
return true;
}
protected void initWith(String label) {
@@ -68,6 +71,26 @@ class DProfileLocation implements ProfileLocation {
return location;
}
@Override
public String fullLocation() {
return fullLocation;
}
@Override
public boolean trace() {
// racey but atomic and no problem with over or under tracing
if (traceCount <= 0) {
return false;
} else {
traceCount--;
return true;
}
}
public void setTraceCount(int traceCount) {
this.traceCount = traceCount;
}
private String create() {
// relatively expensive but we only do it once per profile location
StackTraceElement[] trace = Thread.currentThread().getStackTrace();
@@ -614,7 +614,7 @@ public class CQuery<T> implements DbReadContext, CancelableQuery, SpiProfileTran
public void profile() {
getTransaction()
.profileStream()
.addQueryEvent(query.profileEventId(), profileOffset, desc.getProfileId(), loadedBeanCount, query.getProfileId());
.addQueryEvent(query.profileEventId(), profileOffset, desc.getName(), loadedBeanCount, query.getProfileId());
}
QueryIterator<T> readIterate(int bufferSize, OrmQueryRequest<T> request) {
@@ -189,7 +189,7 @@ class CQueryFetchSingleAttribute implements SpiProfileTransactionEvent {
public void profile() {
getTransaction()
.profileStream()
.addQueryEvent(query.profileEventId(), profileOffset, desc.getProfileId(), rowCount, query.getProfileId());
.addQueryEvent(query.profileEventId(), profileOffset, desc.getName(), rowCount, query.getProfileId());
}
Set<String> getDependentTables() {
@@ -155,7 +155,7 @@ class CQueryRowCount implements SpiProfileTransactionEvent {
public void profile() {
getTransaction()
.profileStream()
.addQueryEvent(query.profileEventId(), profileOffset, desc.getProfileId(), rowCount, query.getProfileId());
.addQueryEvent(query.profileEventId(), profileOffset, desc.getName(), rowCount, query.getProfileId());
}
Set<String> getDependentTables() {
@@ -120,6 +120,6 @@ class CQueryUpdate implements SpiProfileTransactionEvent {
public void profile() {
getTransaction()
.profileStream()
.addQueryEvent(query.profileEventId(), profileOffset, desc.getProfileId(), rowCount, query.getProfileId());
.addQueryEvent(query.profileEventId(), profileOffset, desc.getName(), rowCount, query.getProfileId());
}
}
@@ -120,11 +120,6 @@ class DefaultFetchGroupQuery<T> implements SpiFetchGroupQuery<T> {
return this;
}
@Override
public Query<T> setProfileId(int profileId) {
return this;
}
@Override
public Query<T> setProfileLocation(ProfileLocation profileLocation) {
return this;
@@ -283,11 +283,6 @@ public class DefaultOrmQuery<T> implements SpiQuery<T> {
private boolean orderById;
/**
* Identity the query for profiling purposes (expected to be unique for a bean type).
*/
private short profileId;
private ProfileLocation profileLocation;
public DefaultOrmQuery(BeanDescriptor<T> desc, SpiEbeanServer server, ExpressionFactory expressionFactory) {
@@ -350,14 +345,8 @@ public class DefaultOrmQuery<T> implements SpiQuery<T> {
}
@Override
public short getProfileId() {
return profileId;
}
@Override
public Query<T> setProfileId(int profileId) {
this.profileId = (short) profileId;
return this;
public String getProfileId() {
return getPlanLabel();
}
@Override
@@ -1,7 +1,7 @@
package io.ebeaninternal.server.transaction;
import io.ebean.ProfileLocation;
import io.ebean.config.ProfilingConfig;
import io.ebean.plugin.BeanType;
import io.ebean.plugin.Plugin;
import io.ebean.plugin.SpiServer;
import io.ebeaninternal.api.SpiProfileHandler;
@@ -34,10 +34,8 @@ import static java.time.temporal.ChronoField.YEAR;
* Default profile handler.
* <p>
* Uses ConcurrentLinkedQueue to minimise contention on threads calling collectTransactionProfile().
* </p>
* <p>
* Uses a sleep backoff on the single threaded consumer that reads the profiles and writes them to files.
* </p>
*/
public class DefaultProfileHandler implements SpiProfileHandler, Plugin {
@@ -71,8 +69,6 @@ public class DefaultProfileHandler implements SpiProfileHandler, Plugin {
private final long minMicros;
private final int[] includeIds;
private final long profilesPerFile;
private final boolean verbose;
@@ -91,7 +87,6 @@ public class DefaultProfileHandler implements SpiProfileHandler, Plugin {
public DefaultProfileHandler(ProfilingConfig config) {
this.verbose = config.isVerbose();
this.minMicros = config.getMinimumMicros();
this.includeIds = config.getIncludeProfileIds();
this.profilesPerFile = config.getProfilesPerFile();
// dedicated single threaded executor for consuming the
@@ -114,28 +109,11 @@ public class DefaultProfileHandler implements SpiProfileHandler, Plugin {
}
/**
* Create and return a ProfileStream if we are profiling for the given transaction profileId.
* Create and return a ProfileStream.
*/
@Override
public ProfileStream createProfileStream(int profileId) {
if (profileId < 1) {
// not this transaction
return null;
}
if (includeIds.length == 0) {
return new DefaultProfileStream(profileId, verbose);
}
// check if we are profiling this specific transaction profileId, just
// perform linear search as this is expected to be a small array
for (int includeId : includeIds) {
if (includeId == profileId) {
return new DefaultProfileStream(profileId, verbose);
}
}
return null;
public ProfileStream createProfileStream(ProfileLocation location) {
return new DefaultProfileStream(location, verbose);
}
private void flushCurrentFile() {
@@ -199,7 +177,7 @@ public class DefaultProfileHandler implements SpiProfileHandler, Plugin {
// header
sb.append(profile.getStartTime()).append(' ')
.append(profile.getProfileId()).append(' ')
.append(profile.getLabel()).append(' ')
.append(profile.getTotalMicros()).append(' ');
// summary
@@ -268,14 +246,7 @@ public class DefaultProfileHandler implements SpiProfileHandler, Plugin {
@Override
public void configure(SpiServer server) {
StringBuilder sb = new StringBuilder(200);
sb.append("Bean profile mapping - ");
for (BeanType<?> type : server.getBeanTypes()) {
sb.append("profileId:").append(type.getProfileId())
.append(" ").append(type.getName()).append(", ");
}
log.info(sb.toString());
// do nothing
}
@Override
@@ -1,5 +1,7 @@
package io.ebeaninternal.server.transaction;
import io.ebean.ProfileLocation;
/**
* Default transaction profiling event collection.
*/
@@ -10,9 +12,9 @@ public class DefaultProfileStream implements ProfileStream {
private final TransactionProfile profile;
private final TransactionProfile.Summary summary;
DefaultProfileStream(int profId, boolean verbose) {
DefaultProfileStream(ProfileLocation location, boolean verbose) {
this.startNanos = System.nanoTime();
this.profile = new TransactionProfile(System.currentTimeMillis(), profId);
this.profile = new TransactionProfile(System.currentTimeMillis(), location);
this.summary = profile.getSummary();
this.buffer = (verbose) ? new StringBuilder(200) : null;
}
@@ -33,11 +35,11 @@ public class DefaultProfileStream implements ProfileStream {
* Add a query execution event.
*/
@Override
public void addQueryEvent(String event, long offset, short beanTypeId, int beanCount, short queryId) {
public void addQueryEvent(String event, long offset, String beanName, int beanCount, String queryId) {
long micros = exeMicros(offset);
summary.addQuery(micros, beanCount);
if (buffer != null) {
add(micros, event, offset, beanTypeId, beanCount, queryId);
add(micros, event, offset, beanName, beanCount, queryId);
}
}
@@ -45,11 +47,11 @@ public class DefaultProfileStream implements ProfileStream {
* Add a persist event.
*/
@Override
public void addPersistEvent(String event, long offset, short beanTypeId, int beanCount) {
public void addPersistEvent(String event, long offset, String beanName, int beanCount) {
long micros = exeMicros(offset);
summary.addPersist(micros, beanCount);
if (buffer != null) {
add(micros, event, offset, beanTypeId, beanCount, (short) 0);
add(micros, event, offset, beanName, beanCount, "");
}
}
@@ -67,11 +69,11 @@ public class DefaultProfileStream implements ProfileStream {
}
}
private void add(long micros, String event, long offset, short beanTypeId, int beanCount, short queryId) {
private void add(long micros, String event, long offset, String beanName, int beanCount, String queryId) {
buffer.append(event).append(',');
buffer.append(offset).append(',');
buffer.append(micros).append(',');
buffer.append(beanTypeId).append(',');
buffer.append(beanName).append(',');
buffer.append(beanCount).append(',');
buffer.append(queryId).append(";");
}
@@ -81,7 +83,6 @@ public class DefaultProfileStream implements ProfileStream {
*/
@Override
public void end(TransactionManager manager) {
profile.setTotalMicros(offset());
if (buffer != null) {
profile.setData(buffer.toString());
@@ -1,5 +1,6 @@
package io.ebeaninternal.server.transaction;
import io.ebean.ProfileLocation;
import io.ebeaninternal.api.SpiProfileHandler;
/**
@@ -13,7 +14,7 @@ public class NoopProfileHandler implements SpiProfileHandler {
}
@Override
public ProfileStream createProfileStream(int profileId) {
public ProfileStream createProfileStream(ProfileLocation location) {
// always return null
return null;
}
@@ -13,12 +13,12 @@ public interface ProfileStream {
/**
* Add a query event.
*/
void addQueryEvent(String event, long offset, short beanTypeId, int beanCount, short queryId);
void addQueryEvent(String event, long offset, String beanName, int beanCount, String queryId);
/**
* Add a persist event.
*/
void addPersistEvent(String event, long offset, short beanTypeId, int beanCount);
void addPersistEvent(String event, long offset, String beanName, int beanCount);
/**
* Add the commit/rollback event.
@@ -45,6 +45,7 @@ import java.sql.Connection;
import java.sql.SQLException;
import java.util.List;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.atomic.AtomicLong;
/**
@@ -147,6 +148,8 @@ public class TransactionManager implements SpiTransactionManager {
private final ServerCacheNotify cacheNotify;
private final boolean supportsSavepointId;
private final ConcurrentHashMap<String, ProfileLocation> profileLocations = new ConcurrentHashMap<>();
/**
* Create the TransactionManager
*/
@@ -689,7 +692,6 @@ public class TransactionManager implements SpiTransactionManager {
}
private void initNewTransaction(SpiTransaction transaction, TxScope txScope) {
if (txScope.isSkipCache()) {
transaction.setSkipCache(true);
}
@@ -697,17 +699,22 @@ public class TransactionManager implements SpiTransactionManager {
if (label != null) {
transaction.setLabel(label);
}
int profileId = txScope.getProfileId();
if (profileId > 0) {
transaction.setProfileStream(profileHandler.createProfileStream(profileId));
}
ProfileLocation profileLocation = txScope.getProfileLocation();
if (profileLocation != null) {
profileLocation.obtain();
if (profileLocation.obtain()) {
registerProfileLocation(profileLocation);
}
transaction.setProfileLocation(profileLocation);
if (profileLocation.trace()) {
transaction.setProfileStream(profileHandler.createProfileStream(profileLocation));
}
}
}
private void registerProfileLocation(ProfileLocation profileLocation) {
profileLocations.put(profileLocation.fullLocation(), profileLocation);
}
private TxScope initTxScope(TxScope txScope) {
if (txScope == null) {
return new TxScope();
@@ -1,15 +1,15 @@
package io.ebeaninternal.server.transaction;
import io.ebean.ProfileLocation;
/**
* Profiling information for a single transaction that has completed.
*/
public class TransactionProfile {
private long startTime;
/**
* The profileId of the transaction (On @Transactional explicitly or can be automatically set by enhancement).
*/
private int profileId;
private final ProfileLocation location;
private final String label;
private final long startTime;
/**
* The total execution time of the transaction (for filtering out small/short transactions).
@@ -26,16 +26,18 @@ public class TransactionProfile {
/**
* Create with profileId, total micros and encoded profile data.
*/
public TransactionProfile(long startTime, int profileId) {
public TransactionProfile(long startTime, ProfileLocation location) {
this.location = location;
this.label = location.label();
this.startTime = startTime;
this.profileId = profileId;
this.summary = new Summary();
}
/**
* Construct for JSON tools.
* Return the transaction location label.
*/
public TransactionProfile(){
public String getLabel() {
return label;
}
/**
@@ -45,13 +47,6 @@ public class TransactionProfile {
return startTime;
}
/**
* Return the transaction profileId.
*/
public int getProfileId() {
return profileId;
}
/**
* Return the total transaction execution time in micros.
*/
@@ -66,20 +61,6 @@ public class TransactionProfile {
return data;
}
/**
* Set start time (for JSON tools).
*/
public void setStartTime(long startTime) {
this.startTime = startTime;
}
/**
* Set profileId (for JSON tools).
*/
public void setProfileId(int profileId) {
this.profileId = profileId;
}
/**
* Set total micros (for JSON tools).
*/