Conversation
Single mode traced only PrimaryLogPG::log_op_stats, which fires solely
for client ops on the primary -- replica write subops (MSG_OSD_REPOP)
were invisible, although on a replicated pool they are two thirds of
the write work. Add a second lightweight probe so single mode prints
one line per replica subop write:
osd 0 pg 1.18 subop_w size 4483 client 4126 tid 500 \
object benchmark_data_..._object499 subop_lat 4886
Anchor: ReplicatedBackend::repop_commit, via a standalone v2 program
mirroring uprobe_log_op_stats_v2 (no map state, latency computed
in-kernel from the message recv_stamp, same -l threshold gate).
log_subop_stats was considered and rejected: it is a static function
with a single call site (the last statement of repop_commit itself),
inlined away on -O2 release builds -- it is absent from every embedded
release DWARF JSON (quincy/reef/squid), while repop_commit, invoked
through the C_OSD_RepModifyCommit callback, exists on all of them.
- Append recv_stamp and pg id (cast:MOSDRepOp pgid) varpaths to the
repop_commit list (varids 175-177; 170-174 keep their positions, so
full mode's v1 program is unaffected).
- uprobe_repop_commit_v2 is appended as the last program in the file:
func_progid indices are positional in skeleton declaration order.
- Subop events are excluded from the single-mode size-range histograms:
those measure client-visible latency, and replica subops would also
count each client write once per replica.
- Reads of the new varids degrade gracefully with older DWARF JSON:
no recv_stamp aborts the event (no latency without it), missing pg
fields print as zeros.
Verified on a 3-OSD vstart cluster (size-3 pool, rados bench 4K
writes): subop_w line count is exactly 2x the client op_w count; for
any tid the primary's op_w pairs with two replica subop_w lines on the
same pg/object with subop_lat < op_lat; -l 15 prints only ops and
subops above threshold; histograms unchanged (client writes only);
full mode still attaches 15 probes per OSD with identical output.
Probe body cost measured via bpftool: ~3.5us per subop event.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Stacked on #186. Single mode traced only
PrimaryLogPG::log_op_stats, which fires solely for client ops on the primary — replica write subops (MSG_OSD_REPOP) were invisible, although on a replicated pool they are two thirds of the write work. This adds a second lightweight probe so-sprints one line per replica subop write, with the same in-kernel-lthreshold behavior:Anchor choice:
repop_commit, notlog_subop_statsBoth fire at essentially the same instant — in current Ceph,
log_subop_statsis astaticfunction whose only call site is the last statement ofrepop_commit. But a static single-caller function is inlined at-O2: it is absent from every embedded release DWARF JSON (checked quincy 17.2.6/el8, reef 18.2.4/el9, squid 19.2.0/el9) and only exists out-of-line on debug builds.ReplicatedBackend::repop_commitis invoked through theC_OSD_RepModifyCommitcallback, so it cannot be inlined away, and is present in all embedded release JSONs. It also only ever handles MSG_OSD_REPOP, so no message-type filter is needed.Changes
recv_stampand pg id (cast:MOSDRepOp → pgid.pgid.m_pool/m_seed, layout gdb-verified:MOSDRepOp::pgiddeclared directly at 0x1a0) to therepop_commitlist — varids 175-177; 170-174 keep their positions so full mode's v1 program is untouched. 8/10 varid budget.uprobe_repop_commit_v2, a standalone sibling ofuprobe_log_op_stats_v2— recv_stamp first, in-kernel-lgate, then owner/tid/payload/object-name/pg into a ringbuf event; no map state, no printk. Appended as the last program in the file sincefunc_progidindices are positional in skeleton declaration order.OP_SINGLE_PROBE, exact, v=2),print_single_opbranch forsubop_wlines (noosd_opsfield — a repop carries a serialized ObjectStore transaction, not a decoded OSDOp vector), and subops are excluded from the size-range histograms (they measure client-visible latency and would count each client write once per replica).-shelp text and man page updated.Verification (3-OSD vstart cluster, size-3 pool, tentacle dev build)
subop_wline count = exactly 2× the clientop_wcount (136,438 vs 68,218 over a bench run)op_wpairs with two replicasubop_wlines on the same pg/object, withsubop_lat < op_lat-l 15: only above-threshold ops and subops print — including matched slow pairs (client op slow because its replica subop was slow)peers [(0, 7136), (2, 5906)]on the replicated clusterbpftoolstats: ~3.5 µs per subop event (debug build, contended laptop);-lfast path structurally identical to the validated log_op_stats_v2 gate🤖 Generated with Claude Code
https://claude.ai/code/session_01SQMVEJezhKCMbVMWFpNi5B