Skip to content

[improve][broker] Trace the asynchronous tasks in logs when loading topics#26163

Open
BewareMyPower wants to merge 3 commits into
apache:masterfrom
BewareMyPower:bewaremypower/topic-load-tracing
Open

[improve][broker] Trace the asynchronous tasks in logs when loading topics#26163
BewareMyPower wants to merge 3 commits into
apache:masterfrom
BewareMyPower:bewaremypower/topic-load-tracing

Conversation

@BewareMyPower

@BewareMyPower BewareMyPower commented Jul 8, 2026

Copy link
Copy Markdown
Contributor

Motivation

The topic loading time could be high with pressure, but it's hard to measure which sub-task takes the most time. This is a follow-up work of #24785 to improve the logs that show topic loading latency.

Modifications

Add a simple tracing class LatencyTracer and trace asynchronous futures during topic loading. When tracing a future, if the future is already done, skip tracing it because such tasks are usually not CPU-bounded.

Verifying this change

LatencyTracerTest covers functionality of all public methods with injected timestamps. The topic loading logs can be checked by running testConcurrentLoadTopicExceedLimitShouldNotBeAutoCreated:

Loaded topic {dedupEnabled=false, latency=total: 132 ms, ml-config: 9 ms, open-ml: 64 ms, init: 56 ms, done: 1 ms, topic=persistent://prop/concurrentLoad/my-topic_0}
Loaded topic {dedupEnabled=false, latency=total: 20 ms, ml-config: 1 ms, open-ml: 18 ms, init: 1 ms, done: 127 us, topic=persistent://prop/concurrentLoad/my-topic_1}
Loaded topic {dedupEnabled=false, latency=total: 20 ms, ml-config: 1 ms, open-ml: 18 ms, init: 1 ms, done: 108 us, topic=persistent://prop/concurrentLoad/my-topic_2}
Loaded topic {dedupEnabled=false, latency=total: 4 ms, properties: 2 ms, ml-config: 834 us, open-ml: 121 us, init: 658 us, done: 85 us, topic=persistent://prop/concurrentLoad/my-topic_0}
Loaded topic {dedupEnabled=false, latency=total: 7 ms, queued: 3 ms, properties: 2 ms, ml-config: 465 us, open-ml: 189 us, init: 738 us, done: 85 us, topic=persistent://prop/concurrentLoad/my-topic_1}
Loaded topic {dedupEnabled=false, latency=total: 11 ms, queued: 7 ms, properties: 2 ms, ml-config: 507 us, open-ml: 53 us, init: 548 us, done: 73 us, topic=persistent://prop/concurrentLoad/my-topic_2}

Out of scope

In my previous tests, opening managed ledger could also take much time, this LatencyTracer class can be used to track managed ledger open process as well.

@BewareMyPower BewareMyPower self-assigned this Jul 8, 2026
@BewareMyPower BewareMyPower added release/4.2.4 release/4.0.13 type/enhancement The enhancements for the existing features or docs. e.g. reduce memory usage of the delayed messages area/broker labels Jul 8, 2026
@BewareMyPower BewareMyPower marked this pull request as draft July 8, 2026 12:16
@BewareMyPower BewareMyPower marked this pull request as ready for review July 8, 2026 12:29
@BewareMyPower BewareMyPower reopened this Jul 9, 2026
@BewareMyPower BewareMyPower added this to the 5.0.0-M2 milestone Jul 9, 2026
@BewareMyPower BewareMyPower force-pushed the bewaremypower/topic-load-tracing branch from 0cf2bee to 7ed63b7 Compare July 9, 2026 05:14
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area/broker release/4.0.13 release/4.2.4 type/enhancement The enhancements for the existing features or docs. e.g. reduce memory usage of the delayed messages

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants