Skip to content

[feature](profile) add transaction statistics for profile #33488

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
morningman merged 5 commits into from
Apr 12, 2024
Merged

[feature](profile) add transaction statistics for profile #33488

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
ec29152
fix
wuwenchi Apr 9, 2024
64de08a
fix
wuwenchi Apr 10, 2024
74f46fe
fix
wuwenchi Apr 10, 2024
3485f36
fix
wuwenchi Apr 10, 2024
e1cf19a
fix
wuwenchi Apr 11, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion fe/fe-core/src/main/java/org/apache/doris/common/profile/Profile.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ public List<ExecutionProfile> getExecutionProfiles() {
}

// This API will also add the profile to ProfileManager, so that we could get the profile from ProfileManager.
// isFinished ONLY means the cooridnator or stmtexecutor is finished.
// isFinished ONLY means the coordinator or stmtexecutor is finished.
public synchronized void updateSummary(long startTime, Map<String, String> summaryInfo, boolean isFinished,
Planner planner) {
try {
Expand Down
120 changes: 117 additions & 3 deletions fe/fe-core/src/main/java/org/apache/doris/common/profile/SummaryProfile.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
import org.apache.doris.common.util.RuntimeProfile;
import org.apache.doris.common.util.TimeUtils;
import org.apache.doris.thrift.TUnit;
import org.apache.doris.transaction.TransactionType;

import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableMap;
Expand Down Expand Up @@ -89,10 +90,19 @@ public class SummaryProfile {

public static final String FRAGMENT_COMPRESSED_SIZE = "Fragment Compressed Size";
public static final String FRAGMENT_RPC_COUNT = "Fragment RPC Count";
public static final String TRANSACTION_COMMIT_TIME = "Transaction Commit Time";
public static final String FILESYSTEM_OPT_TIME = "FileSystem Operator Time";
public static final String FILESYSTEM_OPT_RENAME_FILE_CNT = "Rename File Count";
public static final String FILESYSTEM_OPT_RENAME_DIR_CNT = "Rename Dir Count";
public static final String FILESYSTEM_OPT_DELETE_DIR_CNT = "Delete Dir Count";
public static final String HMS_ADD_PARTITION_TIME = "HMS Add Partition Time";
public static final String HMS_ADD_PARTITION_CNT = "HMS Add Partition Count";
public static final String HMS_UPDATE_PARTITION_TIME = "HMS Update Partition Time";
public static final String HMS_UPDATE_PARTITION_CNT = "HMS Update Partition Count";

// These info will display on FE's web ui table, every one will be displayed as
// a column, so that should not
// add many columns here. Add to ExcecutionSummary list.
// add many columns here. Add to ExecutionSummary list.
public static final ImmutableList<String> SUMMARY_KEYS = ImmutableList.of(PROFILE_ID, TASK_TYPE,
START_TIME, END_TIME, TOTAL_TIME, TASK_STATE, USER, DEFAULT_DB, SQL_STATEMENT);

Expand All @@ -111,7 +121,8 @@ public class SummaryProfile {
QUERY_DISTRIBUTED_TIME,
INIT_SCAN_NODE_TIME,
FINALIZE_SCAN_NODE_TIME,
GET_SPLITS_TIME, GET_PARTITIONS_TIME,
GET_SPLITS_TIME,
GET_PARTITIONS_TIME,
GET_PARTITION_FILES_TIME,
CREATE_SCAN_RANGE_TIME,
GET_PARTITION_VERSION_TIME,
Expand All @@ -136,7 +147,9 @@ public class SummaryProfile {
TOTAL_INSTANCES_NUM,
INSTANCES_NUM_PER_BE,
PARALLEL_FRAGMENT_EXEC_INSTANCE,
TRACE_ID);
TRACE_ID,
TRANSACTION_COMMIT_TIME
);

// Ident of each item. Default is 0, which doesn't need to present in this Map.
// Please set this map for new profile items if they need ident.
Expand All @@ -162,6 +175,14 @@ public class SummaryProfile {
.put(SEND_FRAGMENT_PHASE2_TIME, 1)
.put(FRAGMENT_COMPRESSED_SIZE, 1)
.put(FRAGMENT_RPC_COUNT, 1)
.put(FILESYSTEM_OPT_TIME, 1)
.put(FILESYSTEM_OPT_RENAME_FILE_CNT, 2)
.put(FILESYSTEM_OPT_RENAME_DIR_CNT, 2)
.put(FILESYSTEM_OPT_DELETE_DIR_CNT, 2)
.put(HMS_ADD_PARTITION_TIME, 1)
.put(HMS_ADD_PARTITION_CNT, 2)
.put(HMS_UPDATE_PARTITION_TIME, 1)
.put(HMS_UPDATE_PARTITION_CNT, 2)
.build();

private RuntimeProfile summaryProfile;
Expand Down Expand Up @@ -212,6 +233,17 @@ public class SummaryProfile {
private long getPartitionVersionByHasDataCount = 0;
private long getTableVersionTime = 0;
private long getTableVersionCount = 0;
private long transactionCommitBeginTime = -1;
private long transactionCommitEndTime = -1;
private long filesystemOptTime = -1;
private long hmsAddPartitionTime = -1;
private long hmsAddPartitionCnt = 0;
private long hmsUpdatePartitionTime = -1;
private long hmsUpdatePartitionCnt = 0;
private long filesystemRenameFileCnt = 0;
private long filesystemRenameDirCnt = 0;
private long filesystemDeleteDirCnt = 0;
private TransactionType transactionType = TransactionType.UNKNOWN;

public SummaryProfile() {
summaryProfile = new RuntimeProfile(SUMMARY_PROFILE_NAME);
Expand Down Expand Up @@ -317,6 +349,7 @@ private void updateExecutionSummaryProfile() {
RuntimeProfile.printCounter(queryFetchResultConsumeTime, TUnit.TIME_MS));
executionSummaryProfile.addInfoString(WRITE_RESULT_TIME,
RuntimeProfile.printCounter(queryWriteResultConsumeTime, TUnit.TIME_MS));
setTransactionSummary();

if (Config.isCloudMode()) {
executionSummaryProfile.addInfoString(GET_PARTITION_VERSION_TIME, getPrettyGetPartitionVersionTime());
Expand All @@ -328,6 +361,31 @@ private void updateExecutionSummaryProfile() {
}
}

public void setTransactionSummary() {
executionSummaryProfile.addInfoString(TRANSACTION_COMMIT_TIME,
getPrettyTime(transactionCommitEndTime, transactionCommitBeginTime, TUnit.TIME_MS));

if (transactionType.equals(TransactionType.HMS)) {
executionSummaryProfile.addInfoString(FILESYSTEM_OPT_TIME,
getPrettyTime(filesystemOptTime, 0, TUnit.TIME_MS));
executionSummaryProfile.addInfoString(FILESYSTEM_OPT_RENAME_FILE_CNT,
getPrettyCount(filesystemRenameFileCnt));
executionSummaryProfile.addInfoString(FILESYSTEM_OPT_RENAME_DIR_CNT,
getPrettyCount(filesystemRenameDirCnt));
executionSummaryProfile.addInfoString(FILESYSTEM_OPT_DELETE_DIR_CNT,
getPrettyCount(filesystemDeleteDirCnt));

executionSummaryProfile.addInfoString(HMS_ADD_PARTITION_TIME,
getPrettyTime(hmsAddPartitionTime, 0, TUnit.TIME_MS));
executionSummaryProfile.addInfoString(HMS_ADD_PARTITION_CNT,
getPrettyCount(hmsAddPartitionCnt));
executionSummaryProfile.addInfoString(HMS_UPDATE_PARTITION_TIME,
getPrettyTime(hmsUpdatePartitionTime, 0, TUnit.TIME_MS));
executionSummaryProfile.addInfoString(HMS_UPDATE_PARTITION_CNT,
getPrettyCount(hmsUpdatePartitionCnt));
}
}

public void setParseSqlStartTime(long parseSqlStartTime) {
this.parseSqlStartTime = parseSqlStartTime;
}
Expand Down Expand Up @@ -607,6 +665,10 @@ private String getPrettyGetPartitionVersionCount() {
return RuntimeProfile.printCounter(getPartitionVersionCount, TUnit.UNIT);
}

private String getPrettyCount(long cnt) {
return RuntimeProfile.printCounter(cnt, TUnit.UNIT);
}

private String getPrettyGetTableVersionTime() {
if (getTableVersionTime == 0) {
return "N/A";
Expand All @@ -624,4 +686,56 @@ private String getPrettyTime(long end, long start, TUnit unit) {
}
return RuntimeProfile.printCounter(end - start, unit);
}

public void setTransactionBeginTime(TransactionType type) {
this.transactionCommitBeginTime = TimeUtils.getStartTimeMs();
this.transactionType = type;
}

public void setTransactionEndTime() {
this.transactionCommitEndTime = TimeUtils.getStartTimeMs();
}

public void freshFilesystemOptTime() {
if (this.filesystemOptTime == -1) {
// Because this value needs to be summed up.
// If it is not set zero here:
// 1. If the detection time is longer than 1ms,
// the final cumulative value will be 1 ms less due to -1 initialization.
// 2. if the detection time is no longer than 1ms,
// the final cumulative value will be -1 always.
// This is considered to be the indicator's not being detected,
// Apparently not, it's just that the value detected is 0.
this.filesystemOptTime = 0;
}
this.filesystemOptTime += System.currentTimeMillis() - tempStarTime;
}

public void setHmsAddPartitionTime() {
this.hmsAddPartitionTime = TimeUtils.getStartTimeMs() - tempStarTime;
}

public void addHmsAddPartitionCnt(long c) {
this.hmsAddPartitionCnt = c;
}

public void setHmsUpdatePartitionTime() {
this.hmsUpdatePartitionTime = TimeUtils.getStartTimeMs() - tempStarTime;
}

public void addHmsUpdatePartitionCnt(long c) {
this.hmsUpdatePartitionCnt = c;
}

public void addRenameFileCnt(long c) {
this.filesystemRenameFileCnt += c;
}

public void incRenameDirCnt() {
this.filesystemRenameDirCnt += 1;
}

public void incDeleteDirRecursiveCnt() {
this.filesystemDeleteDirCnt += 1;
}
}
Loading