Данная статья не претендует на оригинальность или новизну, а лишь приоткрывает капот в этой адской машине оптимизации.
Прочтя пару дней назад статью товарища pavlinux, я был весьма заинтригован, ведь буквально прошлой ночью я открыл для себя readahead и, подкрутив краники, получил избыточное (с точки зрения идеологии этой программы) кэширование и вместе с ним реактивную загрузку и вход в профиль. Подумалось, почему бы не выжать из скромной печатной машинки на базе Intel Atom ещё немного?
Так сложилось, что, помимо ssh и telnet, в своей работе я часто использую web-браузер, то и проверку на вшивость я устрою именно ему. Позабудем священные войны по поводу «какой же браузер лучший»: сегодня под нож ложится Google Chrome 29.0.1547.62 (r219432).
Поскольку Ваш покорный слуга — скриптоложец 1-го уровня, то использовать я буду bash для небольшого вспомогательного скрипта:
Буду рад Вашим замечаниям в комментариях.
Также, заранее создадим спартанские условия для теста — почистим кэш браузера и заодно системный (pagecache, dentries и inodes):
Запускаем браузер и открываем уйму вкладок с разнообразных перегруженных контентом сайтов. Я знаю, что Вы всегда так делаете, а значит, что ситуация вполне себе штатная.
Для кого-то привычная картина, но для меня это стресс.

Посёрфив некоторое время (в моём случае вышло чуть более часа — больше вытерпеть не смог), закрываем браузер и начинаем разбирать выходные данные:
Объединим все файлы трассировок в один и отсортируем:
Удалим из вывода строки, не имеющие отношения к вызовам ("+++ exited with 0 +++" и иже с ними):
Выберем из файла только те строки, когда вызов завершался неудачно (спасибо за подсказку pavlinux):
Процент неудачных вызовов равен 16,418%.
Немало, но посмотрим глубже и узнаем статистику неудач:
Выходит, что помимо неудачных open и stat64 есть ещё и access и readlinkat.
Всё это интересно, разумеется, и достойно более детального анализа,
но пора узнать, сколько же времени потрачено на эти самые неудачные вызовы.
Выберем из файла конкретные значения времени выполнения вызова:
Теперь наша задача состоит в том, чтобы получить сумму почти 40 тысяч значений. Я был чересчур ленив и взял готовый код отсюда:
Выполним этот код:
Итог немного предсказуем: на неудачные системные вызовы Google Chrome и все запущенные им процессы потратили 4 секунды.
Реальное время выполнения — 1 час 11 минут и 55 секунд, или 4315 секунд.
Процент «утерянного» времени: 4/4315 = ~ 0,093%. Даже не один процент, а один промилле с небольшой натяжкой.
Пусть каждый решит сам для себя. С одной стороны, никогда не будет лишним проверить часто используемые Вами приложения/системы на «вшивость» подобного рода и узнать, где могут быть узкие места и как с ними бороться. С другой стороны, всякое действие должно иметь меру, и педантично-параноидальная оптимизация расположений библиотек/файлов ускоряет запуск приложения на доли секунды и, возможно, даже работу, но это всё равно лишь доли секунды. Они могут быть полезны в системах, работающих с сумашедшим аптаймом, так как будут накапливаться, но их ценность пропадает в приложениях, которые запускаются на относительно короткое время. В конце концов, всё зависит от поставленной Вами задачи и от того, насколько Вы цените собственное время.
В какой-то мере и я не ценю своё время: потратил время сна на исследование этого спорного вопроса и написание статьи про то, что «не надо мешать самолёту летать».
Данная статья призвана не унизить ��оварища pavlinux или его статью, но указать на нюансы, оставленные без внимания. Более того, без первой статьи я бы не стал проводить ночные исследования идумать головой писать свою.
PS: те самые 4.17 секунды и есть Неуловимый Джо.
Предыстория
Прочтя пару дней назад статью товарища pavlinux, я был весьма заинтригован, ведь буквально прошлой ночью я открыл для себя readahead и, подкрутив краники, получил избыточное (с точки зрения идеологии этой программы) кэширование и вместе с ним реактивную загрузку и вход в профиль. Подумалось, почему бы не выжать из скромной печатной машинки на базе Intel Atom ещё немного?
Так сложилось, что, помимо ssh и telnet, в своей работе я часто использую web-браузер, то и проверку на вшивость я устрою именно ему. Позабудем священные войны по поводу «какой же браузер лучший»: сегодня под нож ложится Google Chrome 29.0.1547.62 (r219432).
Подготовка
Поскольку Ваш покорный слуга — скриптоложец 1-го уровня, то использовать я буду bash для небольшого вспомогательного скрипта:
trace_google_chrome
Посыпаю голову пеплом и каюсь, не самый лучший пример скрипта для подобной задачи.#!/bin/bash
ENV_EXCLUDE=('^SUDO_' '^GREP_' '^LS_' '^KONSOLE_' '^_$')
ENV_PERSIST=('^PATH$' '^LOGNAME$' '^USER' '^HOME$')
sudo true || return 1
T0=$(mktemp)
sudo -E env | cut -d'=' -f1 | tee ${T0} &>/dev/null
T1=$(mktemp)
for i in ${ENV_EXCLUDE[@]}; do egrep -e "$i" < ${T0} >> ${T1}; done
T2=$(mktemp)
for i in ${ENV_PERSIST[@]}; do egrep -e "$i" < ${T0} >> ${T2}; done
rm ${T0}
STRACE_ARGS=''
while read L; do
STRACE_ARGS=${STRACE_ARGS}" -E $L"
done < ${T1}; rm ${T1}
while read L; do
declare -p $L &>/dev/null || continue
V=$(env | egrep -e ^$L)
STRACE_ARGS=${STRACE_ARGS}" -E $V"
done < ${T2}; rm ${T2}
U=$(whoami)
date --rfc-3339=ns >d.begin
sudo -E strace -ff -o zzz -v -s 256 -T \
-u ${U} -E USERNAME=${U} ${STRACE_ARGS} \
-e trace=file,signal,ipc google-chrome
date --rfc-3339=ns >d.endБуду рад Вашим замечаниям в комментариях.
Также, заранее создадим спартанские условия для теста — почистим кэш браузера и заодно системный (pagecache, dentries и inodes):
$ find .cache/google-chrome/ -mindepth 1 -delete
$ sync
$ sudo sysctl -w vm.drop_caches=3
vm.drop_caches = 3Тестирование
Запускаем браузер и открываем уйму вкладок с разнообразных перегруженных контентом сайтов. Я знаю, что Вы всегда так делаете, а значит, что ситуация вполне себе штатная.
$ trace_google_chrome
Fontconfig warning: "/etc/fonts/conf.d/50-user.conf", line 9: reading configurations from ~/.fonts.conf is deprecated.
[19883:19883:0904/013557:ERROR:profile_sync_service.cc(1240)] History Delete Directives, Sync Error: Delete directives not supported with encryption.
Fontconfig warning: "/etc/fonts/conf.d/50-user.conf", line 9: reading configurations from ~/.fonts.conf is deprecated.
[19883:19909:0904/013606:ERROR:native_backend_kwallet_x.cc(848)] Error obtaining KWallet handle
ATTENTION: default value of option force_s3tc_enable overridden by environment.
[WARNING:flash/platform/pepper/pep_module.cpp(63)] SANDBOXED
[WARNING:flash/platform/pepper/pep_module.cpp(63)] SANDBOXED
ATTENTION: default value of option force_s3tc_enable overridden by environment.
ATTENTION: default value of option force_s3tc_enable overridden by environment.Для кого-то привычная картина, но для меня это стресс.

