Menu

strace

strace php-fpm process

, 0

Привет,

Днес ще споделя как бързо и лесно можем да следим какво се случва зад един php-fpm процес благодарение на strace!

Добавяме следната функция в .bashrc файла на потребителя ни (препоръчва се да е директно на root) или ще трябва да се изпълни със sudo :

function straceall {
strace -t -f -o strace.txt $(pidof "${1}" | sed 's/\([0-9]*\)/-p \1/g')
}

Зареждаме го на ново чрез source .bashrc или излизаме и влизаме в сървъра ни и започваме да следим процеса :

straceall php-fpm7.0

Ако искаме да следим php7.1-fpm процес пишем :

straceall php-fpm7.1

а за php5-fpm следното :

straceall php5-fpm

Така се детачва strace процес който пише във файл strace.txt в реално време.

Това е!

debug website’s load time with strace

, , , , 0

Хелоу,

В работата ми като системен администратор, често се налага да помагам на девелопърите в дебъгване на ситуации с бавно зареждащи уеб сайтове. Като изключим факта че сме проверили дали всичко по сървъра е наред, дали другите уеб страници на самата машина зареждат добре, а конкретния уеб сайт зарежда 10 пъти по-бавно от другите, в този случай използваме за помощ – strace.
debug website's load time with strace

Това е много полезна програма с която дебъгваме примерно index.php-то на конкретния сайт, и в лога който ще запише програмата можем да видим в timeline кога какво се стратира и зарежда и къде идва и разликата в секундите и съответно къде е проблема в кода.

Чрез командата :

 

strace -t -f -o strace.txt /usr/bin/php index.php

Ние ще направим точно това което съм написал по-горе и резултатите можем да ги прочетем после в strace.txt лога.

Резултатите са нещо от рода на :

1727 10:31:38 fcntl(4, F_SETFL, O_RDWR) = 0
1727 10:31:38 sendto(4, "GET /feed/ HTTP/1.0\r\n", 21, MSG_DONTWAIT, NULL, 0) = 21
1727 10:31:38 sendto(4, "Host: www.tips.website"..., 42, MSG_DONTWAIT, NULL, 0) = 42
1727 10:31:38 sendto(4, "\r\n", 2, MSG_DONTWAIT, NULL, 0) = 2
1727 10:31:38 poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 0 (Timeout)
1727 10:31:38 poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=4, revents=POLLIN|POLLERR|POLLHUP}])
1727 10:31:59 recvfrom(4, 0x7faf915a8b10, 8192, 64, 0, 0) = -1 ECONNRESET (Connection reset by peer)
1727 10:31:59 close(4) = 0
1727 10:31:59 socket(PF_FILE, SOCK_STREAM, 0) = 4
1727 10:31:59 fcntl(4, F_SETFL, O_RDONLY) = 0
1727 10:31:59 fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
1727 10:31:59 fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
1727 10:31:59 fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
1727 10:31:59 connect(4, {sa_family=AF_FILE, path="/var/lib/mysql/mysql.sock"}, 110) = 0

От всичкия лог, най-важното за нас е разликата в секундите – 21 секунди. Тук идва и проблема – самият сайт се зареждаще за около 20-25 секунди. И в крайна сметка се оказа че, в конфигра му беше зададен грешен url към несъществуващ хостнейм (www.tips.website…), и забавянето идваше от факта че , самият сайт се опитваше да го резолвне и не успяваше.