[BugFix] Fix trace times merge bug (backport #62126) (#62216)

Signed-off-by: Seaven <seaven_7@qq.com>
Co-authored-by: Seaven <seaven_7@qq.com>
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
This commit is contained in:
mergify[bot] 2025-08-22 15:29:37 +08:00 committed by GitHub
parent b44663ddfc
commit 6d4fdae2f1
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 49 additions and 14 deletions

View File

@ -15,11 +15,13 @@
package com.starrocks.common.profile;
import com.google.common.base.Stopwatch;
import com.google.common.collect.HashBasedTable;
import com.google.common.collect.Lists;
import com.google.common.collect.Table;
import com.starrocks.common.util.DebugUtil;
import org.apache.commons.lang3.StringUtils;
import java.util.Comparator;
import java.util.LinkedHashMap;
import java.util.List;
import java.util.Map;
import java.util.Optional;
@ -27,28 +29,38 @@ import java.util.concurrent.TimeUnit;
import java.util.stream.Collectors;
public class TimeWatcher {
private int levels = 0;
private final Map<String, ScopedTimer> timers = new LinkedHashMap<>();
private final List<String> levels = Lists.newArrayList();
private final Table<String, String, ScopedTimer> scopedTimers = HashBasedTable.create();
public Timer scope(long time, String name) {
ScopedTimer t;
if (timers.containsKey(name)) {
t = timers.get(name);
String prefix = String.join("/", levels);
if (scopedTimers.row(name).containsKey(prefix)) {
t = scopedTimers.row(name).get(prefix);
} else {
t = new ScopedTimer(time, name);
timers.put(name, t);
scopedTimers.put(name, prefix, t);
}
t.start();
return t;
}
public Optional<Timer> getTimer(String name) {
return Optional.ofNullable(timers.get(name));
if (!scopedTimers.containsRow(name)) {
return Optional.empty();
}
Map<String, ScopedTimer> timers = scopedTimers.row(name);
if (timers.isEmpty()) {
return Optional.empty();
}
return Optional.ofNullable(timers.entrySet().stream()
.min(Comparator.comparingInt(e -> e.getKey().length()))
.map(Map.Entry::getValue)
.orElse(null));
}
public List<Timer> getAllTimerWithOrder() {
return timers.values().stream().sorted(Comparator.comparingLong(o -> o.firstTimePoints))
return scopedTimers.values().stream().sorted(Comparator.comparingLong(o -> o.firstTimePoints))
.collect(Collectors.toList());
}
@ -64,7 +76,7 @@ public class TimeWatcher {
public ScopedTimer(long time, String name) {
this.firstTimePoints = time;
this.name = name;
this.scopeLevel = levels;
this.scopeLevel = levels.size();
}
@Override
@ -77,13 +89,13 @@ public class TimeWatcher {
stopWatch.start();
}
reentrantCount++;
levels++;
count++;
levels.add(name);
}
public void close() {
reentrantCount--;
levels--;
levels.remove(levels.size() - 1);
if (reentrantCount == 0) {
stopWatch.stop();
}

View File

@ -90,7 +90,7 @@ public class DebugOperatorTracer extends OperatorVisitor<String, Void> {
@Override
public String visitLogicalTableScan(LogicalScanOperator node, Void context) {
return "LogicalScanOperator" + " {" +
"table='" + node.getTable().getId() + '\'' +
"table='" + node.getTable().getName() + '\'' +
", outputColumns='" + new ArrayList<>(node.getColRefToColumnMetaMap().keySet()) + '\'' +
'}';
}
@ -110,7 +110,7 @@ public class DebugOperatorTracer extends OperatorVisitor<String, Void> {
@Override
public String visitLogicalOlapScan(LogicalOlapScanOperator node, Void context) {
return "LogicalOlapScanOperator" + " {" + "table=" + node.getTable().getId() +
return "LogicalOlapScanOperator" + " {" + "table=" + node.getTable().getName() +
", selectedPartitionId=" + node.getSelectedPartitionId() +
", selectedIndexId=" + node.getSelectedIndexId() +
", outputColumns=" + new ArrayList<>(node.getColRefToColumnMetaMap().keySet()) +

View File

@ -14,7 +14,10 @@
package com.starrocks.sql.plan;
import com.starrocks.common.profile.Timer;
import com.starrocks.common.profile.Tracers;
import org.apache.commons.lang3.StringUtils;
import org.junit.jupiter.api.Assertions;
import org.junit.jupiter.api.Test;
public class TracerTest extends PlanTestBase {
@ -127,4 +130,24 @@ public class TracerTest extends PlanTestBase {
Tracers.close();
assertContains(pr, "QueryStatement");
}
@Test
public void testTracerMulti() throws Exception {
Tracers.register(connectContext);
String sql = "select l_returnflag, sum(l_quantity) as sum_qty,\n" +
" sum(l_extendedprice * (1 - l_discount) * (1 + l_tax)) as sum_charge\n" +
"from lineitem\n" +
"where l_shipdate <= date '1998-12-01'\n" +
"group by l_returnflag \n" +
"order by l_returnflag;";
Tracers.init(Tracers.Mode.TIMER, Tracers.Module.BASE, false, false);
getFragmentPlan(sql);
try (Timer t = Tracers.watchScope(Tracers.Module.BASE, "thisIsPrivilegeCheckCall")) {
getFragmentPlan(sql);
}
String ss = Tracers.printScopeTimer();
System.out.println(ss);
Assertions.assertEquals(2, StringUtils.countMatches(ss, "Parser"));
Assertions.assertEquals(2, StringUtils.countMatches(ss, "Planner"));
}
}