Doris-Breakwater commented on issue #67123:
URL: https://github.com/apache/doris/issues/67123#issuecomment-5408495620

   Breakwater-GitHub-Analysis-Slot: slot_b598caa888f8
   
   ## Initial triage
   
   **Verdict: the supplied flame graph strongly indicates trace-logging 
overhead; it does not yet confirm a normal non-auto Range partition routing 
bug.** In the profiled run, effective `VLOG(10)` logging was enabled for 
`tablet_info` (either through a matching verbose module or a global verbose 
level). The two large `dump_data -> to_string` branches in the graph match the 
trace statements in the 4.1.3 source exactly. Those calls are not evaluated 
with the default verbose configuration.
   
   The issue currently has no labels. Suggested initial classification is 
`performance`/load plus `needs-info`; a BE routing bug label should wait for a 
clean-verbosity reproduction.
   
   ## Verified from Doris 4.1.3
   
   1. [`OlapTabletFinder::find_tablets()` calls `find_partition()` once per 
row](https://github.com/apache/doris/blob/7126cf65d96ebc43fce0906f51e92c1a2ccf24a6/be/src/exec/sink/vtablet_finder.cpp#L36-L42).
 For a Range-partitioned table, [`find_partition()` uses 
`std::map::upper_bound`](https://github.com/apache/doris/blob/7126cf65d96ebc43fce0906f51e92c1a2ccf24a6/be/src/storage/tablet_info.h#L208-L225).
 This is a per-row ordered partition-key lookup, not a full scan of all tablet 
metadata. Its normal cost is still worth measuring, especially with many 
partitions, but the current profile is confounded by logging.
   2. Immediately after that lookup, `find_partition()` has a `VLOG_TRACE` 
statement which [dumps the complete input block and the partition-boundary 
block](https://github.com/apache/doris/blob/7126cf65d96ebc43fce0906f51e92c1a2ccf24a6/be/src/storage/tablet_info.h#L212-L214).
 The Range-key comparator also [dumps both compared blocks on every 
comparison](https://github.com/apache/doris/blob/7126cf65d96ebc43fce0906f51e92c1a2ccf24a6/be/src/storage/tablet_info.cpp#L78-L87).
 These are the `OlapTabletFinder` and `VOlapTablePartKeyComparator` branches 
visible in the attached flame graph.
   3. [`VLOG_TRACE` is 
`VLOG(10)`](https://github.com/apache/doris/blob/7126cf65d96ebc43fce0906f51e92c1a2ccf24a6/be/src/common/logging.h#L32-L50).
 `Block::dump_data()` formats every column and up to 100 rows by default, so 
enabling those statements inside a per-row lookup and its comparator can 
multiply full-block string conversion many times per input block. This explains 
the observed `ColumnWithTypeAndName::to_string`/`IDataType::to_string` CPU 
stacks.
   4. The 4.1.3 defaults are an empty `sys_log_verbose_modules` and 
`sys_log_verbose_flags_v = -1`; `sys_log_verbose_level = 10` does not enable 
tracing by itself. Doris also documents in the source that glog does not 
generate the message when its VLOG level is disabled. Therefore these 
`dump_data()` calls are not part of the normal default write path.
   5. One busy `FragmentMgrAsyn` thread alone is not proof of a global 
serialization defect. Each `AsyncResultWriter` drains its own queue serially in 
one submitted task; aggregate concurrency depends on the number of sink 
instances/jobs and their distribution across BEs. The issue does not include 
those values. Likewise, low Flink CPU can be a consequence of sink 
backpressure, so it does not independently locate the original bottleneck.
   
   The same expensive trace statements are still present on current `master`, 
so there is also a reasonable defensive code-cleanup opportunity, but that is 
separate from proving a default-configuration throughput regression.
   
   ## Required validation
   
   Please first repeat the same workload after restoring default BE verbosity 
and restarting the affected BE:
   
   ```text
   # leave sys_log_verbose_modules unset/empty
   sys_log_verbose_flags_v = -1
   ```
   
   Also provide the current effective values of `sys_log_verbose_modules`, 
`sys_log_verbose_level`, and `sys_log_verbose_flags_v`. Confirm that `be.INFO` 
no longer contains high-volume messages beginning with `find row ... of`, then 
report actual rows/s and CPU before/after and attach a new 60-second per-thread 
flame graph. This A/B test should be done before changing partition type or job 
parallelism.
   
   If throughput is still low with trace logging disabled, the following 
information is needed to isolate the remaining path:
   
   - Exact `SHOW CREATE TABLE`, total partition count, key model, distribution 
columns/bucket count, indexes, and the number/specification of BEs.
   - Complete Streaming Job/Flink sink definition and connector build, source 
and sink parallelism, batch row/byte size, flush interval, and actual versus 
expected rows/s.
   - The relevant load/execution profile and job metrics showing sink instance 
count, input block sizes, queue/backpressure time, filtered rows, and per-BE 
row distribution.
   - A clean-verbosity CPU profile (SVG plus folded stacks or `perf report`) 
and the matching BE log interval, including any `no partition for this tuple` 
or immutable-partition filtering messages.
   - Confirmation that all FE and BE nodes run the same exact 4.1.3 
build/commit.
   
   ## Maintainer next steps
   
   1. Treat trace verbosity as the leading explanation for this capture and 
request the A/B result above; do not infer a normal-path partition-routing 
regression from the current graph.
   2. Independently consider removing/rate-limiting the full-block `VLOG_TRACE` 
calls in `VOlapTablePartKeyComparator` and `find_partition()`, or logging only 
the current partition key row. Trace mode should not repeatedly stringify whole 
blocks from a hot comparator.
   3. Only if the clean profile remains dominated by `compare_at`/`upper_bound` 
rather than `dump_data`, benchmark routing versus partition count and block 
size and then evaluate a vectorized or cached Range-routing improvement.
   4. Evaluate sink parallelism separately from routing cost using the job 
profile; one writer task being single-threaded is expected, while insufficient 
writer-instance parallelism may be a separate tuning or implementation issue.
   
   No code was changed and no runtime reproduction was performed for this 
initial triage.
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: [email protected]

For queries about this service, please contact Infrastructure at:
[email protected]


---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to