summaryrefslogtreecommitdiff
path: root/md/writeup/kernel_debug_messages.md
blob: 02b6fe82e80ffb0273f2916a81bae537bab4abd2 (plain) (blame)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
title: Kernel debug messages
# Kernel debug messages

## Intro

Usaul way how to debug in kernel is by printing messages all over suspicioiuse 
places and figure out where is the problem.

## Loglevel errors

Here is defintions of log levels from __include/linux/kern_levels.h__ 

```c
#define KERN_SOH        "\001" /* ASCII Start Of Header */
#define KERN_SOH_ASCII  '\001'
```

| Name | Value | Descriptop |
| --- | --- | --- |
| KERN_EMERG	| KERN_SOH "0"	| system is unusable |
| KERN_ALERT	| KERN_SOH "1"	| action must be taken immediately |
| KERN_CRIT	| KERN_SOH "2"	| critical conditions |
| KERN_ERR	| KERN_SOH "3"	| error conditions |
| KERN_WARNING	| KERN_SOH "4"	| warning conditions |
| KERN_NOTICE	| KERN_SOH "5"	| normal but significant condition |
| KERN_INFO	| KERN_SOH "6"	| informational |
| KERN_DEBUG	| KERN_SOH "7"	| debug-level messages |
| KERN_DEFAULT	| KERN_SOH "d"	| the default kernel loglevel |

As we can see kernel printk level is detemined from first bytes from begining of
printed string. Basic usage of log level

```
printk(KERN_ERR"Error division by 0\n");
```

No need to write comma after log level as it will just concatenated with string.
[Source](https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/include/linux/printk.h?id=HEAD#n13)

## Set loging level

To see messages in userspace you can use 
```
dmesg
```
Loged messages you can see in __/proc/sys/kernel/printk__
```
$ cat /proc/sys/kernel/printk
	7       4       1       7
```
Column values are
* current - 7
* default - 4
* minimum - 1
* boot-time-default - 7

If one does not specify the log level then the default log level of KERN_WARNING is used. For example, enable all levels of console message:

```
echo 7 > /proc/sys/kernel/printk
```

If you are working on some device all output also could go to /dev/ttyUSB0 and 
if you conected to that device with serial interface then you can see log 
messages in your console. Sometime also /dev/tty1 could be as default output
for log messages.

### Timing information
Timing information could be added to printk messages you need to enable in 
menuconfig 
__Kernel Hacking > printk and dmesg options >__ 

```
CONFIG_PRINTK_TIME=y
```

### Loglevel at kernel boot
There is possible to set loglevel at bootup as kernel parametr
```
loglevel=
```
| Value | Name | Desc |
| --- | --- | --- |
| 0 | (KERN_EMERG)   | system is unusable
| 1 | (KERN_ALERT)   | action must be taken immediately
| 2 | (KERN_CRIT)    | critical conditions
| 3 | (KERN_ERR)     | error conditions
| 4 | (KERN_WARNING) | warning conditions
| 5 | (KERN_NOTICE)  | normal but significant condition
| 6 | (KERN_INFO)    | informational
| 7 | (KERN_DEBUG)   | debug-level messages

### Printk formating

Here is defined formating specifiers __Documentation/printk-formats.txt__

| Type | printk format specifier |
| --- | --- |
| int                |%d or %x|
| unsigned int       |%u or %x|
| long               |%ld or %lx|
| unsigned long      |%lu or %lx|
| long long          |%lld or %llx|
| unsigned long long |%llu or %llx|
| size_t             |%zu or %zx|
| ssize_t            |%zd or %zx|
| s32                |%d or %x|
| u32                |%u or %x|
| s64                |%lld or %llx|
| u64                |%llu or %llx|
| pointer            |%p|
| function pointer with offset      |%pF|
| function pointer without offset |%pf|
| symbol name with offset |%pS|
| symbol name without offset |%ps|
| symbol name with (with __builtin_extract_return_addr() translation) |%pSR|
| symbol name for printing backtraces |%pB|
| printing kernel pointers which should be hidden from unprivilege users |%pk|
| struct resources |%pr|
| struct resources with decoded flags member |%pR|
| phys_addr_t |%pa[p]|
| dma_addr_t |%pad|
| raw buffer as an escaped string |%*pE[achnops]|
| |a - ESCAPE_ANY|
| |c - ESCAPE_SPECIAL|
| |h - ESCAPE_HEX|
| |n - ESCAPE_NULL|
| |o - ESCAPE_OCTAL|
| |p - ESCAPE_NP|
| |s - ESCAPE_SPACE|
| Raw buffer as a hex string | %*ph, %*ph[CDN] |
| MAC/FDDI addresses | %p[M|MR|MF|m|mR] |
| IPv4 addresses | %p[Ii]4[hnbl] |
| IPv6 addresses | %p[I6|i6|I6c] |
| IPv4/IPv6 addresses (generic, with port, flowinfo, scope) | %p[Ii]S[pfschnbl] |
| UUID/GUID addresses | %pU[b|B|l|L] |
| dentry names | %pd{,2,3,4},%pD{,2,3,4} |
| block_device names | %pg |
| struct va_format | %pV |
| struct clk | %pC[nr] |
| bitmap,bitmap,nodemask | %*pb[l] |
| bitfields such as page flags, gfp_flags | %pG[pgv] |
| netdev_features_t | %pNF |

## Shortened printk versions
Header files defines shortcut versions of print functions for each of log level.

| Function names | Note |
| --- | --- |
| pr_emerg | |
| pr_alert | |
| pr_crit | |
| pr_err | |
| pr_warn | |
| pr_notice | |
| pr_info | |
| no_printk | dummy printk without output |
| pr_devel | when DEBUG is defined |
| printk_once | print one time messages |
| printk_deferred_once | |
| pr_*_once | print once loglevel specific|
| printk_ratelimited | |
| pr_*_ratelimited | printk with loglevel and ratelimit |

## Links

1. http://elinux.org/Debugging_by_printing
2. http://elinux.org/Kernel_Debugging_Tips
3. https://wiki.ubuntu.com/Kernel/KernelDebuggingTricks
4. [Documentation/printk-formats.txt](https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/Documentation/printk-formats.txt?id=HEAD)
5. [include/linux/printk.h](https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/include/linux/printk.h?id=HEAD)
6. [include/linux/kern_levels.h](https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/include/linux/kern_levels.h?id=HEAD)
7. [lib/Kconfig.debug](https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/lib/Kconfig.debug?id=HEAD)
8. [Documentation/kernel-parameters.txt](https://www.kernel.org/doc/Documentation/kernel-parameters.txt)