Linux: ldd, starce, ltrace. Как работают утилиты. Трассировка вызовов.

Linux: ldd, starce, ltrace. Как работают утилиты. Трассировка вызовов.

libc — корневая библиотека языка C (В Linux мы ее видим по пути — /lib64/libc.so.6)
6 — номер версии библиотеки

По сути является ссылкой на библиотеку libc-2.17.so:
# ls -l /lib64/libc.so.6
lrwxrwxrwx. 1 root root 12 Jan 30 04:27 /lib64/libc.so.6 -> libc-2.17.so

Что будем использовать для примера?

ldd — выводит список разделяемых библиотек, используемых указанной утилитой или разделяемой библиотекой

Разделяемые библиотеки содержат реализации функций, необходимых для работы приложений, разделяемых библиотек
Разделяемые библиотеки имеют расширение — «.so» ( аналоги динамических библиотек «.dll» Windows )

Опция -v выводит информацию о версиях используемых разделяемых библиотек
Опция -u выводит список связанных, но не используемых разделяемых библиотек

strace — system trace (трассировка системных вызовов)

ltrace — library trace (трассировка библиотечных вызовов)

Посмотрим, что использует утилита date:
# which date | xargs ldd
linux-vdso.so.1 => (0x00007ffd3d3d8000)
libc.so.6 => /lib64/libc.so.6 (0x00007f931f97d000)
/lib64/ld-linux-x86-64.so.2 (0x00007f931fd4b000)

