Random Kernel Debugging Tips
All-zero address shown when do cat /proc/modules
echo 0 > /proc/sys/kernel/kptr_restrict
# or with sysctl
sysctl kernel.kptr_restrict=0
e.g.
# cat /proc/modules
pstore 53248 0 - Live 0x0000000000000000
# sysctl kernel.kptr_restrict=0
# cat /proc/modules
pstore 53248 0 - Live 0xffffff9001c60000
Find kernel module load address
# cat /sys/module/pstore/sections/.text
0xffffff9001c60000
# cat /proc/modules
pstore 53248 0 - Live 0xffffff9001c60000
There are some other interesting stuff under directory sections:
# ls -a /sys/module/pstore/sections
. .init.text .text
.. .init_array .text.exit
.bss .note.Linux .text.ftrace_trampoline
.data .note.gnu.build-id .text.startup
.data..ro_after_init .plt __bug_table
.eh_frame .rodata __kcrctab_gpl
.exit.text .rodata.str __ksymtab_gpl
.fini_array .rodata.str1.8 __ksymtab_strings
.gnu.linkonce.this_module .strtab __mcount_loc
.init.plt .symtab __param
Pointer address not printed with format %p in printk
[ 5.610054] dwc_otg 3f980000.usb: base=(____ptrval____)
[ 6.193829] vchiq: vchiq_init_state: slot_zero = (____ptrval____), is_master = 0
Use %px instead, refer to printk-formats for more details.
Frequently used tools
gdb list command
aarch64-linux-gnu-addr2line -fe option
aarch64-linux-gnu-objdump -dS option
add initcall_debug to kernel command line parameter to see init sequence
[ 0.051827] calling cpu_stop_init+0x0/0x218 @ 1
[ 0.055580] initcall cpu_stop_init+0x0/0x218 returned 0 after 2929 usecs
[ 0.055704] calling init_events+0x0/0x16c @ 1
[ 0.055881] initcall init_events+0x0/0x16c returned 0 after 0 usecs
[ 0.056004] calling init_trace_printk+0x0/0x24 @ 1
[ 0.056139] initcall init_trace_printk+0x0/0x24 returned 0 after 0 usecs
[ 0.056390] calling event_trace_enable_again+0x0/0xfc @ 1
[ 0.056531] initcall event_trace_enable_again+0x0/0xfc returned 0 after 0 usecs
[ 0.056663] calling jump_label_init_module+0x0/0x28 @ 1
[ 0.056806] initcall jump_label_init_module+0x0/0x28 returned 0 after 0 usecs
[ 0.056939] calling its_pmsi_init+0x0/0x200 @ 1
[ 0.057727] initcall its_pmsi_init+0x0/0x200 returned 0 after 976 usecs
[ 0.057858] calling rand_initialize+0x0/0x268 @ 1
[ 0.060564] initcall rand_initialize+0x0/0x268 returned 0 after 1953 usecs
You can sort the duration with below command to see which part cost time most:
dmesg -s 128000 | grep "initcall" | sed "s/\(.*\)after\(.*\)/\2 \1/g" | sort -n
This is how it looks like after sorting (omitting some lines):
1 usecs [ 6.478152] initcall statistic_mt_init+0x0/0x28 returned 0
1 usecs [ 6.479240] initcall u32_mt_init+0x0/0x28 returned 0
1 usecs [ 6.675807] initcall max_swapfiles_check+0x0/0x20 returned 0
2 usecs [ 6.454905] initcall nf_nat_amanda_init+0x0/0x74 returned 0
2 usecs [ 6.455861] initcall nf_nat_tftp_init+0x0/0x74 returned 0
... ...
32472 usecs [ 8.578399] initcall genpd_debug_init+0x0/0x1f0 returned 0
51804 usecs [ 8.644049] initcall regulatory_init_db+0x0/0x418 returned 0
78080 usecs [ 6.589763] initcall inet6_init+0x0/0x658 returned 0
1803565 usecs [ 8.543766] initcall deferred_probe_initcall+0x0/0x118 returned 0
18538866 usecs [ 27.639963] initcall init_kgdboc+0x0/0x78 returned 0
What does those characters mean in system.map or /proc/kallsyms
System.map is a look-up table between kernel symbols and addresses, these characters between addresses and symbols are symbol types:
ffffff900a1c819c t trace_event_define_fields_task_rename
ffffff900a1c82a4 t coredump_filter_setup
ffffff900a1c82f0 W arch_task_cache_init
ffffff900a1c830c T fork_init
ffffff900a1c856c T proc_caches_init
ffffff900a1c86d0 t register_warn_debugfs
ffffff900a1c8710 t oops_setup
ffffff900a1a6844 r _note_54
ffffff900a26b704 W vmemmap_populate_print_last
ffffff900a28045c R __alt_instructions
ffffff900a2a8ab8 R __alt_instructions_end
Most commonly seen types are:
A for absolute
B or b for uninitialized data section (called BSS)
D or d for initialized data section
G or g for initialized data section for small objects (global)
i for sections specific to DLLs
N for debugging symbol
p for stack unwind section
R or r for read only data section
S or s for uninitialized data section for small objects
T or t for text (code) section
U for undefined
V or v for weak object
W or w for weak objects which have not been tagged so
- for stabs symbol in an a.out object file
? for "symbol type unknown"
What does those numbers mean in /proc/sys/kernel/printk
# cat /proc/sys/kernel/printk
7 4 1 7
The four values define printk log levels for:
| console_loglevel | messages with a higher priority than this will be printed to the console |
| default_message_loglevel | messages without an explicit priority will be printed with this priority |
| minimum_console_loglevel | minimum (highest) value to which console_loglevel can be set |
| default_console_loglevel | default value for console_loglevel |
The console_loglevel can be changed with echo or dmesg with -n option:
echo 1 > /proc/sys/kernel/printk
dmesg -n1