В 19 выпуске Perl-журнала PragmaticPerl опубликованы две мои статьи: Постепенная автоматизация рутинных задач, Постепенная автоматизация в примерах. Здесь находится дополняемая и улучшаемая версия второй статьи.
Примеры к статье Постепенная автоматизация рутинных задач.
Ситуация: на сервере работает веб-сервер (для определенности – apache) с Perl-приложением с богатой логикой. Иногда случаются аварии: одна из баз данных или внешний сервис начинают отвечать долго. Время обработки запросов нашим сервером возрастает по крайней мере до величины таймаута на БД/внешний сервис, и если это достаточно много, то постепенно все воркеры apache оказываются заняты ожиданием этого внешнего сервиса, и новые запросы не успевают обработаться.
Внешние симптомы такой аварии: увеличивается время ответа, уменьшается количество обработанных в единицу времени запросов, apache не отвечает на server-status, а ps показывает количество воркеров, соответствующее настройке MaxClients.
Один из способов понять, на чем именно зависли воркеры –
это взять наугад один из них и посмотреть
starce-ом. Если процесс действительно проводит время
в read-е, flock-е, select-е – скопировать соответствующий дескриптор
и с помощью lsof-а посмотреть, какой именно файл или сокет
открыт под этим дескриптором (или использовать strace -y).
Давайте поавтоматизируем эти действия.
Для демонстрации я буду пользоватся скриптом, который зависает, пытаясь вторично взять лок на уже залоченный файл.
flock-twice.pl:
#!/usr/bin/perl
use strict;
use warnings;
use Fcntl qw(:flock);
my $filename = "/tmp/lockfile";
open(my $fh1, ">>", $filename) or die "open 1";
open(my $fh2, ">>", $filename) or die "open 2";
print STDERR localtime()." start: $$\n";
flock($fh1, LOCK_EX) or die "$$: flock LOCK_EX 1 $!";
# на этом вызове -- виснет
flock($fh2, LOCK_EX) or die "$$: flock LOCK_EX 2 $!";
flock($fh1, LOCK_UN) or die "$$: flock LOCK_UN 1 $!";
flock($fh2, LOCK_UN) or die "$$: flock LOCK_UN 1 $!";
close $fh1;
close $fh2;
unlink $filename;
print STDERR localtime()."done\n";
exit 0;
> ps gaxuww |grep flock
lena 3154 0.0 0.0 29304 232 pts/19 SN May17 0:00 /usr/bin/perl ./flock-twice.pl
lena 3157 0.0 0.0 29304 232 pts/19 SN May17 0:00 /usr/bin/perl ./flock-twice.pl
lena 3164 0.0 0.0 29304 232 pts/19 SN May17 0:00 /usr/bin/perl ./flock-twice.pl
lena 20114 0.0 0.0 10860 636 pts/19 S+ 20:44 0:00 grep flock
> sudo strace -p 3154
Process 3154 attached - interrupt to quit
flock(4, LOCK_EX^C <unfinished ...>
Process 3154 detached
> lsof -a -p 3154 -d 4 |tail -n 1
flock-twi 3154 lena 4wW REG 8,1 0 7222737 /tmp/lockfile
# ps gaxuww |grep 'floc[k]' |awk '{print $2}' |while read i ; do strace -y -p $i & ; sleep 1 ; kill -9 $! ; done
[5] 28989
Process 28972 attached
flock(4</tmp/lockfile>, LOCK_EX[6] 28993
[5] - killed strace -y -p $i
Process 28976 attached
flock(3</tmp/lockfile>, LOCK_EX[5] 28997
[6] - killed strace -y -p $i
Process 28979 attached
flock(3</tmp/lockfile>, LOCK_EX# [5] + killed strace -y -p $i
multitrace-0.sh
#!/bin/sh
ps gaxuww |
grep $1 |
awk '{print $2}' |
while read i
do
echo $i
strace -y -p $i &
sleep 1
kill -9 $!
echo
done 2>&1 |
grep -v 'attached'
#multitrace-0.sh 'floc[k]'
29032
flock(4</tmp/lockfile>, LOCK_EX
29035
flock(3</tmp/lockfile>, LOCK_EX
29038
flock(3</tmp/lockfile>, LOCK_EX#
Но может быть, не стоит массово дергать процессы strace-ом?
Кстати: статья об опасностях strace.
На Linux можно попробовать обойтись информацией из /proc/<pid>/syscall.
Для расшифровки номера системного вызова используем хедер unistd_64.h
Кроме того, добавим расшифровку дескриптора, если он идет первым параметром системного вызова:
multitrace-1.sh
ps gaxuww |grep $1 |awk '{print $2}' |
while read i
do
str=`cat /proc/$i/syscall`
n=${str%% *}
s=${str#* 0x}
fd=${s%% *}
lsof=`lsof -p $i -d $fd -a -w |tail -n 1`
file=${lsof##* }
syscall=`cat /usr/include/x86_64-linux-gnu/asm/unistd_64.h |grep "\<$n\>" |sed -e 's/^.*_NR_\([^ \t]*\).*$/\1/'`
echo "$syscall $fd $file $i\t$str"
done
#multitrace-1.sh 'floc[k]'
flock 4 /tmp/lockfile 29120 73 0x4 0x2 0x0 0x0 0x0 0x0 0x7fffc5728e28 0x7f13acf7c957
flock 3 /tmp/lockfile 29125 73 0x3 0x2 0x0 0x7fff2cda7500 0x0 0x0 0x7fff2cda7738 0x7ff67492c957
flock 3 /tmp/lockfile 29130 73 0x3 0x2 0x0 0x7fff874eb6b0 0x0 0x0 0x7fff874eb8e8 0x7f50ada58957
Нормально, только десктипторы с номерами больше 9 обрабатывает неправильно… Исправим в перловой версии.
multitrace-2.pl
#!/usr/bin/perl
use strict;
use warnings;
my @pids = split /\s+/, `ps gaxuww |grep $ARGV[0] | awk '{print \$2}'`;
for my $p (@pids){
my $proc_str = `cat /proc/$p/syscall`;
(my $syscall_num = $proc_str) =~ s/ .*$//s;
(my $fd = $proc_str) =~ s/^.*?0x([0-9]+).*/$1/s;
$fd = hex($fd);
my $lsof=`lsof -p $p -d $fd -a -w |tail -n 1`;
(my $file = $lsof) =~ s/.* ([^ ]+)\n$/$1/;
my $syscall=`cat /usr/include/x86_64-linux-gnu/asm/unistd_64.h |grep "\\<$syscall_num\\>"`;
$syscall =~ s/^.*_NR_([^ \t]*).*\n/$1/;
print "$syscall $fd $file $p\t$proc_str";
}
Работает аналогично multitrace-1.sh:
#multitrace-2.pl 'floc[k]'
flock 4 /tmp/lockfile 29206 73 0x4 0x2 0x0 0x0 0x0 0x0 0x7fff1a387348 0x7f9ff4b88957
flock 3 /tmp/lockfile 29209 73 0x3 0x2 0x0 0x7fffa7e20270 0x0 0x0 0x7fffa7e204a8 0x7f560524a957
flock 3 /tmp/lockfile 29212 73 0x3 0x2 0x0 0x7fff406a49e0 0x0 0x0 0x7fff406a4c18 0x7f0db5e62957
Большие номера дескрипторов обрабатывает правильно.
После нескольких серий доработок у меня получилось следующее: multitrace@github.
Пока мне хватает имеющихся возможностей ^_^.
А вообще интересно было бы сделать скрипт более кроссплатформенным, не привязанным к Linux.
Дано: хотим удобный поиск в коде.
Удобный – значит только по .pl и .pm (а также .html, .tt2, .js и т.п.) файлам,
исключая метаданные svn, git, hg,
а также пару каталогов, где хранится автоматически сгенерированный код.
Нужные файлы можно найти find-ом, ненужные пути выкинуть опцией -prune или же grep-ом,
найденные файлы передать xargs-ом в grep.
Это уже практически рецепт шелльного однострочника, и он решал бы многие задачи поиска в коде.
А если пойти дальше и дальше по дороге улучшений – можно написать что-то вроде Ack – better than grep ^_^
Если у вас есть свои примеры итеративной разработки – поделитесь в комментариях, это интересно!