Linux system Driven Development Debugging Technology Guide Tutorial

first, the use of PRINTK

This is the most unadorned, and most commonly used, and effective means of driving development. The scull-driven main.c No. 338 line Below is the example of using PRINTK for debugging, and this example is believed to be ubiquitous when reading the driving source code.

PRINTK (Kern_alert "wakeup by signal in process%dn", current->;p ID);

The PRINTK function is the same as the printf we often use in the application, except that PRINTK can precede the print string with a kernel-defined macro, such as the Kern_alert in the example above (note: there is no comma between the macro and the string):

#define Kern_emerg ""
#define Kern_alert ""
#define KERN_CRIT ""
#define KERN_ERR ""
#define Kern_warning ""
#define Kern_notice ""
#define KERN_INFO ""
#define KERN_DEBUG ""
#define DEFAULT_CONSOLE_LOGLEVEL 7

This macro is used to define the level of the string that needs to be printed, and the smaller the value, the higher the level. A parameter in the kernel is used to control whether the PRINTK printed string is output to the console (screen or/sys/log/syslog log file)

# CAT/PROC/SYS/KERNEL/PRINTK
6 4 1 7

The first 6 indicates that a message with a level above (less than) 6 is output to the console. The second 4 means that if the message level (macro) is not specified when the PRINTK is invoked, the message level is 4, and the third 1 indicates that the highest (minimum) level of acceptance is 1, and the fourth 7 indicates that the first 6 of the original value at the time the system was started is 7.

Therefore, if you find that the output of some PRINTK in your program is not visible on the console, use echo 8 >/PROC/SYS/KERNEL/PRINTK to resolve it.

In the complex drive development process, we add hundreds of PRINTK statements to the source code in order to debug. And when debugging finished forming the final product is bound to delete these PRINTK statements (why?) Think of yourself as the driver of the user rather than the developer. Remember: Do unto others, others, this is not a small amount of work. Most of all, if we delete the debug PRINTK statement and the user reports that our driver has bugs, we have to manually add these thousands of PRINTK statements again. OMG, kill me. So, we need a way to easily turn on and off debugging information. Where can we find such a means? Haha, far away, in sight. Look at the scull-driven or LEDs-driven source code!

#define Leds_debug
#undef Pdebug
#ifdef Leds_debug
#ifdef __kernel__

#define PDEBUG (FMT, args ...) printk (Kern_emerg "LEDs:" FMT, # # args)
#else

#define PDEBUG (FMT, args ...) fprintf (stderr, FMT, # # args)
#endif
#else
#define PDEBUG (FMT, args ...)
#endif
#undef Pdebugg
#define PDEBUGG (FMT, args ...)

Thus, in the development drive process, if you want to print debug messages, we can use Pdebug ("Address of I_cdev is%pn", Inode->i_cdev); , if you don't want to see the debug message, simply change the pdebug to Pdebugg. And when we have finished debugging and forming the final product, simply comment out the 1th line.
The __kernel__ in the upper section of the code is the macro defined in the kernel, which is defined when we compile the kernel (including the module). Of course, if you don't understand the code ... and # #是什么意思的话, please check gcc about the preprocessing section of the information! If you're too lazy to check in, act as a VC engineer and copy the code to your code.

Second, view OOP messages

Oop means surprise. When you have a problem with the driver, the kernel is not surprised: Hey! Boy, why are you doing this? Well, let's see how the kernel is surprised.
Compile the Faulty.ko according to FAULTY.C and Insmod Faulty.ko. Performing echo Yang >/dev/faulty, the result is a surprise to the kernel. Why is the kernel surprised? Because the faulty-driven write function executes the * (int *) 0 = 0, writes to the memory 0 address, which is absolutely not allowed by the kernel.

ssize_t faulty_write (struct file *filp, const char __user *buf, size_t count, loff_t *pos)
{
* (int *) 0 = 0;

return 0;
}

