Примеры использования strace для отладки скриптов

Strace — это встроенный перехватчик системных вызовов и сигналов в линуксе. Основная его цель — это перехват информации относительно какого-то процесса. Крайне незаменимая штука при отладке скриптов, особенно закодированных.

Пример использования — есть один сервис, который я написал, и обьявилась там проблема — каким-то неведомым образом права на файл, куда пишется лог, начали выставляться криво. А именно: вместо положенных rw — rw — rw стали w — wx — wT. Проблема тут в том, что надо указывать права при смене не как:

chmod('file.txt', '0666'); или
chmod('file.txt', 666);

в этом случае 0666 будет string, а вот так:

chmod('file.txt', intval('666', 8));

Так они уже будут в корректной форме.

Вернемся к проблеме. Нужно было найти, кто ставит на файл неверные права. Вот так можно отловить все вызовы определенного файла:

strace php ./script.php 2>&1 | grep file.txt

Ответ будет вида:

open("/path/to/file.txt", O_RDWR|O_CREAT|O_APPEND|O_LARGEFILE, 0666) = 4
chmod("/path/to/file.txt", 0666) = 0

Вот так можно отмониторить все обращения к файлу

Однако у меня была проблема с записью при запуске через апача, т.е. скрипт запускался не от моего пользователя. Тут можно отмониторить по pid процесса, но нужен рут.

strace -p 123 2>&1 | grep file.txt

Гашение вывода 2>&1 позволит не читать тонны ненужной инфы. Но для хардкорных дебаггеров можно убрать.

Еще вот примеры использования strace, перевел отсюда

Смотрим, какие конфиги читает скрипт:

$ strace -e open php 2>&1 | grep php.ini
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/php.ini", O_RDONLY) = 4

Смотрим, почему скрипт не может открыть определенный файл:

$ strace -e open,access 2>&1 | grep your-filename

Что процесс делает в данный момент:

root@dev:~# strace -p 15427
Process 15427 attached - interrupt to quit
futex(0x402f4900, FUTEX_WAIT, 2, NULL
Process 15427 detached

Следующий пример очень полезен — показывает на что тратится процессорное время скриптом:

root@dev:~# strace -c -p 11084
Process 11084 attached - interrupt to quit
Process 11084 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 94.59    0.001014          48        21           select
  2.89    0.000031           1        21           getppid
  2.52    0.000027           1        21           time
------ ----------- ----------- --------- --------- ----------------
100.00    0.001072                    63           total
root@dev:~#

При таком вызове он будет отображать данные до тех пор, пока принудительно его не завершить.

Можно запросить  раскладку от начала до конца:

root@dev:~# strace -c >/dev/null ls
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 23.62    0.000205         103         2           getdents64
 18.78    0.000163          15        11         1 open
 15.09    0.000131          19         7           read
 12.79    0.000111           7        16           old_mmap
  7.03    0.000061           6        11           close
  4.84    0.000042          11         4           munmap
  4.84    0.000042          11         4           mmap2
  4.03    0.000035           6         6         6 access
  3.80    0.000033           3        11           fstat64
  1.38    0.000012           3         4           brk
  0.92    0.000008           3         3         3 ioctl
  0.69    0.000006           6         1           uname
  0.58    0.000005           5         1           set_thread_area
  0.35    0.000003           3         1           write
  0.35    0.000003           3         1           rt_sigaction
  0.35    0.000003           3         1           fcntl64
  0.23    0.000002           2         1           getrlimit
  0.23    0.000002           2         1           set_tid_address
  0.12    0.000001           1         1           rt_sigprocmask
------ ----------- ----------- --------- --------- ----------------
100.00    0.000868                    87        10 total

Вот такая полезная штука. Man strace, одним словом!

 

5.00 avg. rating (90% score) - 1 vote

3 комментария

  • […] его через strace. Там и увидели, что скрипт ловит SIGTERM. Как использовать strace я уже писал. Позволяет исследовать реальную работу […]

  • Спасибо за кейсы про профилирование производительности. Есть примеры реального применения strace для оптимизации скриптов на php?

    • Олег, да регулярно вылавливаю так баги типа инклюд в цикле или просто функция. И освобождение памяти так проверяю, потому как иногда забываешь переменные unsetить

css.php