From 9583b86fcf22c1113bfd22ba8dbe4251fdcd1bc3 Mon Sep 17 00:00:00 2001 From: zhiqiang Date: Mon, 23 Sep 2024 12:37:05 +0800 Subject: [PATCH] [feat](profile) Print changed session var in profile (#41016) Add changed session var like follow: ``` Changed Session Variables: VarName | CurrentValue | DefaultValue ------------------------------------------------|---------------------|------------- character_set_results | NULL | utf8mb4 enable_profile | true | false enable_auto_analyze | false | true max_scan_key_num | -1 | 48 enable_prepared_stmt_audit_log | true | false sql_mode | STRICT_TRANS_TABLES | wait_timeout | 31000 | 28800 parallel_pipeline_task_num | 8 | 0 num_scanner_threads | 10 | 0 experimental_enable_agg_state | true | false max_pushdown_conditions_per_column | -1 | 1024 experimental_parallel_scan_min_rows_per_scanner | 16384 | 2097152 max_allowed_packet | 1048576 | 16777216 ``` --- .../apache/doris/common/profile/Profile.java | 108 +++++++++++------- .../apache/doris/common/util/DebugUtil.java | 59 ++++++++++ .../doris/common/util/ProfileManager.java | 2 +- .../org/apache/doris/qe/StmtExecutor.java | 2 + .../java/org/apache/doris/qe/VariableMgr.java | 36 ++++++ 5 files changed, 167 insertions(+), 40 deletions(-) diff --git a/fe/fe-core/src/main/java/org/apache/doris/common/profile/Profile.java b/fe/fe-core/src/main/java/org/apache/doris/common/profile/Profile.java index e17b5b68c1ec52..203e95669b77ce 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/common/profile/Profile.java +++ b/fe/fe-core/src/main/java/org/apache/doris/common/profile/Profile.java @@ -107,6 +107,8 @@ public class Profile { // Profile size is the size of profile file private long profileSize = 0; + private String changedSessionVarCache = ""; + // Need default constructor for read from storage public Profile() {} @@ -321,8 +323,9 @@ public String getProfileByLevel() { StringBuilder builder = new StringBuilder(); // add summary to builder summaryProfile.prettyPrint(builder); - // read execution profile from storage or generate it from memory (during query execution) + getChangedSessionVars(builder); getExecutionProfileContent(builder); + getOnStorageProfile(builder); return builder.toString(); } @@ -366,49 +369,13 @@ public String getProfileBrief() { return gson.toJson(rootProfile.toBrief()); } - // Read file if profile has been stored to storage. + // Return if profile has been stored to storage public void getExecutionProfileContent(StringBuilder builder) { if (builder == null) { builder = new StringBuilder(); } if (profileHasBeenStored()) { - LOG.info("Profile {} has been stored to storage, reading it from storage", id); - - FileInputStream fileInputStream = null; - - try { - fileInputStream = createPorfileFileInputStream(profileStoragePath); - if (fileInputStream == null) { - builder.append("Failed to read execution profile from " + profileStoragePath); - return; - } - - DataInputStream dataInput = new DataInputStream(fileInputStream); - // skip summary profile - Text.readString(dataInput); - // read compressed execution profile - int binarySize = dataInput.readInt(); - byte[] binaryExecutionProfile = new byte[binarySize]; - dataInput.readFully(binaryExecutionProfile, 0, binarySize); - // decompress binary execution profile - String textExecutionProfile = decompressExecutionProfile(binaryExecutionProfile); - builder.append(textExecutionProfile); - return; - } catch (Exception e) { - LOG.error("An error occurred while reading execution profile from storage, profile storage path: {}", - profileStoragePath, e); - builder.append("Failed to read execution profile from " + profileStoragePath); - } finally { - if (fileInputStream != null) { - try { - fileInputStream.close(); - } catch (Exception e) { - LOG.warn("Close profile {} failed", profileStoragePath, e); - } - } - } - return; } @@ -448,8 +415,9 @@ public void setSummaryProfile(SummaryProfile summaryProfile) { this.summaryProfile = summaryProfile; } - public void releaseExecutionProfile() { + public void releaseMemory() { this.executionProfiles.clear(); + this.changedSessionVarCache = ""; } public boolean shouldStoreToStorage() { @@ -580,6 +548,7 @@ public void writeToStorage(String systemProfileStorageDir) { // store execution profiles as string StringBuilder build = new StringBuilder(); + getChangedSessionVars(build); getExecutionProfileContent(build); byte[] buf = compressExecutionProfile(build.toString()); dataOutputStream.writeInt(buf.length); @@ -648,4 +617,65 @@ public boolean shouldBeRemoveFromMemory() { return true; } + + public void setChangedSessionVar(String changedSessionVar) { + this.changedSessionVarCache = changedSessionVar; + } + + private void getChangedSessionVars(StringBuilder builder) { + if (builder == null) { + builder = new StringBuilder(); + } + if (profileHasBeenStored()) { + return; + } + + builder.append("\nChanged Session Variables:\n"); + builder.append(changedSessionVarCache); + builder.append("\n"); + } + + private void getOnStorageProfile(StringBuilder builder) { + if (!profileHasBeenStored()) { + return; + } + + LOG.info("Profile {} has been stored to storage, reading it from storage", id); + + FileInputStream fileInputStream = null; + + try { + fileInputStream = createPorfileFileInputStream(profileStoragePath); + if (fileInputStream == null) { + builder.append("Failed to read execution profile from " + profileStoragePath); + return; + } + + DataInputStream dataInput = new DataInputStream(fileInputStream); + // skip summary profile + Text.readString(dataInput); + // read compressed execution profile + int binarySize = dataInput.readInt(); + byte[] binaryExecutionProfile = new byte[binarySize]; + dataInput.readFully(binaryExecutionProfile, 0, binarySize); + // decompress binary execution profile + String textExecutionProfile = decompressExecutionProfile(binaryExecutionProfile); + builder.append(textExecutionProfile); + return; + } catch (Exception e) { + LOG.error("An error occurred while reading execution profile from storage, profile storage path: {}", + profileStoragePath, e); + builder.append("Failed to read execution profile from " + profileStoragePath); + } finally { + if (fileInputStream != null) { + try { + fileInputStream.close(); + } catch (Exception e) { + LOG.warn("Close profile {} failed", profileStoragePath, e); + } + } + } + + return; + } } diff --git a/fe/fe-core/src/main/java/org/apache/doris/common/util/DebugUtil.java b/fe/fe-core/src/main/java/org/apache/doris/common/util/DebugUtil.java index 937c74cac66bb5..39c4cd91904775 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/common/util/DebugUtil.java +++ b/fe/fe-core/src/main/java/org/apache/doris/common/util/DebugUtil.java @@ -26,6 +26,7 @@ import java.io.PrintWriter; import java.io.StringWriter; import java.text.DecimalFormat; +import java.util.List; import java.util.UUID; public class DebugUtil { @@ -177,4 +178,62 @@ public static String getStackTrace(Exception e) { e.printStackTrace(new PrintWriter(sw)); return sw.toString(); } + + public static String prettyPrintChangedSessionVar(List> nestedList) { + if (nestedList == null || nestedList.isEmpty()) { + return ""; + } + + StringBuilder output = new StringBuilder(); + + // Assuming each inner list has exactly 3 columns + int[] columnWidths = new int[3]; + + // Calculate the maximum width of each column + // First consider the header widths: "VarName", "CurrentValue", "DefaultValue" + String[] headers = {"VarName", "CurrentValue", "DefaultValue"}; + for (int i = 0; i < headers.length; i++) { + columnWidths[i] = headers[i].length(); // Initialize with header length + } + + // Update column widths based on data + for (List row : nestedList) { + for (int i = 0; i < row.size(); i++) { + columnWidths[i] = Math.max(columnWidths[i], row.get(i).length()); + } + } + + // Build the table header + for (int i = 0; i < headers.length; i++) { + output.append(String.format("%-" + columnWidths[i] + "s", headers[i])); + if (i < headers.length - 1) { + output.append(" | "); // Separator between columns + } + } + output.append("\n"); // Newline after the header + + // Add a separator line for better readability (optional) + for (int i = 0; i < headers.length; i++) { + output.append(String.format("%-" + columnWidths[i] + "s", Strings.repeat("-", columnWidths[i]))); + if (i < headers.length - 1) { + output.append("-|-"); // Separator between columns + } + } + output.append("\n"); // Newline after the separator + + // Build the table body with proper alignment based on column widths + for (List row : nestedList) { + for (int i = 0; i < row.size(); i++) { + String element = row.get(i); + // Pad with spaces if the element is shorter than the column width + output.append(String.format("%-" + columnWidths[i] + "s", element)); + if (i < row.size() - 1) { + output.append(" | "); // Separator between columns + } + } + output.append("\n"); // Newline after each row + } + + return output.toString(); + } } diff --git a/fe/fe-core/src/main/java/org/apache/doris/common/util/ProfileManager.java b/fe/fe-core/src/main/java/org/apache/doris/common/util/ProfileManager.java index 65ddab151e8145..c6fc3307fe0b29 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/common/util/ProfileManager.java +++ b/fe/fe-core/src/main/java/org/apache/doris/common/util/ProfileManager.java @@ -687,7 +687,7 @@ private void writeProfileToStorage() { for (ExecutionProfile executionProfile : profileElement.profile.getExecutionProfiles()) { this.queryIdToExecutionProfiles.remove(executionProfile.getQueryId()); } - profileElement.profile.releaseExecutionProfile(); + profileElement.profile.releaseMemory(); } } finally { writeLock.unlock(); diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java b/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java index bd16d011a59c57..ff940eb633b751 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java +++ b/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java @@ -691,6 +691,8 @@ private void executeByNereids(TUniqueId queryId) throws Exception { context.setQueryId(queryId); context.setStartTime(); profile.getSummaryProfile().setQueryBeginTime(); + List> changedSessionVar = VariableMgr.dumpChangedVars(context.getSessionVariable()); + profile.setChangedSessionVar(DebugUtil.prettyPrintChangedSessionVar(changedSessionVar)); context.setStmtId(STMT_ID_GENERATOR.incrementAndGet()); parseByNereids(); diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/VariableMgr.java b/fe/fe-core/src/main/java/org/apache/doris/qe/VariableMgr.java index 1b1a317f5f0bb5..8bb4210c605607 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/qe/VariableMgr.java +++ b/fe/fe-core/src/main/java/org/apache/doris/qe/VariableMgr.java @@ -800,6 +800,42 @@ public int compare(List o1, List o2) { return changedRows; } + public static List> dumpChangedVars(SessionVariable sessionVar) { + // Hold the read lock when session dump, because this option need to access global variable. + rlock.lock(); + List> changedRows = Lists.newArrayList(); + try { + for (Map.Entry entry : ctxByDisplayVarName.entrySet()) { + VarContext ctx = entry.getValue(); + List row = Lists.newArrayList(); + String varName = entry.getKey(); + String curValue = getValue(sessionVar, ctx.getField()); + String defaultValue = ctx.getDefaultValue(); + if (VariableVarConverters.hasConverter(varName)) { + try { + defaultValue = VariableVarConverters.decode(varName, Long.valueOf(defaultValue)); + curValue = VariableVarConverters.decode(varName, Long.valueOf(curValue)); + } catch (DdlException e) { + LOG.warn("Decode session variable {} failed, reason: {}", varName, e.getMessage()); + } + } + + if (curValue.equals(defaultValue)) { + continue; + } + + row.add(varName); + row.add(curValue); + row.add(defaultValue); + changedRows.add(row); + } + } finally { + rlock.unlock(); + } + + return changedRows; + } + @Retention(RetentionPolicy.RUNTIME) public @interface VarAttr { // Name in show variables and set statement;