Посмотрим, как отрабатывают системные вызовы при вызове утилиты date:
# which date | xargs strace
execve(«/bin/date», [«/bin/date»], [/* 22 vars */]) = 0
brk(NULL) = 0x20ab000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f71db8b0000
access(«/etc/ld.so.preload», R_OK) = -1 ENOENT (No such file or directory)
open(«/etc/ld.so.cache», O_RDONLY|O_CLOEXEC) = 3
fstat(3, ) = 0
mmap(NULL, 57295, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f71db8a2000
close(3) = 0
open(«/lib64/libc.so.6», O_RDONLY|O_CLOEXEC) = 3
read(3, «\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20&\2\0\0\0\0\0». 832) = 832
fstat(3, ) = 0
mmap(NULL, 3985888, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f71db2c2000
mprotect(0x7f71db485000, 2097152, PROT_NONE) = 0
mmap(0x7f71db685000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1c3000) = 0x7f71db685000
mmap(0x7f71db68b000, 16864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f71db68b000
close(3) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f71db8a1000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f71db89f000
arch_prctl(ARCH_SET_FS, 0x7f71db89f740) = 0
mprotect(0x7f71db685000, 16384, PROT_READ) = 0
mprotect(0x60d000, 4096, PROT_READ) = 0
mprotect(0x7f71db8b1000, 4096, PROT_READ) = 0
munmap(0x7f71db8a2000, 57295) = 0
brk(NULL) = 0x20ab000
brk(0x20cc000) = 0x20cc000
brk(NULL) = 0x20cc000
open(«/usr/lib/locale/locale-archive», O_RDONLY|O_CLOEXEC) = 3
fstat(3, ) = 0
mmap(NULL, 106075056, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f71d4d98000
close(3) = 0
open(«/etc/localtime», O_RDONLY|O_CLOEXEC) = 3
fstat(3, ) = 0
fstat(3, ) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f71db8af000
read(3, «TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0». 4096) = 3519
lseek(3, -2252, SEEK_CUR) = 1267
read(3, «TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\5\0\0\0\5\0\0\0\0». 4096) = 2252
close(3) = 0
munmap(0x7f71db8af000, 4096) = 0
fstat(1, ) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f71db8af000
write(1, «Thu Mar 12 17:22:20 EDT 2020\n», 29Thu Mar 12 17:22:20 EDT 2020
) = 29
close(1) = 0
munmap(0x7f71db8af000, 4096) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++

Кратко из вывода strace (набора вызовов к ядру операционной системы) мы видим:
execve — системный вызов, указывает, что для работы команды date необходимо загрузить утилиту по пути /bin/date
open — системные вызовы, которые загружают указанные библиотеки и файлы, в которых есть зависимость (вывод ldd)
read — системные вызовы, осуществляющме чтение оных
Так-же в выводе присутствует ряд действий
Пример: «open(«/etc/localtime», O_RDONLY|O_CLOEXEC) = 3″ — считывается файл с зоной
write — собственно вывод результата работы утилиты (вывод на экран)

Пример трассировки определенных вызовов:
# which date | xargs strace -fe open,read,write,close
open(«/etc/ld.so.cache», O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(«/lib64/libc.so.6», O_RDONLY|O_CLOEXEC) = 3
read(3, «\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20&\2\0\0\0\0\0». 832) = 832
close(3) = 0
open(«/usr/lib/locale/locale-archive», O_RDONLY|O_CLOEXEC) = 3
close(3) = 0
open(«/etc/localtime», O_RDONLY|O_CLOEXEC) = 3
read(3, «TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0». 4096) = 3519
read(3, «TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\5\0\0\0\5\0\0\0\0». 4096) = 2252
close(3) = 0
write(1, «Thu Mar 12 17:59:02 EDT 2020\n», 29Thu Mar 12 17:59:02 EDT 2020
) = 29
close(1) = 0
close(2) = 0
+++ exited with 0 +++

Посмотрим, как отрабатывают библиотечные вызовы при вызове утилиты date:
# which date | xargs ltrace
__libc_start_main(0x401ab0, 1, 0x7ffc7e59ae08, 0x4096e0
strrchr(«/bin/date», ‘/’) = «/date»
setlocale(LC_ALL, «») = «en_US.UTF-8»
bindtextdomain(«coreutils», «/usr/share/locale») = «/usr/share/locale»
textdomain(«coreutils») = «coreutils»
__cxa_atexit(0x402c40, 0, 0, 0x736c6974756572) = 0
getopt_long(1, 0x7ffc7e59ae08, «d:f:I::r:Rs:u», 0x60d2a0, nil) = -1
nl_langinfo(0x2006c, 1, 0, 0) = 0x7f890e9a2025
clock_gettime(0, 0x7ffc7e59ac40, 0xc94440, 0) = 0
localtime(0x7ffc7e59abc0) = 0x7f8915103d20
strftime(» Thu», 1024, » %a», 0x7f8915103d20) = 4
fwrite(«Thu», 3, 1, 0x7f89150ff400) = 1
fputc(‘ ‘, 0x7f89150ff400) = 32
strftime(» Mar», 1024, » %b», 0x7f8915103d20) = 4
fwrite(«Mar», 3, 1, 0x7f89150ff400) = 1
fputc(‘ ‘, 0x7f89150ff400) = 32
fwrite(«12», 2, 1, 0x7f89150ff400) = 1
fputc(‘ ‘, 0x7f89150ff400) = 32
fwrite(«17», 2, 1, 0x7f89150ff400) = 1
fputc(‘:’, 0x7f89150ff400) = 58
fwrite(«23», 2, 1, 0x7f89150ff400) = 1
fputc(‘:’, 0x7f89150ff400) = 58
fputc(‘0’, 0x7f89150ff400) = 48
fwrite(«3», 1, 1, 0x7f89150ff400) = 1
fputc(‘ ‘, 0x7f89150ff400) = 32
strlen(«EDT») = 3
fwrite(«EDT», 3, 1, 0x7f89150ff400) = 1
fputc(‘ ‘, 0x7f89150ff400) = 32
fwrite(«2020», 4, 1, 0x7f89150ff400) = 1
__overflow(0x7f89150ff400, 10, 4, 0x30323032Thu Mar 12 17:23:03 EDT 2020
) = 10
exit(0
__fpending(0x7f89150ff400, 0, 64, 0x7f89150ffeb0) = 0
fileno(0x7f89150ff400) = 1
__freading(0x7f89150ff400, 0, 64, 0x7f89150ffeb0) = 0
__freading(0x7f89150ff400, 0, 2052, 0x7f89150ffeb0) = 0
fflush(0x7f89150ff400) = 0
fclose(0x7f89150ff400) = 0
__fpending(0x7f89150ff1c0, 0, 3328, 0xfbad000c) = 0
fileno(0x7f89150ff1c0) = 2
__freading(0x7f89150ff1c0, 0, 3328, 0xfbad000c) = 0
__freading(0x7f89150ff1c0, 0, 4, 0xfbad000c) = 0
fflush(0x7f89150ff1c0) = 0
fclose(0x7f89150ff1c0) = 0
+++ exited (status 0) +++

Из вывода ltrace мы видим:
clock_gettime — по сути функция, получающая время системы
strftime — форматирование в нужном формате
fwrite и fputc — функции вывода

Источник

Debian // Call Trace

Последний Stable Debian. На борту: squid, postfix, dovecot, LAMP. Вот что выдаёт в логе. С Дебианом вожусь впервые и многое непонятно, но стараюсь вроде всё найти в нете. С этим маюсь уже неделю. Никак не пойму что это, критично ли это. Понимаю что что-то с сидюком, но он работает нормально. Что сие может означать?

Aug 13 22:11:36 gateway kernel: [17795.124760] Call Trace:
Aug 13 22:11:36 gateway kernel: [17795.124790] [ ] :ide_cd_mod:cdrom_do_newpc_cont+0x0/0x2b
Aug 13 22:11:36 gateway kernel: [17795.124799] [ ] schedule_timeout+0x1e/0xad
Aug 13 22:11:36 gateway kernel: [17795.124816] [ ] :ide_core:ide_do_request+0x8cd/0x930
Aug 13 22:11:36 gateway kernel: [17795.124825] [ ] :ide_cd_mod:cdrom_newpc_intr+0x0/0x5e1
Aug 13 22:11:36 gateway kernel: [17795.124840] [ ] :ide_core:ide_do_request+0x1c/0x930
Aug 13 22:11:36 gateway kernel: [17795.124847] [ ] wait_for_common+0xcf/0x13a
Aug 13 22:11:36 gateway kernel: [17795.124852] [ ] default_wake_function+0x0/0xe
Aug 13 22:11:36 gateway kernel: [17795.124870] [ ] :ide_core:ide_do_drive_cmd+0xe2/0x109
Aug 13 22:11:36 gateway kernel: [17795.124882] [ ] :ide_cd_mod:ide_cd_queue_pc+0x42/0xca
Aug 13 22:11:36 gateway kernel: [17795.124889] [ ] :ide_cd_mod:ide_cd_queue_pc+0x42/0xca
Aug 13 22:11:36 gateway kernel: [17795.124895] [ ] blk_rq_init+0x1c/0x85
Aug 13 22:11:36 gateway kernel: [17795.124905] [ ] :ide_cd_mod:cdrom_read_tocentry+0xb1/0xc3
Aug 13 22:11:36 gateway kernel: [17795.124927] [ ] blk_end_sync_rq+0x0/0x2e
Aug 13 22:11:36 gateway kernel: [17795.124938] [ ] :ide_cd_mod:ide_cd_read_toc+0x101/0x3c8
Aug 13 22:11:36 gateway kernel: [17795.124952] [ ] :ide_cd_mod:idecd_revalidate_disk+0x14/0x1b
Aug 13 22:11:36 gateway kernel: [17795.124959] [ ] __invalidate_device+0x3a/0x42
Aug 13 22:11:36 gateway kernel: [17795.124964] [ ] check_disk_change+0x4f/0x76
Aug 13 22:11:36 gateway kernel: [17795.124973] [ ] :cdrom:cdrom_open+0x983/0xa14
Aug 13 22:11:36 gateway kernel: [17795.124980] [ ] dput+0x1c/0xdd
Aug 13 22:11:36 gateway kernel: [17795.124984] [ ] kobject_get+0x12/0x17
Aug 13 22:11:36 gateway kernel: [17795.124989] [ ] get_disk+0x40/0x5b
Aug 13 22:11:36 gateway kernel: [17795.124994] [ ] exact_lock+0xc/0x14
Aug 13 22:11:36 gateway kernel: [17795.125003] [ ] :ide_cd_mod:idecd_open+0x5b/0x89
Aug 13 22:11:36 gateway kernel: [17795.125007] [ ] blkdev_open+0x0/0x5d
Aug 13 22:11:36 gateway kernel: [17795.125012] [ ] do_open+0xd1/0x2e8
Aug 13 22:11:36 gateway kernel: [17795.125019] [ ] blkdev_open+0x0/0x5d
Aug 13 22:11:36 gateway kernel: [17795.125023] [ ] blkdev_open+0x2e/0x5d
Aug 13 22:11:36 gateway kernel: [17795.125029] [ ] __dentry_open+0x12c/0x238
Aug 13 22:11:36 gateway kernel: [17795.125037] [ ] do_filp_open+0x3d7/0x7c4
Aug 13 22:11:36 gateway kernel: [17795.125045] [ ] :cdrom:cdrom_release+0x1a7/0x1e4
Aug 13 22:11:36 gateway kernel: [17795.125055] [ ] iput+0x27/0x60
Aug 13 22:11:36 gateway kernel: [17795.125062] [ ] get_unused_fd_flags+0x71/0x115
Aug 13 22:11:36 gateway kernel: [17795.125070] [ ] do_sys_open+0x46/0xc3
Aug 13 22:11:36 gateway kernel: [17795.125076] [ ] system_call_after_swapgs+0x8a/0x8f
Aug 13 22:11:36 gateway kernel: [17795.125085]
Aug 13 22:13:45 gateway kernel: [17923.972736] hald-addon-st D0000000000000000 0 3459 3431
Aug 13 22:13:45 gateway kernel: [17923.972742] ffff81002c105878 0000000000000082 0000000000000000 ffffffffa0117b00
Aug 13 22:13:45 gateway kernel: [17923.972747] ffff81002c0c94f0 ffffffff804f8480 ffff81002c0c9778 0000000037987400
Aug 13 22:13:45 gateway kernel: [17923.972752] ffffffffa0117b90 0000000000000000 00000000ffffffff 0000000000000000

Источник

10 Strace Commands for Troubleshooting and Debugging Linux Processes

strace is a powerful command line tool for debugging and trouble shooting programs in Unix-like operating systems such as Linux. It captures and records all system calls made by a process and the signals received by the process.

It displays the name of each system call together with its arguments enclosed in a parenthesis and its return value to standard error; you can optionally redirect it to a file as well.

In this article, we will explain 10 strace command examples for troubleshooting and debugging programs and processes in a Linux system.

How to Install Strace Process Monitoring Tool in Linux

If strace is not pre-installed on your Linux system, run the appropriate command below for your distribution, to install it.

In case a program crashes or behaves in a way not expected, you can go through its systems calls to get a clue of what exactly happened during its execution. As we will see later on, system calls can be categorized under different events: those relating to process management, those that take a file as an argument, those that involve networking, memory mapping, signals, IPC and also file descriptor related system calls.

You can either run a program/command with strace or pass a PID to it using the -p option as in the following examples.

1. Trace Linux Command System Calls

You can simply run a command with strace like this, here we are tracing of all system calls made by the df command.

>P\t». 832) = 832 fstat(3, ) = 0 mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f82f7310000 .

From the output above, you can see various types of system calls made by df command, for example.

• open – is the type of system call
• (“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) – system call argument
• 3 – system call return value

Below is an sample output showing the write system calls, that displays df command output on the screen.

2. Trace Linux Process PID

If a process is already running, you can trace it by simply passing its PID as follows; this will fill your screen with continues output that shows system calls being made by the process, to end it, press [Ctrl + C] .

%», 4096>], msg_controllen=0, msg_flags=0>, 0) = 32 recvmsg(4, 0x7ffee4dbf870, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(4, 0x7ffee4dbf850, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([, , , , , ], 6, -1) = 1 ([]) read(31, «2», 1) = 1 recvmsg(4, 0x7ffee4dbf850, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([, , , , , ], 6, 0) = 1 ([]) read(31, «2», 1) = 1 recvmsg(4, 0x7ffee4dbf850, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([, , , , , ], 6, 0) = 0 (Timeout) mprotect(0x207faa20000, 8192, PROT_READ|PROT_WRITE) = 0 mprotect(0x207faa20000, 8192, PROT_READ|PROT_EXEC) = 0 mprotect(0x207faa21000, 4096, PROT_READ|PROT_WRITE) = 0 mprotect(0x207faa21000, 4096, PROT_READ|PROT_EXEC) = 0 .

3. Get Summary of Linux Process

Using the -c flag, you can generate a report of total time, calls, and errors for each system call, as follows.

4. Print Instruction Pointer During System Call

The -i option displays the instruction pointer at the time of each system call made by the program.

>P\t». 832) = 832 [00007faf9cafb2b4] fstat(3, ) = 0 [00007faf9cafb47a] mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7faf9c716000 [00007faf9cafb517] mprotect(0x7faf9c8d6000, 2097152, PROT_NONE) = 0 .

5. Show Time of Day For Each Trace Output Line

You can also print the time of day for each line in the trace output, by passing the -t flag.

>P\t». 832) = 832 15:19:25 fstat(3, ) = 0 15:19:25 mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f8c7ebec000 15:19:25 mprotect(0x7f8c7edac000, 2097152, PROT_NONE) = 0 .

6. Print Command Time Spent in System Calls

To shows the time difference between the starting and the end of each system call made by a program, use the -T option.

7. Trace Only Specific System Calls

In the command below, trace=write is known as a qualifying expression, where trace is a qualifier (others include signal, abbrev, verbose, raw, read, or write). Here, write is the value of the qualifier.

The following command actually shows the system calls to print df output on standard output.

Here are some additional commands about trace qualifier.

8. Trace System Calls Based on a Certain Condition

Let’s look at how to trace system calls relating to a given class of events. This command can be used to trace all system calls involving process management.

Next, to trace all system calls that take a filename as an argument, run this command.

To trace all system calls involving memory mapping, type.

You can trace all network and signals related system calls.

9. Redirect Trace Output to File

To write the trace messages sent to standard error to a file, use the -o option. This means that only the command output is printed on the screen as shown below.

To look through the file, use cat command.

10. Show Some Debugging Output of Strace

To show debugging information for strace tool, use the -d flag.

For additional information, see the strace man page.

Also read these useful related articles:

In conclusion, strace is a remarkable tool for diagnosing cause(s) of program failure: it is a powerful debugging and trouble shooting. It is practically useful to experienced system administrators, programmers and hackers. To share any thoughts concerning this article, use the feedback form below.

If You Appreciate What We Do Here On TecMint, You Should Consider:

TecMint is the fastest growing and most trusted community site for any kind of Linux Articles, Guides and Books on the web. Millions of people visit TecMint! to search or browse the thousands of published articles available FREELY to all.

If you like what you are reading, please consider buying us a coffee ( or 2 ) as a token of appreciation.

We are thankful for your never ending support.

Источник