Unable to handle kernel NULL pointer dereference in virtual Address 00000000
PGD = c3894000
[00000000] *pgd=33830031, *pte=00000000, *ppte=00000000
Internal error:oops:817 [#1] Preempt
Modules linked in:faulty Scull
Cpu:0 not tainted (2.6.22.6 #4)
PC is at faulty_write+0x10/0x18 [faulty]
LR is at vfs_write+0xc4/0x148
PC: [] LR: [] psr:a0000013
Sp:c3871f44 ip:c3871f54 FP:C3871F50
r10:4021765c r9:c3870000 r8:00000000
r7:00000004 r6:c3871f78 r5:40016000 r4:c38e5160
r3:c3871f78 r2:00000004 r1:40016000 r0:00000000
FLAGS:NZCV IRQs on Fiqs on Mode svc_32 Segment user
control:c000717f table:33894000 dac:00000015
Process sh (pid:745, stack limit = 0xc3870258)
Stack: (0xc3871f44 to 0xc3872000)
1f40:c3871f74 c3871f54 c0088eb8 bf00608c 00000004 c38e5180
1f60:c3871f78 00000000 c3871fa4 c3871f78 c0088ffc C0088e04 00000000 00000000
1f80:00000000 00000004 40016000 40215730 00000004 C002c0e4 00000000 C3871fa8
1fa0:c002bf40 c0088fc0 00000004 40016000 00000001 40016000 00000004 00000000
1fc0:00000004 40016000 40215730 00000004 00000001 00000000 4021765c 00000000
1fe0:00000000 bea60964 0000266c 401adb40 60000010 00000001 00000000 00000000
BackTrace:
[] (faulty_write+0x0/0x18 [faulty]) from [] (vfs_write+0xc4/0x148)
[] (vfs_write+0x0/0x148) from [] (sys_write+0x4c/0x74)
r7:00000000 r6:c3871f78 r5:c38e5160 r4:c38e5180
[] (sys_write+0x0/0x74) from [] (RET_FAST_SYSCALL+0X0/0X2C)
R8:c002c0e4 r7:00000004 r6:40215730 r5:40016000 r4:00000004
code:e1a0c00d e92dd800 e24cb004 e3a00000 (e5800000)

1 lines of surprise, which is the cause of the report error;
2-4 Line is the OOP information sequence number;
5 line is the kernel loaded module when the error occurs;
6 line is the CPU serial number where the error occurred;
7-15 lines is where the error occurred, and the value of the CPU registers at that time, which is most helpful for us to find the location of the problem;
Line 16 is the name of the current process and the process ID
17-23 line is an error, the contents of the stack
24-29 rows are stack backtracking information, and can be seen until the function of the progressive call relationship (make sure config_frame_pointer is defined)
30 line is the machine code of the error instruction and its nearby instruction, the error instruction itself is in the parentheses

Disassembly Faulty.ko:

arm-linux-objdump-d Faulty.ko > Faulty.dis Cat Faulty.dis

You can see the following statement as follows:

0000007C:
7C:E1A0C00D mov IP, SP
80:e92dd800 Stmdb sp!, {fp, IP, LR, PC}
84:e24cb004 Sub fp, IP, #4; 0x4
88:e3a00000 mov r0, #0; 0x0
8c:e5800000 str r0, [R0]
90:e89da800 Ldmia sp, {fp, SP, PC}

The process of locating an error location and obtaining relevant information:

9 PC: [] LR: [] psr:a0000013
[] (faulty_write+0x0/0x18 [faulty]) from [] (vfs_write+0xc4/0x148)
[] (vfs_write+0x0/0x148) from [] (sys_write+0x4c/0x74)

The error code is the 5th instruction ((0xbf00608c-0xbf00607c)/4+1=5) in the Faulty_write function, and the first address of the function is 0xbf00607c, which has a total of 6 instructions (0x18), The function is invoked by the previous instruction of 0XC0088EB8 (that is, the function return address is 0xc0088eb8.) This can be from the error when the LR value is exactly equal to 0xc0088eb8 to be confirmed. The instruction that invokes the function is the Vfs_write 49th (0xc4/4=49) instruction.

The function call flow that achieves the fault is: write (System call to User space) –> sys_write–> vfs_write-> faulty_write.

OOP message not only let me locate the wrong place, but also to my surprise, it let me know some secrets: 1, what is the usefulness of FP in GCC? 2. Why does gcc compile any function, always put 3 of seemingly silly instructions at the beginning of the entire function? 3. How does the kernel and gdb know the order of function call stacks and use the name of the function instead of the address? 4, how can I know the contents of each function into the stack? Haha, I gradually like to let the kernel surprised, then see the kernel again surprised.

Execute cat/dev/faulty, the kernel is once again surprised!

1 Unable to handle kernel NULL pointer dereference in virtual address 0000000b
2 PGD = c3a88000
3 [0000000b] *pgd=33a79031, *pte=00000000, *ppte=00000000
4 Internal error:oops:13 [#2] Preempt
5 Modules Linked In:faulty
6 cpu:0 not tainted (2.6.22.6 #4)
7 PC is at vfs_read+0xe0/0x140
8 LR is at 0xFFFFFFFF
9 PC: [] LR: [] psr:20000013
Ten sp:c38d9f54 ip:0000001c fp:ffffffff
One r10:00000001 r9:c38d8000 r8:00000000
r7:00000004 r6:ffffffff r5:ffffffff r4:ffffffff
R3:FFFFFFFF r2:00000000 r1:c38d9f38 r0:00000004
FLAGS:NZCV IRQs on Fiqs on Mode svc_32 Segment user
control:c000717f table:33a88000 dac:00000015
Process Cat (pid:767, stack limit = 0xc38d8258)
Stack: (0xc38d9f54 to 0xc38da000)
9f40:00002000 c3c105a0 c3c10580
9f60:c38d9f78 00000000 c38d9fa4 c38d9f78 c0088f88 C0088bb4 00000000 00000000
9f80:00000000 00002000 bef07c80 00000003 00000003 C002c0e4 00000000 C38d9fa8
9fa0:c002bf40 c0088f4c 00002000 bef07c80 00000003 bef07c80 00002000 00000000
9fc0:00002000 bef07c80 00000003 00000000 00000000 00000001 00000001 00000003
9fe0:00000000 bef07c6c 0000266c 401adab0 60000010 00000003 00000000 00000000
Backtrace:invalid Frame Pointer 0xFFFFFFFF
Code:ebffff86 e3500000 e1a07000 da000015 (e594500c)
Num Segmentation fault

But the surprise was puzzling. How is it possible that OOP is vfs_read (to know that it is the Montana of the kernel code) that makes a mistake? Haha, the universal kernel can not trace the function call stack, this is why? In fact, the problem in the Faulty_read 43 lines, it caused the stack of R4, R5, R6, FP all into the 0XFFFFFFFF,IP, LR value unchanged, so that the Faulty_read function can successfully return to its caller--vfs_read. But poor Vfs_read (faithful Aptcs rule) did not know that its R4, R5, R6 has been the evil faulty_read change, so down vfs_read fate can be imagined-will die no doubt! Although the kernel is very capable, it is not able to trace the function call stack without the correct FP help.

ssize_t faulty_read (struct file *filp, char __user *buf,
size_t count, loff_t *pos)
{
int ret;
Char stack_buf[4];

memset (Stack_buf, 0xFF, 20);
if (Count > 4)
Count = 4;
ret = Copy_to_user (buf, Stack_buf, Count);
if (!ret)
return count;
return ret;
}

00000000:
0:E1A0C00D mov IP, SP
4:e92dd870 Stmdb sp!, {r4, R5, R6, FP, IP, LR, PC}
8:e24cb004 Sub fp, IP, #4; 0x4
c:e24dd004 Sub sp, SP, #4; 0x4, here for stack_buf[] Allocate 1 words on the stack space, local variable RET use register storage, so not allocate space on the stack
10:e24b501c Sub R5, FP, #28; 0x1c
14:E1A04001 mov r4, r1
18:E1A06002 mov r6, R2
1C:E3A010FF mov r1, #255; 0xFF
20:E3A02014 mov r2, #20; 0x14
24:E1A00005 mov r0, R5
28:ebfffffe BL 28//here in call Memset
78:e89da878 Ldmia sp, {r3, R4, R5, R6, FP, SP, PC}

This OOP has made me profoundly aware that:
The kernel is very powerful, but it is not and cannot be omnipotent. So even if you are strong, you have to do well with your team member, otherwise you will be unlucky at the critical moment;
What went wrong was Faulty_read,vfs_read, who made the scapegoat. So people should not be confused by the surface phenomenon, to look into the essence;
The kernel was super robust, but the driver you wrote was part of the kernel, and as it went wrong, the result was a total crash. So when you join a team, be sure to warn yourself that while your role may not be important, your carelessness will be enough to crash the entire very bovine X team. Conversely, when you are team leader, you must be careful, cautious, and cautious when choosing a group member, even if he is only a small role.
Don't mess with the stack, it will be a very difficult thing to locate if it goes wrong. So, do not provoke your leader, or you will die hard to see.

iii. use of Strace

Sometimes small problems can be tracked by monitoring the behavior of the user's application, while monitoring the program also helps build confidence in driving the right job. For example, after seeing how its read implementation responds to read requests for different amounts of data, we can feel confident that scull is running correctly.

There are several ways to monitor user space programs to run. You can run a debugger to step through its functions, add print statements, or run programs under Strace. Here, we will discuss the last technique, because it is most useful when the real purpose is to check kernel code.

The Strace command is a powerful tool that shows the system calls made by all user-space programs. It not only displays the call, but also displays the parameters and return values of the call in symbolic form. When a system call fails, the wrong symbolic value (for example, Enomem) and the corresponding string (out of memory) are displayed. Strace has a number of command-line options, the most useful of which is-T to display the time of each call execution,-T to display the time spent in the call, and-E to limit the types of calls being tracked (for example, strace–eread,write LS means to monitor only read and write calls), and-O To redirect output to a file. By default, Strace prints the call information to stderr.

Strace gets information from the kernel itself. This means that a program can be tracked regardless of whether it is compiled with debug support (the-G option for GCC) and whether it has been strip or not. In addition, you can track a running process, which is similar to the debugger connecting to a running process and controlling it.

Trace information is often used to support fault reporting to application developers, but is also valuable to kernel programmers. We've seen how the driver code runs in response to system calls, and Strace allows us to check the consistency of input and output data for each invocation.

For example, the Run command strace ls/dev >/dev/scull0 will display the following on the screen:

Open ("Dev", o_rdonly| o_nonblock| o_largefile| o_directory) = 3
Fstat64 (3, {st_mode=s_ifdir|0755, st_size=24576, ...}) = 0
Fcntl64 (3, f_setfd, fd_cloexec) = 0
Getdents64 (3,, 4096) = 4088
[...]
Getdents64 (3,, 4096) = 0
Close (3) = 0
[...]
Fstat64 (1, {st_mode=s_ifchr|0664, St_rdev=makedev (254, 0), ...}) = 0
Write (1, "Makedevnadmmidi0nadmmidi1nadmmid" ..., 4096) = 4000
Write (1, "bnptywcnptywdnptywenptywfnptyx0n" ..., 96) = 96
Write (1, "bnptyxcnptyxdnptyxenptyxfnptyy0n" ..., 4096) = 3904
Write (1, "S17nvcs18nvcs19nvcs2nvcs20nvcs21" ..., 192) = 192
Write (1, "NVCS47NVCS48NVCS49NVCS5NVCS50NVC" ..., 673) = 673
Close (1) = 0
Exit_group (0) =?

From the first write call, it is obvious that after the LS finishes viewing the target directory, it tries to write 4KB. Oddly, only 4000 bytes were written successfully and the operation was duplicated. But when we look at the write implementation in scull, we find that it only allows one quantum (a total of 4000 bytes) to be written at a time, and the visible driver is expected to write the part. After a few steps, everything clears and the program exits successfully. It is through the output of strace that we are sure that the part of the write function is running correctly.

As another example, let's read the scull device (using the WC scull0 command):

[...]
Open ("/dev/scull0", o_rdonly| O_largefile) = 3
Fstat64 (3, {st_mode=s_ifchr|0664, St_rdev=makedev (254, 0), ...}) = 0
Read (3, "Makedevnadmmidi0nadmmidi1nadmmid" ..., 16384) = 4000
Read (3, "bnptywcnptywdnptywenptywfnptyx0n" ..., 16384) = 4000
Read (3, "S17nvcs18nvcs19nvcs2nvcs20nvcs21" ..., 16384) = 865
Read (3, "", 16384) = 0
Fstat64 (1, {st_mode=s_ifchr|0620, St_rdev=makedev (136, 1), ...}) = 0
Write (1, "8865/dev/scull0n", 17) = 17
Close (3) = 0
Exit_group (0) =?

As expected, read can only get 4000 bytes at a time, but the total amount of data is equivalent to the previous example written. This example, the unexpected harvest is: To be sure, the WC is optimized for fast reading, it bypasses the standard library (not using FSCANF), but directly a system call to read more data. This can be confirmed by the fact that the WC tries to read the data in kilobytes one time from the read rows that are tracked.

Iv. use of IOCTL method

Because the IOCTL function in the drive can return some of the driven information to the user program, it can also allow the user program to set some driver parameters through the IOCTL system call. Therefore, during the drive development process, some IOCTL commands can be extended to pass and set the various information and parameters required for debugging drive to achieve the goal of debugging.

V. Using the/proc file system

The/proc file system is used by the kernel to expose some kernel information to user space. For debugging purposes, therefore, we can add code to the/proc file system to export the information that helps monitor the drive in the driver code. This allows us to monitor and debug drivers by looking at the relevant information in/Proc. How to implement the export of information to the/proc file system in drive, see section 4.3 of the Linux Device Driver.
Vi. Use of Kgdb

Kgdb is a patch that is used in kernel source code to debug the kernel, and then through the appropriate hardware and software, you can debug the kernel (including, of course, drivers) as if GDB were stepping through the application. As for kgdb how to use, please google it, it is not, Baidu can also.