Skip to content

report hung radostrace ops on interrupt - #92

Merged
taodd merged 4 commits into
taodd:mainfrom
zhhuabj:detect_hang_ops_with_radostrace
Sep 2, 2026
Merged

report hung radostrace ops on interrupt#92
taodd merged 4 commits into
taodd:mainfrom
zhhuabj:detect_hang_ops_with_radostrace

Conversation

@zhhuabj

@zhhuabj zhhuabj commented May 13, 2026

Copy link
Copy Markdown
Contributor

Handle SIGINT without exiting immediately so radostrace can dump operations still pending in the BPF ops map before cleanup.

  • add SIGINT state tracking in radostrace
  • iterate the ops BPF map and print unfinished operations
  • include stuck duration, client, tid, target osd, object, and rw mode
  • return cleanly after interrupt/timeout-triggered shutdown

@zhhuabj

zhhuabj commented May 13, 2026

Copy link
Copy Markdown
Contributor Author

test result - https://paste.ubuntu.com/p/FvpMC8XsCX/

Comment thread src/radostrace.cc Outdated
clog << "process killed" << endl;
got_sigint = 1;
} else {
exit(signum);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

exit(3) isn't a async-signal-safe function: https://www.man7.org/linux/man-pages/man7/signal-safety.7.html

better to use _exit() instead.

The same concern is applicable for clog too. We need to review "signal safety" across the codease. But that can be done separately later.

Comment thread src/radostrace.cc Outdated
int found = 0;

memset(&key, 0, sizeof(key));
while (bpf_map_get_next_key(map_fd, &key, &next_key) == 0) {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To get the first key that's not in the map, bpf_map_get_next_key needs to be called with NULL as key. But a valid "key" is passed now (key is zero-initalized but it's not NULL), so this is likely to miss the correct first key.

struct client_op_k *cur = NULL;
while (bpf_map_get_next_key(map_fd, cur, &next_key) == 0) {
    if (bpf_map_lookup_elem(map_fd, &next_key, &val) == 0) {
        ...
    }
    key = next_key;
    cur = &key;
}

would fix it.

@pponnuvel

Copy link
Copy Markdown
Collaborator

I also think "hung ops" better describes than "hang ops", so suggest name changes as such.

@zhhuabj
zhhuabj force-pushed the detect_hang_ops_with_radostrace branch 2 times, most recently from aa20743 to b05de17 Compare May 14, 2026 14:16

@taodd taodd left a comment

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We also need to add a test to deliberately cause a hang Op

Comment thread src/radostrace.bpf.c Outdated
}
if (name_len > 0) {
bpf_probe_read_user(val->object_name, name_len, (void *)name_base);
}

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's keep the original code here

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

done

Comment thread src/radostrace.cc Outdated
@zhhuabj
zhhuabj force-pushed the detect_hang_ops_with_radostrace branch from b05de17 to 762503a Compare May 19, 2026 04:10
@zhhuabj

zhhuabj commented May 19, 2026

Copy link
Copy Markdown
Contributor Author

test result in microceph - https://paste.ubuntu.com/p/9NqMgrcz4K/
test result in openstack - https://paste.ubuntu.com/p/Dtg36rVNx8/

@taodd

taodd commented May 19, 2026

Copy link
Copy Markdown
Owner

Thanks @zhhuabj

  1. The incomplete operations are missing the pid value, we can get the pid value from the send_op function instead of the finish_op function.
  2. To simplify the output, instead of naming the new column as "status" and filled with words "complete" and "incomplete", we can name the column to "Complete" with value of "1" or "0" to indicate whether the operation is complete or not.
  3. Another suggestion is that we don't need to separate the output between complete and incomplete ops. Put all of them together would be fine and easy to process by the analyzer

@taodd

taodd commented May 19, 2026

Copy link
Copy Markdown
Owner

Also, the patch needs to be rebased

@zhhuabj
zhhuabj force-pushed the detect_hang_ops_with_radostrace branch from 762503a to f67ffe2 Compare May 22, 2026 10:49
@zhhuabj

