| Demonstrations of reset-trace, for Linux bcc/BPF. |
| |
| |
| You will probably never need this tool. If you kill -9 a bcc tool (plus other |
| signals, like SIGTERM), or if a bcc tool crashes, then kernel tracing can be |
| left in a semi-enabled state. It's not as bad as it sounds: there may just be |
| overhead for writing to ring buffers that are never read. This tool can be |
| used to clean up the tracing state, and reset and disable active tracing. |
| |
| WARNING: Make sure no other tracing sessions are active, as it will likely |
| stop them from functioning (perhaps ungracefully). |
| |
| This specifically clears the state in at least the following files in |
| /sys/kernel/debug/tracing: kprobe_events, uprobe_events, trace_pipe. |
| Other tracing facilities (ftrace) are checked, and if not in an expected state, |
| a note is printed. All tracing files can be reset with -F for force, but this |
| will interfere with any other running tracing sessions (eg, ftrace). |
| |
| Here's an example: |
| |
| # ./reset-trace.sh |
| # |
| |
| That's it. |
| |
| |
| You can use -v to see what it does: |
| |
| # ./reset-trace.sh -v |
| Resetting tracing state... |
| |
| Checking /sys/kernel/debug/tracing/kprobe_events |
| Checking /sys/kernel/debug/tracing/uprobe_events |
| Checking /sys/kernel/debug/tracing/trace |
| Checking /sys/kernel/debug/tracing/current_tracer |
| Checking /sys/kernel/debug/tracing/set_ftrace_filter |
| Checking /sys/kernel/debug/tracing/set_graph_function |
| Checking /sys/kernel/debug/tracing/set_ftrace_pid |
| Checking /sys/kernel/debug/tracing/events/enable |
| Checking /sys/kernel/debug/tracing/tracing_thresh |
| Checking /sys/kernel/debug/tracing/tracing_on |
| |
| Done. |
| |
| In this example, no resetting was necessary. |
| |
| |
| Here's an example of actually needing it: |
| |
| # ./funccount 'bash:r*' |
| Tracing 317 functions for "bash:r*"... Hit Ctrl-C to end. |
| ^C |
| FUNC COUNT |
| rl_free_undo_list 1 |
| rl_deprep_terminal 1 |
| readline_internal_teardown 1 |
| rl_on_new_line 1 |
| rl_crlf 1 |
| rl_clear_signals 1 |
| rl_prep_terminal 1 |
| rl_reset_line_state 1 |
| rl_initialize 1 |
| rl_newline 1 |
| readline_internal_setup 1 |
| rl_set_screen_size 1 |
| readline 1 |
| rl_set_signals 1 |
| rl_expand_prompt 1 |
| replace_history_data 1 |
| rl_set_prompt 1 |
| rl_add_undo 1 |
| rl_insert_text 2 |
| rl_insert 2 |
| rl_redisplay 3 |
| rl_read_key 3 |
| rl_getc 3 |
| readline_internal_char 3 |
| restore_parser_state 6 |
| reap_dead_jobs 6 |
| reset_parser 6 |
| restore_input_line_state 6 |
| realloc 7 |
| read_octal 10 |
| read_tty_modified 13 |
| run_exit_trap 13 |
| redirection_expand 13 |
| restore_pipestatus_array 18 |
| reader_loop 20 |
| run_return_trap 21 |
| remember_args 25 |
| reset_signal_handlers 30 |
| remove_quoted_escapes 60 |
| run_unwind_frame 102 |
| reset_terminating_signals 125 |
| restore_original_signals 139 |
| reset_internal_getopt 405 |
| run_debug_trap 719 |
| read_command 940 |
| remove_quoted_nulls 1830 |
| run_pending_traps 3207 |
| ^C |
| ^C |
| ^C |
| |
| I've traced 317 functions using funccount, and when I hit Ctrl-C, funccount is |
| not exiting (it can normally take many seconds, but this really looks stuck): |
| |
| # pidstat 1 |
| Linux 4.9.0-rc1-virtual (bgregg-xenial-bpf-i-xxx) 10/18/2016 _x86_64_ (8 CPU) |
| |
| 10:00:33 PM UID PID %usr %system %guest %CPU CPU Command |
| 10:00:34 PM 60004 3277 0.00 0.98 0.00 0.98 0 redis-server |
| 10:00:34 PM 0 27980 87.25 10.78 0.00 98.04 3 funccount.py |
| 10:00:34 PM 0 29965 0.00 0.98 0.00 0.98 6 pidstat |
| |
| 10:00:34 PM UID PID %usr %system %guest %CPU CPU Command |
| 10:00:35 PM 65534 3276 0.00 1.00 0.00 1.00 2 multilog |
| 10:00:35 PM 0 27980 77.00 23.00 0.00 100.00 3 funccount.py |
| 10:00:35 PM 0 29965 0.00 1.00 0.00 1.00 6 pidstat |
| 10:00:35 PM 60004 29990 0.00 1.00 0.00 1.00 6 catalina.sh |
| |
| funccount looks a lot like it's in an infinite loop (I can use a stack-sampling |
| profiler to confirm). This is a known bug (#665) and may be fixed by the time |
| you read this. But right now it's a good example of needing reset-trace. |
| |
| I'll send a SIGTERM, before resorting to a SIGKILL: |
| |
| # kill 27980 |
| Terminated |
| |
| Ok, so the process is now gone, but it did leave tracing in a semi-enabled |
| state. Using reset-trace: |
| |
| # ./reset-trace.sh -v |
| Resetting tracing state... |
| |
| Checking /sys/kernel/debug/tracing/kprobe_events |
| Checking /sys/kernel/debug/tracing/uprobe_events |
| Needed to reset /sys/kernel/debug/tracing/uprobe_events |
| uprobe_events, before (line enumerated): |
| 1 p:uprobes/p__bin_bash_0xa2540 /bin/bash:0x00000000000a2540 |
| 2 p:uprobes/p__bin_bash_0x21220 /bin/bash:0x0000000000021220 |
| 3 p:uprobes/p__bin_bash_0x78530 /bin/bash:0x0000000000078530 |
| 4 p:uprobes/p__bin_bash_0xa3840 /bin/bash:0x00000000000a3840 |
| 5 p:uprobes/p__bin_bash_0x9c550 /bin/bash:0x000000000009c550 |
| 6 p:uprobes/p__bin_bash_0x5e360 /bin/bash:0x000000000005e360 |
| 7 p:uprobes/p__bin_bash_0xb2630 /bin/bash:0x00000000000b2630 |
| 8 p:uprobes/p__bin_bash_0xb1e70 /bin/bash:0x00000000000b1e70 |
| 9 p:uprobes/p__bin_bash_0xb2540 /bin/bash:0x00000000000b2540 |
| 10 p:uprobes/p__bin_bash_0xb16e0 /bin/bash:0x00000000000b16e0 |
| [...] |
| 312 p:uprobes/p__bin_bash_0xa80b0 /bin/bash:0x00000000000a80b0 |
| 313 p:uprobes/p__bin_bash_0x9e280 /bin/bash:0x000000000009e280 |
| 314 p:uprobes/p__bin_bash_0x9e100 /bin/bash:0x000000000009e100 |
| 315 p:uprobes/p__bin_bash_0xb2bd0 /bin/bash:0x00000000000b2bd0 |
| 316 p:uprobes/p__bin_bash_0x9d9c0 /bin/bash:0x000000000009d9c0 |
| 317 p:uprobes/p__bin_bash_0x4a930 /bin/bash:0x000000000004a930 |
| uprobe_events, after (line enumerated): |
| |
| Checking /sys/kernel/debug/tracing/trace |
| Checking /sys/kernel/debug/tracing/current_tracer |
| Checking /sys/kernel/debug/tracing/set_ftrace_filter |
| Checking /sys/kernel/debug/tracing/set_graph_function |
| Checking /sys/kernel/debug/tracing/set_ftrace_pid |
| Checking /sys/kernel/debug/tracing/events/enable |
| Checking /sys/kernel/debug/tracing/tracing_thresh |
| Checking /sys/kernel/debug/tracing/tracing_on |
| |
| Done. |
| |
| Now looks clean. I did truncate the output here: there were a few hundred lines |
| from uprobe_events. |
| |
| Here's the same situation, but without the verbose option: |
| |
| # ./reset-trace.sh |
| Needed to reset /sys/kernel/debug/tracing/uprobe_events |
| # |
| |
| And again with quiet: |
| |
| # ./reset-trace.sh -q |
| # |
| |
| |
| Here is an example of reset-trace detecting an unrelated tracing session: |
| |
| # ./reset-trace.sh |
| Noticed unrelated tracing file /sys/kernel/debug/tracing/set_ftrace_filter isn't set as expected. Not resetting (-F to force, -v for verbose). |
| |
| And verbose: |
| |
| # ./reset-trace.sh -v |
| Resetting tracing state... |
| |
| Checking /sys/kernel/debug/tracing/kprobe_events |
| Checking /sys/kernel/debug/tracing/uprobe_events |
| Checking /sys/kernel/debug/tracing/trace |
| Checking /sys/kernel/debug/tracing/current_tracer |
| Checking /sys/kernel/debug/tracing/set_ftrace_filter |
| Noticed unrelated tracing file /sys/kernel/debug/tracing/set_ftrace_filter isn't set as expected. Not resetting (-F to force, -v for verbose). |
| Contents of set_ftrace_filter is (line enumerated): |
| 1 tcp_send_mss |
| 2 tcp_sendpage |
| 3 tcp_sendmsg |
| 4 tcp_send_dupack |
| 5 tcp_send_challenge_ack.isra.53 |
| 6 tcp_send_rcvq |
| 7 tcp_send_ack |
| 8 tcp_send_loss_probe |
| 9 tcp_send_fin |
| 10 tcp_send_active_reset |
| 11 tcp_send_synack |
| 12 tcp_send_delayed_ack |
| 13 tcp_send_window_probe |
| 14 tcp_send_probe0 |
| Expected "". |
| Checking /sys/kernel/debug/tracing/set_graph_function |
| Checking /sys/kernel/debug/tracing/set_ftrace_pid |
| Checking /sys/kernel/debug/tracing/events/enable |
| Checking /sys/kernel/debug/tracing/tracing_thresh |
| Checking /sys/kernel/debug/tracing/tracing_on |
| |
| Done. |
| |
| So this file is not currently used by bcc, but it may be useful to know that |
| it's not in the default state -- something is either using it or has left it |
| enabled. These files can be reset with -F, but that may break other tools that |
| are currently using them. |
| |
| |
| Use -h to print the USAGE message: |
| |
| # ./reset-trace.sh -h |
| USAGE: reset-trace [-Fhqv] |
| -F # force: reset all tracing files |
| -v # verbose: print details while working |
| -h # this usage message |
| -q # quiet: no output |
| eg, |
| reset-trace # disable semi-enabled tracing |
