Tuesday, 10 January 2017

Debugging with strace

Strace is a brilliant tool for helping debugging problems when you don't have access to the source code and hence is usually aimed at administrators, engineers and the generally inquisitive types.

The utility itself monitors system calls (including return codes) for a specific process - for example:

strace cat /etc/sysctl.conf

Sample output (documented line by line):

# Execute the cat command - returns successful.
execve("/bin/cat", ["cat", "/etc/sysctl.conf"], [/* 33 vars */]) = 0
# Calling brk with an invalid value (e.g. null) simply returns the pointer location in the process memory address space.
brk(NULL)                               = 0x562ce17f4000
# Allocate 8kb of memory and instruct the kernel to choose the address at which the mapping is created. The memory can be either read or written to and uses anonymous memory.
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6c2692b000
# Check the file '/etc/ld.so.preload' exists with read-only mode - returns failure.
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
# Open '/etc/ld.so.cache' in read-only mode and set file descriptor of 3.
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
# The above file has a file descriptor of 3, its permissions are 0644 and it is 112.9kb in size.
fstat(3, {st_mode=S_IFREG|0644, st_size=115629, ...}) = 0
# Allocate 112.9kb's of memory (chosen by the kernel) for file descriptor 3, which you can read and write to and is private memory - no offset.
mmap(NULL, 115629, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6c2690e000
# Close file descriptor 3
close(3)                                = 0
# Open file '/lib64/libc.so.6' with file descriptor of 3, read only.
open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
# Read 832 bytes from file descriptor 3 and keep in the buffer below.
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \5\2\0\0\0\0\0"..., 832) = 832
# The above file has the permissions of 0755 and is 2.02mb in size.
fstat(3, {st_mode=S_IFREG|0755, st_size=2115832, ...}) = 0
# Allocate 3.77mb of at 0x7f6c26342000 for file descriptor 3 - allow read and execute - no offset.
mmap(NULL, 3955040, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f6c26342000
# Set no memory protection of on the first 204.4kb of memory at 0x7f6c264ff000 i.e. allow read, write and execute on it.
mprotect(0x7f6c264ff000, 2093056, PROT_NONE) = 0
# Allocate 24kb of memory at address 0x7f6c266fe000 for file descriptor 3 that allows read, write and is private memory.
mmap(0x7f6c266fe000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bc000) = 0x7f6c266fe000
# Allocate 14.3kb of memory at address 0x7f6c26704000 that allows read, write, is anonymous private memory and has no file descriptor (-1).
mmap(0x7f6c26704000, 14688, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f6c26704000
# Close file descriptor 3.
close(3)                                = 0
# Allocate (chosen by the kernel) 8kb of memory that can be read and written to, no file descriptor and no offset.
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6c2690c000
# Set the 64-bit base for the FS register at 0x7f6c2690c700
arch_prctl(ARCH_SET_FS, 0x7f6c2690c700) = 0
# Set memory protection for 0x7f6c266fe000 (16kb) to read only.
mprotect(0x7f6c266fe000, 16384, PROT_READ) = 0
# Set memory protection for 0x562cdfa74000 (4kb) to read only.
mprotect(0x562cdfa74000, 4096, PROT_READ) = 0
# Set memory protection for 0x7f6c2692d000 (4kb) to read only.
mprotect(0x7f6c2692d000, 4096, PROT_READ) = 0
# Unmap 133kb of memory at address 0x7f6c2690e000
munmap(0x7f6c2690e000, 115629)          = 0
# Determine current location of the pointer that is allocated to the data segment of the process.
brk(NULL)                               = 0x562ce17f4000
# Change the locatino of the program break (which defines end of the processes data segment.)
brk(0x562ce1815000)                     = 0x562ce1815000
# Determine current location of the pointer that is allocated to the data segment of the process.
brk(NULL)                               = 0x562ce1815000
# Open '/usr/lib/locale/locale-archive' in read only with the file descriptor of 3.
open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
# The file descriptor has permissions of 0644 and is 107.6mb in size.
fstat(3, {st_mode=S_IFREG|0644, st_size=112823232, ...}) = 0
# Map 107.6mb of read-only, private memory to file descriptor 3 at 0x7f6c1f7a9000.
mmap(NULL, 112823232, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6c1f7a9000
# Close file descriptor 3.
close(3)                                = 0
# File descriptor 1 (FD1) is a character device with permissions of 0620.
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
# Open '/etc/sysctl.conf' in read-only mode as file descriptor 3.
open("/etc/sysctl.conf", O_RDONLY)      = 3
# File descriptor 3 is 449 bytes in size and has the permissions 0644.
fstat(3, {st_mode=S_IFREG|0644, st_size=449, ...}) = 0
# Announce to kernel that intention to access file data in specific pattern for FD 3.
fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
# Map memory (chosen by kernel) of 136kb - allow read and write access - anonymous private memory - no file descriptor or offset.
mmap(NULL, 139264, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6c268ea000
# Read the first '131072' bytes of file descriptor 3.
read(3, "# sysctl settings are defined th"..., 131072) = 449
# Write the following buffer to stdout (FD 1)
write(1, "# sysctl settings are defined th"..., 449# sysctl settings are defined through files in
# /usr/lib/sysctl.d/, /run/sysctl.d/, and /etc/sysctl.d/.
#
# Vendors settings live in /usr/lib/sysctl.d/.
# To override a whole file, create a new file with the same in
# /etc/sysctl.d/ and put new settings there. To override
# only specific settings, add a file with a lexically later
# name in /etc/sysctl.d/ and put new settings there.
#
# For more information, see sysctl.conf(5) and sysctl.d(5).
) = 449
# Read another 131072 bytes - nothing left.
read(3, "", 131072)                     = 0
# Unmap 132kb of memory at address 0x7f6c268ea000
munmap(0x7f6c268ea000, 139264)          = 0
# Close file descriptors.
close(3)                                = 0
close(1)                                = 0
close(2)                                = 0
Exit all threads in process.
exit_group(0)                           = ?
+++ exited with 0 +++

Strace can also be attached to an exsiting process with the '-p' switch for example:

strace -p 12345

Sources:
https://aboutthebird.wordpress.com/2013/03/02/interpreting-the-output-of-strace-line-by-line/
http://unix.stackexchange.com/questions/75638/why-is-brk0-called
http://man7.org/linux/man-pages/man2/mmap.2.html
https://linux.die.net/man/2/read

0 comments:

Post a comment