Skip to content

Commit 8537f07

Browse files
Hor911Hor911
authored
Update time in stat (#17131)
1 parent 4002b7e commit 8537f07

File tree

7 files changed

+51
-7
lines changed

7 files changed

+51
-7
lines changed

‎ydb/core/kqp/executer_actor/kqp_executer_stats.cpp‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -488,6 +488,10 @@ ui64 TStageExecutionStats::UpdateStats(const NYql::NDqProto::TDqTaskStats& taskS
488488
CurrentWaitInputTimeUs.Set(index, taskStats.GetCurrentWaitInputTimeUs());
489489
CurrentWaitOutputTimeUs.Set(index, taskStats.GetCurrentWaitOutputTimeUs());
490490

491+
auto updateTimeMs = taskStats.GetUpdateTimeMs();
492+
UpdateTimeMs = std::max(UpdateTimeMs, updateTimeMs);
493+
baseTimeMs = NonZeroMin(baseTimeMs, updateTimeMs);
494+
491495
SpillingComputeBytes.SetNonZero(index, taskStats.GetSpillingComputeWriteBytes());
492496
SpillingChannelBytes.SetNonZero(index, taskStats.GetSpillingChannelWriteBytes());
493497
SpillingComputeTimeUs.SetNonZero(index, taskStats.GetSpillingComputeReadTimeUs() + taskStats.GetSpillingComputeWriteTimeUs());
@@ -878,6 +882,10 @@ void TQueryExecutionStats::AddComputeActorFullStatsByTask(
878882
UpdateAggr(stageStats->MutableWaitInputTimeUs(), task.GetWaitInputTimeUs());
879883
UpdateAggr(stageStats->MutableWaitOutputTimeUs(), task.GetWaitOutputTimeUs());
880884

885+
auto updateTimeMs = task.GetUpdateTimeMs();
886+
stageStats->SetUpdateTimeMs(std::max(stageStats->GetUpdateTimeMs(), updateTimeMs));
887+
BaseTimeMs = NonZeroMin(BaseTimeMs, updateTimeMs);
888+
881889
UpdateAggr(stageStats->MutableSpillingComputeBytes(), task.GetSpillingComputeWriteBytes());
882890
UpdateAggr(stageStats->MutableSpillingChannelBytes(), task.GetSpillingChannelWriteBytes());
883891
UpdateAggr(stageStats->MutableSpillingComputeTimeUs(), task.GetSpillingComputeReadTimeUs() + task.GetSpillingComputeWriteTimeUs());
@@ -1518,6 +1526,7 @@ void TQueryExecutionStats::ExportExecStats(NYql::NDqProto::TDqExecutionStats& st
15181526
ExportAggStats(stageStat.DurationUs, *stageStats.MutableDurationUs());
15191527
stageStat.WaitInputTimeUs.ExportAggStats(BaseTimeMs, *stageStats.MutableWaitInputTimeUs());
15201528
stageStat.WaitOutputTimeUs.ExportAggStats(BaseTimeMs, *stageStats.MutableWaitOutputTimeUs());
1529+
stageStats.SetUpdateTimeMs(stageStat.UpdateTimeMs > BaseTimeMs ? stageStat.UpdateTimeMs - BaseTimeMs : 0);
15211530

15221531
stageStat.SpillingComputeBytes.ExportAggStats(BaseTimeMs, *stageStats.MutableSpillingComputeBytes());
15231532
stageStat.SpillingChannelBytes.ExportAggStats(BaseTimeMs, *stageStats.MutableSpillingChannelBytes());
@@ -1648,6 +1657,8 @@ void TQueryExecutionStats::AdjustBaseTime(NDqProto::TDqStageStats* stageStats) {
16481657
for (auto& p : *stageStats->MutableEgress()) {
16491658
AdjustAsyncBufferAggr(p.second);
16501659
}
1660+
auto updateTimeMs = stageStats->GetUpdateTimeMs();
1661+
stageStats->SetUpdateTimeMs(updateTimeMs > BaseTimeMs ? updateTimeMs - BaseTimeMs : 0);
16511662
}
16521663

16531664
void TQueryExecutionStats::Finish() {

‎ydb/core/kqp/executer_actor/kqp_executer_stats.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -218,6 +218,7 @@ struct TStageExecutionStats {
218218
TTimeSeriesStats WaitOutputTimeUs;
219219
TMinStats CurrentWaitInputTimeUs;
220220
TMinStats CurrentWaitOutputTimeUs;
221+
ui64 UpdateTimeMs = 0;
221222

222223
TTimeSeriesStats SpillingComputeBytes;
223224
TTimeSeriesStats SpillingChannelBytes;

‎ydb/core/kqp/opt/kqp_query_plan.cpp‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2893,6 +2893,9 @@ TString AddExecStatsToTxPlan(const TString& txPlanJson, const NYql::NDqProto::TD
28932893
stats["PhysicalStageId"] = (*stat)->GetStageId();
28942894
stats["Tasks"] = (*stat)->GetTotalTasksCount();
28952895
stats["FinishedTasks"] = (*stat)->GetFinishedTasksCount();
2896+
if (auto updateTimeUs = (*stat)->GetUpdateTimeMs(); updateTimeUs) {
2897+
stats["UpdateTimeMs"] = updateTimeUs;
2898+
}
28962899

28972900
stats["StageDurationUs"] = (*stat)->GetStageDurationUs();
28982901

‎ydb/library/yql/dq/actors/compute/dq_compute_actor_stats.cpp‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -291,6 +291,7 @@ void FillTaskRunnerStats(ui64 taskId, ui32 stageId, const TDqTaskRunnerStats& ta
291291
protoTask->SetCreateTimeMs(taskStats.CreateTs.MilliSeconds());
292292
protoTask->SetStartTimeMs(startTime.MilliSeconds());
293293
protoTask->SetFinishTimeMs(finishTime.MilliSeconds());
294+
protoTask->SetUpdateTimeMs(TInstant::Now().MilliSeconds());
294295
}
295296

296297
} // namespace NDq

‎ydb/library/yql/dq/actors/protos/dq_stats.proto‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -286,6 +286,7 @@ message TDqTaskStats {
286286
uint64 CreateTimeMs = 166;
287287
uint64 StartTimeMs = 158;
288288
uint64 FinishTimeMs = 5;
289+
uint64 UpdateTimeMs = 169;
289290

290291
reserved 4; // was FirstRowTimeMs
291292
reserved 104;
@@ -439,6 +440,7 @@ message TDqStageStats {
439440
TDqStatsAggr FinishTimeMs = 32;
440441
TDqStatsAggr StartTimeMs = 33;
441442
TDqStatsAggr DurationUs = 34; // just aggregate over task.DurationUs
443+
uint64 UpdateTimeMs = 51;
442444

443445
TDqStatsAggr WaitInputTimeUs = 35;
444446
TDqStatsAggr WaitOutputTimeUs = 36;

‎ydb/public/lib/ydb_cli/common/plan2svg.cpp‎

Lines changed: 29 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1181,6 +1181,10 @@ void TPlan::LoadStage(std::shared_ptr<TStage> stage, const NJson::TJsonValue& no
11811181
if (auto* wotNode = stage->StatsNode->GetValueByPath("WaitOutputTimeUs")) {
11821182
stage->WaitOutputTime = std::make_shared<TSingleMetric>(WaitOutputTime, *wotNode, stage->MinTime, stage->MaxTime);
11831183
}
1184+
1185+
if (auto* updateTimeNode = stage->StatsNode->GetValueByPath("UpdateTimeMs")) {
1186+
stage->UpdateTime = updateTimeNode->GetIntegerSafe();
1187+
}
11841188
}
11851189

11861190
if (stage->IngressBytes) {
@@ -1214,6 +1218,7 @@ void TPlan::LoadStage(std::shared_ptr<TStage> stage, const NJson::TJsonValue& no
12141218
}
12151219

12161220
Max0(MaxTime, stage->MaxTime);
1221+
Max0(UpdateTime, stage->UpdateTime);
12171222
}
12181223

12191224
void TPlan::LoadSource(const NJson::TJsonValue& node, std::vector<TOperatorInfo>& stageOperators, const NJson::TJsonValue* ingressRowsNode) {
@@ -1534,7 +1539,7 @@ void TPlan::PrintStageSummary(TStringBuilder& background, TStringBuilder&, ui32
15341539
}
15351540
}
15361541

1537-
void TPlan::PrintSvg(ui64 maxTime, ui32& offsetY, TStringBuilder& background, TStringBuilder& canvas) {
1542+
void TPlan::PrintSvg(ui64 maxTime, ui32 timelineDelta, ui32& offsetY, TStringBuilder& background, TStringBuilder& canvas) {
15381543
OffsetY = offsetY;
15391544
ui32 planHeight = 0;
15401545

@@ -1637,8 +1642,8 @@ void TPlan::PrintSvg(ui64 maxTime, ui32& offsetY, TStringBuilder& background, TS
16371642
ui32 y0 = s->OffsetY + offsetY + INTERNAL_GAP_Y;
16381643

16391644
auto tx0 = Config.TimelineLeft;
1640-
auto px = tx0 + TimeOffset * Config.TimelineWidth / maxTime;
1641-
auto pw = MaxTime * Config.TimelineWidth / maxTime;
1645+
auto px = tx0 + TimeOffset * (Config.TimelineWidth - timelineDelta) / maxTime;
1646+
auto pw = MaxTime * (Config.TimelineWidth - timelineDelta) / maxTime;
16421647

16431648
if (s->External) {
16441649
canvas
@@ -2191,6 +2196,7 @@ void TPlanVisualizer::PostProcessPlans() {
21912196
for (auto& p : Plans) {
21922197
p.TimeOffset = p.BaseTime - BaseTime;
21932198
MaxTime = std::max(MaxTime, p.TimeOffset + p.MaxTime);
2199+
UpdateTime = std::max(UpdateTime, p.TimeOffset + p.UpdateTime);
21942200
}
21952201
}
21962202

@@ -2208,6 +2214,7 @@ TString TPlanVisualizer::PrintSvg() {
22082214
TStringBuilder svg;
22092215

22102216
ui32 offsetY = 0;
2217+
ui32 timelineDelta = (UpdateTime > MaxTime) ? std::min<ui32>(Config.TimelineWidth * (UpdateTime - MaxTime) / UpdateTime, Config.TimelineWidth / 10) : 0;
22112218

22122219
ui32 summary3 = (Config.SummaryWidth - INTERNAL_GAP_X * 2) / 3;
22132220
for (auto& p : Plans) {
@@ -2278,7 +2285,7 @@ TString TPlanVisualizer::PrintSvg() {
22782285
<< "' y='" << offsetY + INTERNAL_TEXT_HEIGHT * 2 + GAP_Y<< "'>" << FormatBytes(p.MaxMemoryUsage->Value) << "</text>" << Endl
22792286
<< "</g>" << Endl;
22802287

2281-
auto x = Config.TimelineLeft + Config.TimelineWidth * (p.MaxTime + p.TimeOffset) / MaxTime;
2288+
auto x = Config.TimelineLeft + (Config.TimelineWidth - timelineDelta) * (p.MaxTime + p.TimeOffset) / MaxTime;
22822289
canvas
22832290
<< "<g><title>" << "Duration: " << FormatTimeMs(p.MaxTime) << ", Total " << FormatTimeMs(p.MaxTime + p.TimeOffset) << "</title>" << Endl
22842291
<< " <rect x='" << x - summary3 << "' y='" << offsetY
@@ -2297,7 +2304,7 @@ TString TPlanVisualizer::PrintSvg() {
22972304
p.PrintDeriv(canvas, p.TotalCpuTime, tx0, offsetY, tw, INTERNAL_HEIGHT, "Max CPU " + FormatMCpu(maxCpu), Config.Palette.CpuMedium, Config.Palette.CpuLight);
22982305
}
22992306
offsetY += INTERNAL_HEIGHT;
2300-
p.PrintSvg(MaxTime, offsetY, background, canvas);
2307+
p.PrintSvg(MaxTime, timelineDelta, offsetY, background, canvas);
23012308
}
23022309

23032310
svg << "<svg width='" << Config.Width << "' height='" << offsetY << "' xmlns='http://www.w3.org/2000/svg'>" << Endl;
@@ -2354,7 +2361,7 @@ TString TPlanVisualizer::PrintSvg() {
23542361
}
23552362

23562363
auto x = Config.TimelineLeft + INTERNAL_GAP_X;
2357-
auto w = Config.TimelineWidth - INTERNAL_GAP_X * 2;
2364+
auto w = Config.TimelineWidth - timelineDelta - INTERNAL_GAP_X * 2;
23582365

23592366
for (ui64 t = 0; t < maxSec; t += deltaSec) {
23602367
ui64 x1 = t * w / maxSec;
@@ -2371,6 +2378,22 @@ TString TPlanVisualizer::PrintSvg() {
23712378
}
23722379
}
23732380

2381+
if (timelineDelta) {
2382+
auto opacity = MaxTime ? std::min(0.5, static_cast<double>(UpdateTime - MaxTime) / (2 * MaxTime)) : 0.5;
2383+
svg
2384+
<< "<rect x='" << Config.TimelineLeft + Config.TimelineWidth - timelineDelta << "' y='" << 0
2385+
<< "' width='" << timelineDelta << "' height='" << offsetY
2386+
<< "' stroke-width='0' opacity='" << opacity << "' fill='" << Config.Palette.StageTextHighlight << "'/>" << Endl;
2387+
svg
2388+
<< "<g><title>" << "Last Update: " << FormatTimeMs(UpdateTime) << "</title>" << Endl
2389+
<< " <rect x='" << Config.TimelineLeft + Config.TimelineWidth - summary3 << "' y='" << GAP_Y
2390+
<< "' width='" << summary3 << "' height='" << TIME_HEIGHT
2391+
<< "' stroke-width='0' fill='" << Config.Palette.StageTextHighlight << "'/>" << Endl
2392+
<< " <text text-anchor='end' font-family='Verdana' font-size='" << INTERNAL_TEXT_HEIGHT << "px' fill='" << Config.Palette.TextInverted << "' x='" << Config.TimelineLeft + Config.TimelineWidth - 2
2393+
<< "' y='" << GAP_Y + INTERNAL_TEXT_HEIGHT << "'>" << FormatTimeMs(UpdateTime) << "</text>" << Endl
2394+
<< "</g>" << Endl;
2395+
}
2396+
23742397
svg << TString(canvas) << Endl;
23752398
svg << "</svg>" << Endl;
23762399

‎ydb/public/lib/ydb_cli/common/plan2svg.h‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -162,6 +162,7 @@ class TStage {
162162
const NJson::TJsonValue* StatsNode = nullptr;
163163
ui64 MinTime = 0;
164164
ui64 MaxTime = 0;
165+
ui64 UpdateTime = 0;
165166
bool External = false;
166167
};
167168

@@ -262,7 +263,7 @@ class TPlan {
262263
void PrintDeriv(TStringBuilder& canvas, TMetricHistory& history, ui32 x, ui32 y, ui32 w, ui32 h, const TString& title, const TString& lineColor, const TString& fillColor = "");
263264
void PrintValues(TStringBuilder& canvas, std::shared_ptr<TSingleMetric> metric, ui32 x, ui32 y, ui32 w, ui32 h, const TString& title, const TString& lineColor, const TString& fillColor = "");
264265
void PrintStageSummary(TStringBuilder& background, TStringBuilder&, ui32 viewLeft, ui32 viewWidth, ui32 y0, ui32 h, std::shared_ptr<TSingleMetric> metric, const TString& mediumColor, const TString& lightColor, const TString& textSum, const TString& tooltip, ui32 taskCount, const TString& iconRef, const TString& iconScale);
265-
void PrintSvg(ui64 maxTime, ui32& offsetY, TStringBuilder& background, TStringBuilder& canvas);
266+
void PrintSvg(ui64 maxTime, ui32 timelineDelta, ui32& offsetY, TStringBuilder& background, TStringBuilder& canvas);
266267
TString NodeType;
267268
std::vector<std::shared_ptr<TStage>> Stages;
268269
std::shared_ptr<TSummaryMetric> CpuTime;
@@ -296,6 +297,7 @@ class TPlan {
296297
ui64 TimeOffset = 0;
297298
ui32 OffsetY = 0;
298299
ui32 Tasks = 0;
300+
ui64 UpdateTime = 0;
299301
std::vector<std::pair<std::string, std::shared_ptr<TConnection>>> CteRefs;
300302
std::vector<std::pair<std::string, std::pair<std::shared_ptr<TStage>, ui32>>> MemberRefs;
301303
TPlanViewConfig& Config;
@@ -316,6 +318,7 @@ class TPlanVisualizer {
316318
std::vector<TPlan> Plans;
317319
ui64 MaxTime = 1000;
318320
ui64 BaseTime = 0;
321+
ui64 UpdateTime = 0;
319322
TPlanViewConfig Config;
320323
std::map<std::string, std::shared_ptr<TStage>> CteStages;
321324
std::map<std::string, std::string> CteSubPlans;

0 commit comments

Comments
 (0)