Self-service Linux problem diagnostic Tool strace "Go"

Transferred from: http://www.cnblogs.com/bangerlee/archive/2012/02/20/2356818.html

Introduction

"Oops, the system hangs dead ..."

"Oops, the program crashed ..."

"Oops, command execution error ..."

For the maintenance staff, such tragedies are staged every day. Ideally, the error log for the system or application provides sufficient information, and by looking at the relevant logs, the maintenance staff can quickly pinpoint the cause of the problem. In reality, however, many error logs print in an ambiguous manner, more descriptive of the phenomenon when it goes wrong (such as "could not open file", "Connect to XXX Time out"), rather than the cause of the error.

The error log does not meet the needs of the location problem, can we start from a more "deep" aspect of the analysis? The execution of a program or command requires interaction with the operating system via system call, in fact, by observing these system calls and their parameters, return values, defining the scope of the error, and even finding the root cause of the problem.

In Linux, Strace is one such tool. It allows us to keep track of the system calls and signals received during the execution of the program, and to help us analyze the anomalies encountered in the execution of the program or command.

A simple example

How to use Strace to track the program, how to view the corresponding output? Let's go through an example to illustrate this.

1. Examples of tracked procedures

Main.c
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
int main ()
{
int FD;
int i = 0;
FD = open ("/tmp/foo", o_rdonly);
if (FD < 0)
i=5;
Else
i=2;
return i;
}

The above program attempts to open the/tmp/foo file in a read-only manner and then exits, where only the open system call function is used. We then compile the program to generate the executable file:

[Email protected]:~$ gcc Main.c-o Main

2.strace Trace Output

Using the following command, we will use Strace to trace the above program and redirect the results to the Main.strace file:

[Email protected]:~$ strace-o main.strace./main

Next we look at the contents of the Main.strace file:

[Email protected]:~$ cat Main.strace
1 Execve ("./main", ["./main"], [/* VARs */]) = 0
2 BRK (0) = 0x9ac4000
3 Access ("/etc/ld.so.nohwcap", F_OK) = 1 ENOENT (No such file or directory)
4 Mmap2 (NULL, 8192, prot_read| Prot_write, map_private| Map_anonymous,-1, 0) = 0xb7739000
5 Access ("/etc/ld.so.preload", R_OK) = 1 ENOENT (No such file or directory)
6 Open ("/etc/ld.so.cache", o_rdonly) = 3
7 Fstat64 (3, {st_mode=s_ifreg|0644, st_size=80682, ...}) = 0
8 Mmap2 (NULL, 80682, Prot_read, Map_private, 3, 0) = 0xb7725000
9 Close (3) = 0
Access ("/etc/ld.so.nohwcap", F_OK) =-1 ENOENT (No such file or directory)
One open ("/lib/i386-linux-gnu/libc.so.6", o_rdonly) = 3
Read (3, "\177elf\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220o\1\0004\0\0\0" ..., 512) = 512
Fstat64 (3, {st_mode=s_ifreg|0755, st_size=1434180, ...}) = 0
MMAP2 (NULL, 1444360, prot_read| Prot_exec, map_private| Map_denywrite, 3, 0) = 0x56d000
Mprotect (0x6c7000, 4096, prot_none) = 0
MMAP2 (0x6c8000, 12288, prot_read| Prot_write, map_private| map_fixed| Map_denywrite, 3, 0x15a) = 0x6c8000
MMAP2 (0x6cb000, 10760, prot_read| Prot_write, map_private| map_fixed| Map_anonymous,-1, 0) = 0x6cb000
Close (3) = 0
MMAP2 (NULL, 4096, prot_read| Prot_write, map_private| Map_anonymous,-1, 0) = 0xb7724000
Set_thread_area ({entry_number:-1-6, base_addr:0xb77248d0, limit:1048575, Seg_32bit:1, contents:0, read_exec_ o nly:0, Limit_in_pages:1, seg_not_present:0, useable:1}) = 0
Mprotect (0x6c8000, 8192, prot_read) = 0
Mprotect (0x8049000, 4096, prot_read) = 0
Mprotect (0x4b0000, 4096, prot_read) = 0
Munmap (0xb7725000, 80682) = 0
Open ("/tmp/foo", o_rdonly) =-1 ENOENT (No such file or directory)
Exit_group (5) =?
Line numbers marked red are added for convenience, non-strace execution output