zhhuabj commented May 22, 2026

Copy link
Copy Markdown
Contributor Author

Thanks @zhhuabj

  1. The incomplete operations are missing the pid value, we can get the pid value from the send_op function instead of the finish_op function.
  2. To simplify the output, instead of naming the new column as "status" and filled with words "complete" and "incomplete", we can name the column to "Complete" with value of "1" or "0" to indicate whether the operation is complete or not.
  3. Another suggestion is that we don't need to separate the output between complete and incomplete ops. Put all of them together would be fine and easy to process by the analyzer

Hi @dongdong, Thank you for the feedback! I've addressed all three suggestions:

1, pid from send_op: Moved val->pid = get_pid() to uprobe_send_op so incomplete ops also have a valid pid.
2, Complete column with 0/1: Renamed the status column to Complete and replaced "complete"/"incomplete" strings with "1"/"0" for easier filtering.
3, Unified output: Merged complete and incomplete ops into a single output stream — completed ops print with Complete=1 as they arrive, incomplete ops print with Complete=0 at flush time.

and here is the latest test result - https://paste.ubuntu.com/p/3sSGqb3WGv/

@zhhuabj
zhhuabj force-pushed the detect_hang_ops_with_radostrace branch from f67ffe2 to cf846e9 Compare May 22, 2026 14:44
@zhhuabj
zhhuabj force-pushed the detect_hang_ops_with_radostrace branch from cf846e9 to 8f8b0ba Compare August 20, 2026 06:54
@zhhuabj

zhhuabj commented Aug 20, 2026

Copy link
Copy Markdown
Contributor Author

test results:
radostrace_complete_test.log - https://pastebin.com/3NskVFsr
radostrace_sigint_test.log - https://pastebin.com/aJfs7zFB
radostrace_timeout_final.log - https://pastebin.com/E2ahamUy

radostrace previously discarded operations that were still present in
the BPF ops map when tracing stopped. This made hung or slow operations
invisible when the user interrupted tracing or a timeout expired.

Track pending operations until completion and report entries remaining
in the BPF map during shutdown. Completed and incomplete operations use
the same output format, with the Complete column set to 1 or 0.

Detach the probes and drain completed events before reporting pending
operations to avoid classifying newly completed operations as
incomplete.

Add a functional test that suspends an OSD with SIGSTOP and verifies
that pending operations are reported.

Signed-off-by: Zhang Hua <joshua.zhang@canonical.com>
@taodd
taodd force-pushed the detect_hang_ops_with_radostrace branch from 8f8b0ba to 9849fb4 Compare September 2, 2026 03:17
The "Reporting pending ops" and "Total reported ops" lines were written
to unbuffered stderr while the rows went through buffered stdout, so with
output redirected to a file the status lines could land in the middle of
a row. Drop them: the Complete column already marks pending rows. Flush
stdout before the final cleanup log line for the same reason.

Return a nonzero exit code when ring buffer setup fails; the path jumped
to cleanup with ret still 0 and exited 0.

Fix the indentation of the new helpers.
Add the Complete column to the sample output in README and
doc/radostrace.md, describe it in the column table and CSV section, and
add an "Incomplete Operations" section explaining the rows printed on
Ctrl-C or timeout.

Tests: _radostrace_rows now emits the Complete flag as its own field,
both radostrace verifiers read it and reject anything other than 0 or 1,
and the qemu test reads the extra field. The hung-op step in the
microceph test uses _radostrace_rows instead of its own awk so the
column layout lives in one place. Fix comments that still referred to
the old NF >= 10 predicate.
pgrep -f "ceph-osd" matches any process whose command line contains the
string, including a shell running a script that mentions it, so the
hung-op step could SIGSTOP the wrong process. Use pgrep -x so only the
ceph-osd and rados executables match.

@taodd taodd left a comment

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@taodd
taodd merged commit 05dcdc5 into taodd:main Sep 2, 2026
23 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants