Есть сервер Processor 2x Intel Xeon E5-2650v4, RAM 128 GB, Disks 4x480GB SSD, CentOS 7.3. На нем работают mysql, php-fpm, redis, nginx.
Статус php-fpm (утро):
Processes active: 6, idle: 144, Requests: 724543849, slow: 0, Traffic: 753req/sec
top:
top - 11:09:19 up 447 days, 4:47, 1 user, load average: 9.66, 8.10, 7.90
Tasks: 651 total, 8 running, 643 sleeping, 0 stopped, 0 zombie
%Cpu(s): 2.9 us, 4.0 sy, 0.0 ni, 93.1 id, 0.0 wa, 0.0 hi, 0.1 si, 0.0 st
KiB Mem : 13145292+total, 2053168 free, 38556552 used, 90843208 buff/cache
KiB Swap: 4194300 total, 3122176 free, 1072124 used. 88618272 avail Mem
Всё работает более менее нормально, запросы в базу оптимизированы (редко какой дольше 1 мс), php скрипты выполняются в среднем за 10-30 мс.
Проблема в том, что иногда проскакивает лаг на 200-300 мс (грубо говоря, 1 http-запрос из 10). Путем экспериментов удалось понять, что этот лаг происходит на ровном месте (например, проход по одному небольшому массиву с формированием другого). Через strace php удалось поймать такую картину:
1574322420.597333 fstat(3, {st_mode=S_IFREG|0644, st_size=76666, ...}) = 0 <0.000010>
1574322420.597358 mmap(NULL, 76666, PROT_READ, MAP_SHARED, 3, 0) = 0x7fbe917c2000 <0.000015>
1574322420.598163 mmap(NULL, 2097152, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbe7aa00000 <0.000014>
1574322420.894121 munmap(0x7fbe917c2000, 76666) = 0 <0.000024>
1574322420.894191 close(3) = 0 <0.000011>
В текущем логе после mmap задержка в 296 мс, хотя сам mmap выполняется быстро. Иногда задержка возникает после munmap. Получается, скрипт выполняется в 90% случаев, грубо говоря, за 50 мс. А в 10% случаев проскакивает единовременный лаг на 300 мс (в сумме 350).
Вопрос. Это нормальное поведение загруженного сервера (хотя он вроде бы не сильно загружен) или есть какая-то проблема? Как докопаться до сути? Как оптимизировать?
P. S. Появились предложения заняться оптимизацией приложения. Повторюсь, приложение не при чем. В процессе работы скрипта возникает единовременный продолжительный лаг на 200-300 мс. При чем возникает в том месте, где нет каких-либо внешний обращений, которые могли бы вызвать блокировку. Этот лаг изначально был замечен при обработке http-запроса в php-fpm. В процессе экспериментов уже выполнялся скрипт из консоли напрямую через php с анализом времени выполнения каждой строки. Скрипт выполняется в нормальном режиме за несколько ms (1-5). Примерно на один вызов из 10 время поднимается до 200-300, дополнительная задержка возникает на ровном месте. Например, есть цикл на 100 итераций, где на каждой итерации в массив добавляется новый элемент (не из откуда-то из БД, а, например, строка, просто содержащая номер итерации). Обычно весь цикл выполняется мгновенно за микросекунды, но иногда на одной из итераций скрипт подвисает на 200-300 мс. Этот скрипт был запущен через strace, чтобы понять на каком системном вызове происходит задержка, результат выше по тексту (про mmap и munmap). При запуске через команду time время user и sys минимально (1-5 ms), а вся дополнительная задержка включена в real.
Средний