See this pile of output, whether heart fear mood? Don't worry, let's analyze the output article by article.

Strace the system calls generated when the tracker interacts with the system, each of these lines corresponds to a system call in the following format:

Name of system call (parameter ...) = return value error flag and description

Line 1: Execve (or one of the Exec series calls) is the first in the Strace output system call for a program executed under the command lines. Strace first calls the fork or clone function to create a new child process, and then calls exec in the child process to load the program that needs to be executed (in this case,./main)

Line 2: Call BRK with 0 as parameter, the return value is the starting address of memory management (if malloc is called in a child process, the space is allocated from the 0x9ac4000 address)

Line 3: Call the Access function to verify that/ETC/LD.SO.NOHWCAP exists

Line 4: Use the MMAP2 function for anonymous memory mapping to get 8192bytes of memory space, the space starting address is 0xb7739000, about the anonymous memory map, you can see here

Line 6: Call the Open function to try to open the/etc/ld.so.cache file, return a file descriptor of 3

Line 7: fstat64 function gets/etc/ld.so.cache file information

Line 8: Call the MMAP2 function to map the/etc/ld.so.cache file to memory, about using the mmap mapping file to memory, you can see here

Line 9: Close Close File descriptor 3 pointing to the/etc/ld.so.cache file

Line12: Call read, read 512bytes from/lib/i386-linux-gnu/libc.so.6 the libc library file, i.e. read Elf header information

Line15: Use the Mprotect function to protect the 4096bytes space at the beginning of the 0x6c7000 (prot_none means no access, prot_read indicates that it can be read)

Line24: Call the Munmap function to map the/etc/ld.so.cache file from memory, corresponding to the MMAP2 of line 8

Line25: The only system call--open function used in the corresponding source code, use it to open the/tmp/foo file

Line26: Child process end, exit code is 5 (why is the exit value 5?) Return to the previous program Example section to see the source bar:)

3. Output analysis

Whirring After reading so many system call functions, is not a little touch the north? Let's start with the whole and return to the topic strace.

From the above output can be found that the real can correspond to the source of only the open system call (LINE25), the other system calls almost all for process initialization work: loading the executed program, loading the LIBC function library, set memory mapping, etc.

The IF statement or other code in the source is not reflected in the corresponding strace output because they do not evoke a system call. Strace only cares about the interaction between the program and the system, so strace does not apply to the debugging and parsing of program logic code.

For Linux in hundreds of system calls, the above strace output of a few just the tip of the iceberg, want to know more about the Linux system call, then man!

Man 2 system call name
Man ld.so  //linux dynamic Link manpage

Strace Common Options

This section describes the several Strace command options that are frequently used, and when to use these options appropriately.

1. Track Child processes

By default, strace tracks only the specified processes, not the new child processes in the specified process. With the-f option, you can track the new child processes in the process and print the corresponding process PID in the output results:

Mprotect (0x5b1000, 4096, prot_read)     = 0
Munmap (0xb77fc000, 80682)               = 0
Clone (Process 13600 attached
Child_stack=0, flags=clone_child_cleartid| clone_child_settid| SIGCHLD, child_tidptr=0xb77fb938) = 13600
[PID 13599] Fstat64 (1, {st_mode=s_ifchr|0620, St_rdev=makedev (136, 0), ...}) = 0
[PID 13600] Fstat64 (1, {st_mode=s_ifchr|0620, St_rdev=makedev (136, 0), ...}) = 0
[PID 13599] MMAP2 (NULL, 4096, prot_read| Prot_write, map_private| Map_anonymous,-1, 0 <unfinished ...>
[PID 13600] MMAP2 (NULL, 4096, prot_read| Prot_write, map_private| Map_anonymous,-1, 0) = 0xb780f000
......

The-f option is generally turned on when you are tracking multi-process programs, commands, and scripts using Strace.

2. Recording system call time

Strace can also record the time information when each system call occurs when the program interacts with the system, there are several options such as R, T, TT, TTT, T and so on, and they record the time in the following way:

-T: Record the time spent on each system call, accurate to microseconds

-R: Timed to the first system call (usually EXECVE), accurate to microseconds

-T: Hours: minutes: seconds

-tt: Hours: minutes: seconds. Microseconds

-TTT: The number of seconds since the computer era. Microseconds

The more commonly used is the T option because it provides the time that each system call takes. While the time records for other options include both system call times and user-level code execution, the reference is less significant. For part-time options we can combine them with, for example:

Strace-tr./main
0.000000 Execve ("./main", ["main"], [/* + VARs */]) = 0
0.000931 fcntl64 (0, f_getfd) = 0 <0.000012>
0.000090 fcntl64 (1, f_getfd) = 0 <0.000022>
0.000060 Fcntl64 (2, F_GETFD) = 0 <0.000012>
0.000054 uname ({sys= "Linux", node= "ion", ...}) = 0 <0.000014>
0.000307 geteuid32 () = 7903 <0.000011>
0.000040 getuid32 () = 7903 <0.000012>
0.000039 getegid32 () = <0.000011>
0.000039 getgid32 () = <0.000011>
......

The leftmost column corresponds to the time output of the-r option, and the rightmost column corresponds to the output of the-t option.

3. Keeping track of running processes

Using Strace to track running programs, use the command "Strace-p PID", and after the command executes, the tracked process executes as usual, and other options for Strace also apply to running process traces.

Hang dead using strace handlers

Finally, we use a program example to learn how to hang dead using the Strace parser.

1. Hanging Dead Program source code

Hang.c
#include <stdio.h>
#include <sys/types.h>
#include <unistd.h>
#include <string.h>

int main (int argc, char** argv)
{
    Getpid (); The system call plays a role in the identity
    if (ARGC < 2)
    {
        printf ("Hang (User|system) \ n");
        return 1;
    }
    if (!strcmp (argv[1], "user"))
        while (1);
    else if (!strcmp (argv[1], "system"))
        Sleep (500);
    return 0;
}

You can pass the user and system parameters to the program, which uses a dead loop to simulate the state of the die, and calls the sleep analog kernel program to hang dead.

2.strace Trace Output

User state hangs dead trace output:

[Email protected]:~$ gcc hang.c-o Hang
[Email protected]:~$ strace/hang User
......
Mprotect (0x8049000, 4096, prot_read)    = 0
Mprotect (0xb59000, 4096, prot_read)     = 0
Munmap (0xb77bf000, 80682)               = 0
Getpid ()                                = 14539

Kernel state hangs dead trace output:

[Email protected]:~$ strace./hang system
......
Mprotect (0x8049000, 4096, prot_read)    = 0
Mprotect (0xddf000, 4096, prot_read)     = 0
Munmap (0xb7855000, 80682)               = 0
Getpid ()                                = 14543
Rt_sigprocmask (Sig_block, [chld], [], 8) = 0
Rt_sigaction (SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
Rt_sigprocmask (Sig_setmask, [], NULL, 8) = 0

3. Output analysis

When the user state hangs, Strace has no other system call output after the Getpid () line output; The process is dead in the kernel state, the last line of system call Nanosleep is not fully displayed, here Nanosleep no return value indicates that the call has not been completed.

Thus we can draw the following conclusion: Use Strace to trace the dead program, if the last line of system call is complete, the program hangs dead at the logic code, if the last line of system call is incomplete, the program hangs dead at the system call.

When the program hangs dead at the system call, we can look at the man Manual of the system call, and understand under what circumstances the system call will appear dead. In addition, the parameters of the system call provide us with some information, such as hanging dead in the following system call:

Read (16,

So we can know that the read function is reading a file or socket with a file descriptor of 16, and further, we can use the Lsof tool to get information that corresponds to the file name that is 16, which process occupies the file.

Summary

This paper introduces the common problem diagnostic Tool strace in Linux, introduces the method of using Strace, the output format and the method of using Strace analysis program to hang the dead problem through the program example, and also explains several common options of strace tool. Describes the scenarios in which these options apply.

The next time you encounter the program hangs dead, the command executes the error question, if from the program log and the system log to see does not have the problem to appear the reason, first does not rush Google or to seek the expert to help, do not forget a powerful tool it is there, does not abandon, strace a bit!

Self-service Linux problem diagnostic Tool strace "Go"