Посёрфив некоторое время (в моём случае вышло чуть более часа — больше вытерпеть не смог), закрываем браузер и начинаем разбирать выходные данные:
$ egrep -He^ d.*
d.begin:2013-09-04 01:35:39.040184387+04:00
d.end:2013-09-04 02:57:34.084098826+04:00
$ du -ch zzz.* | tail -n 1
34M итогоОбъединим все файлы трассировок в один и отсортируем:
$ cat zzz.* > z
$ sort < z > z.sorted
$ wc -l < z.sorted
243048Удалим из вывода строки, не имеющие отношения к вызовам ("+++ exited with 0 +++" и иже с ними):
$ egrep -ve '^\+' < z.sorted > z.clean
$ wc -l < z.clean
242474Выберем из файла только те строки, когда вызов завершался неудачно (спасибо за подсказку pavlinux):
$ fgrep -e ' = -' < z.clean > z.fail
$ wc -l < z.fail
39810Процент неудачных вызовов равен 16,418%.
Немало, но посмотрим глубже и узнаем статистику неудач:
$ cut -d'(' -f1 < z.fail | uniq > z.fail.names
$ cat z.fail.names |
> while read SYSCALL; do
> echo -n "${SYSCALL}:"
> egrep -ce "^${SYSCALL}\(" z.fail
> done
access:16807
chmod:2
execve:56
faccessat:6
fstatat64:46
lstat64:91
mkdir:8
openat:155
open:7812
readlinkat:4909
readlink:86
rt_sigaction:59
rt_sigreturn:8
shmctl:1
sigreturn:47
stat64:9658
statfs64:39
unlink:20Выходит, что помимо неудачных open и stat64 есть ещё и access и readlinkat.
Всё это интересно, разумеется, и достойно более детального анализа,
но пора узнать, сколько же времени потрачено на эти самые неудачные вызовы.
Выберем из файла конкретные значения времени выполнения вызова:
$ sed -nre '/^.* <([0-9\.]+)>$/{s##\1#;p}' < z.fail > z.fail.timingТеперь наша задача состоит в том, чтобы получить сумму почти 40 тысяч значений. Я был чересчур ленив и взял готовый код отсюда:
#include <stdio.h>
#include <stdlib.h>
int main(void) {
ssize_t read;
char *line = NULL;
size_t len = 0;
double sum = 0.0;
while (read = getline(&line, &len, stdin) != -1) {
sum += atof(line);
}
printf("%f\n", sum);
return 0;
}Выполним этот код:
$ gcc sum.c -o sum; ./sum < z.fail.timing
4.173705Итог немного предсказуем: на неудачные системные вызовы Google Chrome и все запущенные им процессы потратили 4 секунды.
Реальное время выполнения — 1 час 11 минут и 55 секунд, или 4315 секунд.
Процент «утерянного» времени: 4/4315 = ~ 0,093%. Даже не один процент, а один промилле с небольшой натяжкой.
Выводы
Пусть каждый решит сам для себя. С одной стороны, никогда не будет лишним проверить часто используемые Вами приложения/системы на «вшивость» подобного рода и узнать, где могут быть узкие места и как с ними бороться. С другой стороны, всякое действие должно иметь меру, и педантично-параноидальная оптимизация расположений библиотек/файлов ускоряет запуск приложения на доли секунды и, возможно, даже работу, но это всё равно лишь доли секунды. Они могут быть полезны в системах, работающих с сумашедшим аптаймом, так как будут накапливаться, но их ценность пропадает в приложениях, которые запускаются на относительно короткое время. В конце концов, всё зависит от поставленной Вами задачи и от того, насколько Вы цените собственное время.
В какой-то мере и я не ценю своё время: потратил время сна на исследование этого спорного вопроса и написание статьи про то, что «не надо мешать самолёту летать».
Послесловие
Данная статья призвана не унизить ��оварища pavlinux или его статью, но указать на нюансы, оставленные без внимания. Более того, без первой статьи я бы не стал проводить ночные исследования и
PS: те самые 4.17 секунды и есть Неуловимый Джо.
