1Demonstrations of reset-trace, for Linux bcc/BPF. 2 3 4You will probably never need this tool. If you kill -9 a bcc tool (plus other 5signals, like SIGTERM), or if a bcc tool crashes, then kernel tracing can be 6left in a semi-enabled state. It's not as bad as it sounds: there may just be 7overhead for writing to ring buffers that are never read. This tool can be 8used to clean up the tracing state, and reset and disable active tracing. 9 10WARNING: Make sure no other tracing sessions are active, as it will likely 11stop them from functioning (perhaps ungracefully). 12 13This specifically clears the state in at least the following files in 14/sys/kernel/debug/tracing: kprobe_events, uprobe_events, trace_pipe. 15Other tracing facilities (ftrace) are checked, and if not in an expected state, 16a note is printed. All tracing files can be reset with -F for force, but this 17will interfere with any other running tracing sessions (eg, ftrace). 18 19Here's an example: 20 21# ./reset-trace.sh 22# 23 24That's it. 25 26 27You can use -v to see what it does: 28 29# ./reset-trace.sh -v 30Reseting tracing state... 31 32Checking /sys/kernel/debug/tracing/kprobe_events 33Checking /sys/kernel/debug/tracing/uprobe_events 34Checking /sys/kernel/debug/tracing/trace 35Checking /sys/kernel/debug/tracing/current_tracer 36Checking /sys/kernel/debug/tracing/set_ftrace_filter 37Checking /sys/kernel/debug/tracing/set_graph_function 38Checking /sys/kernel/debug/tracing/set_ftrace_pid 39Checking /sys/kernel/debug/tracing/events/enable 40Checking /sys/kernel/debug/tracing/tracing_thresh 41Checking /sys/kernel/debug/tracing/tracing_on 42 43Done. 44 45In this example, no resetting was necessary. 46 47 48Here's an example of actually needing it: 49 50# ./funccount 'bash:r*' 51Tracing 317 functions for "bash:r*"... Hit Ctrl-C to end. 52^C 53FUNC COUNT 54rl_free_undo_list 1 55rl_deprep_terminal 1 56readline_internal_teardown 1 57rl_on_new_line 1 58rl_crlf 1 59rl_clear_signals 1 60rl_prep_terminal 1 61rl_reset_line_state 1 62rl_initialize 1 63rl_newline 1 64readline_internal_setup 1 65rl_set_screen_size 1 66readline 1 67rl_set_signals 1 68rl_expand_prompt 1 69replace_history_data 1 70rl_set_prompt 1 71rl_add_undo 1 72rl_insert_text 2 73rl_insert 2 74rl_redisplay 3 75rl_read_key 3 76rl_getc 3 77readline_internal_char 3 78restore_parser_state 6 79reap_dead_jobs 6 80reset_parser 6 81restore_input_line_state 6 82realloc 7 83read_octal 10 84read_tty_modified 13 85run_exit_trap 13 86redirection_expand 13 87restore_pipestatus_array 18 88reader_loop 20 89run_return_trap 21 90remember_args 25 91reset_signal_handlers 30 92remove_quoted_escapes 60 93run_unwind_frame 102 94reset_terminating_signals 125 95restore_original_signals 139 96reset_internal_getopt 405 97run_debug_trap 719 98read_command 940 99remove_quoted_nulls 1830 100run_pending_traps 3207 101^C 102^C 103^C 104 105I've traced 317 functions using funccount, and when I hit Ctrl-C, funccount is 106not exiting (it can normally take many seconds, but this really looks stuck): 107 108# pidstat 1 109Linux 4.9.0-rc1-virtual (bgregg-xenial-bpf-i-xxx) 10/18/2016 _x86_64_ (8 CPU) 110 11110:00:33 PM UID PID %usr %system %guest %CPU CPU Command 11210:00:34 PM 60004 3277 0.00 0.98 0.00 0.98 0 redis-server 11310:00:34 PM 0 27980 87.25 10.78 0.00 98.04 3 funccount.py 11410:00:34 PM 0 29965 0.00 0.98 0.00 0.98 6 pidstat 115 11610:00:34 PM UID PID %usr %system %guest %CPU CPU Command 11710:00:35 PM 65534 3276 0.00 1.00 0.00 1.00 2 multilog 11810:00:35 PM 0 27980 77.00 23.00 0.00 100.00 3 funccount.py 11910:00:35 PM 0 29965 0.00 1.00 0.00 1.00 6 pidstat 12010:00:35 PM 60004 29990 0.00 1.00 0.00 1.00 6 catalina.sh 121 122funccount looks a lot like it's in an infinite loop (I can use a stack-sampling 123profiler to confirm). This is a known bug (#665) and may be fixed by the time 124you read this. But right now it's a good example of needing reset-trace. 125 126I'll send a SIGTERM, before resorting to a SIGKILL: 127 128# kill 27980 129Terminated 130 131Ok, so the process is now gone, but it did leave tracing in a semi-enabled 132state. Using reset-trace: 133 134# ./reset-trace.sh -v 135Reseting tracing state... 136 137Checking /sys/kernel/debug/tracing/kprobe_events 138Checking /sys/kernel/debug/tracing/uprobe_events 139Needed to reset /sys/kernel/debug/tracing/uprobe_events 140uprobe_events, before (line enumerated): 141 1 p:uprobes/p__bin_bash_0xa2540 /bin/bash:0x00000000000a2540 142 2 p:uprobes/p__bin_bash_0x21220 /bin/bash:0x0000000000021220 143 3 p:uprobes/p__bin_bash_0x78530 /bin/bash:0x0000000000078530 144 4 p:uprobes/p__bin_bash_0xa3840 /bin/bash:0x00000000000a3840 145 5 p:uprobes/p__bin_bash_0x9c550 /bin/bash:0x000000000009c550 146 6 p:uprobes/p__bin_bash_0x5e360 /bin/bash:0x000000000005e360 147 7 p:uprobes/p__bin_bash_0xb2630 /bin/bash:0x00000000000b2630 148 8 p:uprobes/p__bin_bash_0xb1e70 /bin/bash:0x00000000000b1e70 149 9 p:uprobes/p__bin_bash_0xb2540 /bin/bash:0x00000000000b2540 150 10 p:uprobes/p__bin_bash_0xb16e0 /bin/bash:0x00000000000b16e0 151[...] 152 312 p:uprobes/p__bin_bash_0xa80b0 /bin/bash:0x00000000000a80b0 153 313 p:uprobes/p__bin_bash_0x9e280 /bin/bash:0x000000000009e280 154 314 p:uprobes/p__bin_bash_0x9e100 /bin/bash:0x000000000009e100 155 315 p:uprobes/p__bin_bash_0xb2bd0 /bin/bash:0x00000000000b2bd0 156 316 p:uprobes/p__bin_bash_0x9d9c0 /bin/bash:0x000000000009d9c0 157 317 p:uprobes/p__bin_bash_0x4a930 /bin/bash:0x000000000004a930 158uprobe_events, after (line enumerated): 159 160Checking /sys/kernel/debug/tracing/trace 161Checking /sys/kernel/debug/tracing/current_tracer 162Checking /sys/kernel/debug/tracing/set_ftrace_filter 163Checking /sys/kernel/debug/tracing/set_graph_function 164Checking /sys/kernel/debug/tracing/set_ftrace_pid 165Checking /sys/kernel/debug/tracing/events/enable 166Checking /sys/kernel/debug/tracing/tracing_thresh 167Checking /sys/kernel/debug/tracing/tracing_on 168 169Done. 170 171Now looks clean. I did truncate the output here: there were a few hundred lines 172from uprobe_events. 173 174Here's the same situation, but without the verbose option: 175 176# ./reset-trace.sh 177Needed to reset /sys/kernel/debug/tracing/uprobe_events 178# 179 180And again with quiet: 181 182# ./reset-trace.sh -q 183# 184 185 186Here is an example of reset-trace detecting an unrelated tracing session: 187 188# ./reset-trace.sh 189Noticed unrelated tracing file /sys/kernel/debug/tracing/set_ftrace_filter isn't set as expected. Not reseting (-F to force, -v for verbose). 190 191And verbose: 192 193# ./reset-trace.sh -v 194Reseting tracing state... 195 196Checking /sys/kernel/debug/tracing/kprobe_events 197Checking /sys/kernel/debug/tracing/uprobe_events 198Checking /sys/kernel/debug/tracing/trace 199Checking /sys/kernel/debug/tracing/current_tracer 200Checking /sys/kernel/debug/tracing/set_ftrace_filter 201Noticed unrelated tracing file /sys/kernel/debug/tracing/set_ftrace_filter isn't set as expected. Not reseting (-F to force, -v for verbose). 202Contents of set_ftrace_filter is (line enumerated): 203 1 tcp_send_mss 204 2 tcp_sendpage 205 3 tcp_sendmsg 206 4 tcp_send_dupack 207 5 tcp_send_challenge_ack.isra.53 208 6 tcp_send_rcvq 209 7 tcp_send_ack 210 8 tcp_send_loss_probe 211 9 tcp_send_fin 212 10 tcp_send_active_reset 213 11 tcp_send_synack 214 12 tcp_send_delayed_ack 215 13 tcp_send_window_probe 216 14 tcp_send_probe0 217Expected "". 218Checking /sys/kernel/debug/tracing/set_graph_function 219Checking /sys/kernel/debug/tracing/set_ftrace_pid 220Checking /sys/kernel/debug/tracing/events/enable 221Checking /sys/kernel/debug/tracing/tracing_thresh 222Checking /sys/kernel/debug/tracing/tracing_on 223 224Done. 225 226So this file is not currently used by bcc, but it may be useful to know that 227it's not in the default state -- something is either using it or has left it 228enabled. These files can be reset with -F, but that may break other tools that 229are currently using them. 230 231 232Use -h to print the USAGE message: 233 234# ./reset-trace.sh -h 235USAGE: reset-trace [-Fhqv] 236 -F # force: reset all tracing files 237 -v # verbose: print details while working 238 -h # this usage message 239 -q # quiet: no output 240 eg, 241 reset-trace # disable semi-enabled tracing 242