diff --git a/README.md b/README.md index ca2655f..419015a 100644 --- a/README.md +++ b/README.md @@ -78,13 +78,17 @@ or in QEMU: Show serial output of QEMU directly on the current terminal, without opening a QEMU window: - ./run -n + ./runqemu -n To exit, just do a regular: poweroff -This is particularly useful to get full panic traces when you start making the kernel crash :-) See also: +This mode is very useful to: + +- get full panic traces when you start making the kernel crash :-) See also: +- copy and paste commands and stdout output to / from host +- have a large scroll buffer, and be able to search it, e.g. by using GNU `screen` on host If the system crashes, you can't can quit QEMU with `poweroff`, but you can use either: @@ -111,6 +115,11 @@ See also: - - +TODO: Ctrl + C kills the emulator, it is not sent to guest processes. See: + +- +- + ## Debugging To GDB the Linux kernel, first run: @@ -238,9 +247,6 @@ Debug: ARM TODOs: - only managed to run in the terminal interface (but weirdly a blank QEMU window is still opened) -- Ctrl + C kills the emulator, not sent to guest. See: - - - - - GDB not connecting to KGDB. Possibly linked to `-serial stdio`. See also: ## KGDB @@ -355,6 +361,7 @@ You can still send key presses to QEMU however even without the mouse capture, j 1. [Build](build.md) 1. [kmod](kmod.md) 1. [vermagic](vermagic.md) +1. [ftrace](ftrace.md) 1. [Bibliography](bibliography.md) 1. Examples 1. [Host](host/) diff --git a/buildroot_config_fragment b/buildroot_config_fragment index 0b41fd4..1fbcd2e 100644 --- a/buildroot_config_fragment +++ b/buildroot_config_fragment @@ -32,3 +32,6 @@ BR2_PACKAGE_HOST_QEMU_VDE2=y #BR2_DEBUG_3=y #BR2_ENABLE_DEBUG=y #BR2_OPTIMIZE_0=y + +# ftrace +BR2_PACKAGE_TRACE_CMD=y diff --git a/ftrace.md b/ftrace.md new file mode 100644 index 0000000..2164290 --- /dev/null +++ b/ftrace.md @@ -0,0 +1,87 @@ +# ftrace + +Trace a single function: + + cd /sys/kernel/debug/tracing/ + + # Stop tracing. + echo 0 > tracing_on + + # Clear previous trace. + echo '' > trace + + echo 1 > max_graph_depth + + # List the available tracers, and pick one. + cat available_tracers + echo function > current_tracer + + # List all functions that can be traced + # cat available_filter_functions + # Choose one. + echo __kmalloc >set_ftrace_filter + # Confirm that only __kmalloc is enabled. + cat enabled_functions + + echo 1 > tracing_on + + # Latest events. + head trace + + # Observe trace continously, and drain seen events out. + cat trace_pipe + +Sample output: + + # tracer: function + # + # entries-in-buffer/entries-written: 97/97 #P:1 + # + # _-----=> irqs-off + # / _----=> need-resched + # | / _---=> hardirq/softirq + # || / _--=> preempt-depth + # ||| / delay + # TASK-PID CPU# |||| TIMESTAMP FUNCTION + # | | | |||| | | + head-228 [000] .... 825.534637: __kmalloc <-load_elf_phdrs + head-228 [000] .... 825.534692: __kmalloc <-load_elf_binary + head-228 [000] .... 825.534815: __kmalloc <-load_elf_phdrs + head-228 [000] .... 825.550917: __kmalloc <-__seq_open_private + head-228 [000] .... 825.550953: __kmalloc <-tracing_open + head-229 [000] .... 826.756585: __kmalloc <-load_elf_phdrs + head-229 [000] .... 826.756627: __kmalloc <-load_elf_binary + head-229 [000] .... 826.756719: __kmalloc <-load_elf_phdrs + head-229 [000] .... 826.773796: __kmalloc <-__seq_open_private + head-229 [000] .... 826.773835: __kmalloc <-tracing_open + head-230 [000] .... 827.174988: __kmalloc <-load_elf_phdrs + head-230 [000] .... 827.175046: __kmalloc <-load_elf_binary + head-230 [000] .... 827.175171: __kmalloc <-load_elf_phdrs + +Trace all possible functions, and draw a call graph: + + echo 1 > events/enable + echo function_graph > current_tracer + +Sample output: + + # CPU DURATION FUNCTION CALLS + # | | | | | | | + 0) 2.173 us | } /* ntp_tick_length */ + 0) | timekeeping_update() { + 0) 4.176 us | ntp_get_next_leap(); + 0) 5.016 us | update_vsyscall(); + 0) | raw_notifier_call_chain() { + 0) 2.241 us | notifier_call_chain(); + 0) + 19.879 us | } + 0) 3.144 us | update_fast_timekeeper(); + 0) 2.738 us | update_fast_timekeeper(); + 0) ! 117.147 us | } + 0) | _raw_spin_unlock_irqrestore() { + 0) 4.045 us | _raw_write_unlock_irqrestore(); + 0) + 22.066 us | } + 0) ! 265.278 us | } /* update_wall_time */ + +TODO: what do `+` and `!` mean? + +Each `enable` under the `events/` tree enables a certain set of functions, the higher the `enable` more functions are enabled. diff --git a/kernel_config_fragment b/kernel_config_fragment index bd32212..fb1b915 100644 --- a/kernel_config_fragment +++ b/kernel_config_fragment @@ -39,3 +39,16 @@ CONFIG_SERIAL_KGDB_NMI=n # at insmod, but bgrep did not find it in kernel image. # Does not show in /proc/kallyms either. CONFIG_MODVERSIONS=y + +# ftrace +CONFIG_DYNAMIC_FTRACE=y +CONFIG_FTRACE=y +CONFIG_FTRACE_SYSCALLS=y +CONFIG_FUNCTION_GRAPH_TRACER=y +CONFIG_FUNCTION_PROFILER=y +CONFIG_FUNCTION_TRACER=y +CONFIG_HWLAT_TRACER=y +CONFIG_IRQSOFF_TRACER=y +CONFIG_SCHED_TRACER=y +CONFIG_STACK_TRACER=y +CONFIG_TRACER_SNAPSHOT=y