High LA caused by php-fpm

[Dimitri Minaev]

Hello,

Today, I tried to move our bunch of Drupal-powered web sites to a new
server.  The old server was running FreeBSD 7.2 and I wanted to install a
newer version. In the meanwhile, I transferred the sites to the new server
(FreeBSD 10.1 on ZFS mirror,  1CPU with 6 cores and hyperthreading).
Everything looked fine, but as soon as the requests rate reached the usual
50-150 req/sec, the server shut up. Load average went up to 60, all
requests timed out and the backlog on php-fpm socket was full (2048). All
diagnostic tools showed that I/O was negligible, there was no swapping and
the only problem was high CPU usage caused by php-fpm.

Php-fpm was configured to start 100 children. When I lowered the number to
50, LA decreased to 30, but the requests were timing out as before.

Things looked like high LA was caused by bad PHP code, but it was the same
code that ran without problems on the old server. I tried to trace PHP
scripts using `truss', but could not find any problems -- just normal
operations.

Slow PHP requests logged by php-fpm contained no regular patterns that
might indicate problematic areas -- any kind of request ended up in the
slow log.
freebsd-questions at freebsd.org
I moved the sites back to the old server. The LA on the old one stayed high
until the queued requests had been processed. What's wrong with php-fpm?

Some specs:
FreeBSD 10.1-RELEASE-p9 running on Xeon(R) CPU E5-2420. Root partition is
on ZFS.
PHP 5.3.29 (5.3 required by developers). Nginx 1.6.2. MySQL runs on another
server and doesn't look like a bottleneck.

This is the upper part of `top' output:

Mem: 317M Active, 5866M Inact, 6819M Wired, 2724M Free
ARC: 5652M Total, 2382M MFU, 2554M MRU, 16K Anon, 32M Header, 684M Other
Swap: 4096M Total, 4096M Free

  PID USERNAME   PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
34803 www         81    0   310M   172M RUN     4   7:40  31.05%
php-fpm{php-fpm}
34796 www         80    0   314M   175M CPU3    3   7:42  30.57%
php-fpm{php-fpm}
34797 www         81    0   310M   171M RUN     7   7:35  30.57%
php-fpm{php-fpm}
34785 www         80    0   306M   164M *Name   7   7:38  27.88%
php-fpm{php-fpm}
34790 www         80    0   310M   172M RUN     5   6:37  27.88%
php-fpm{php-fpm}
34783 www         80    0   310M   171M *Name   8   7:40  27.78%
php-fpm{php-fpm}
34805 www         80    0   310M   170M CPU6    6   7:38  27.59%
php-fpm{php-fpm}
34821 www         80    0   310M   171M RUN    11   7:39  26.95%
php-fpm{php-fpm}
34815 www         80    0   318M   178M CPU8    8   7:36  26.37%
php-fpm{php-fpm}
34822 www         80    0   310M   171M *Name   0   7:38  26.27%
php-fpm{php-fpm}
34813 www         80    0   314M   175M RUN    10   7:40  25.98%
php-fpm{php-fpm}
34816 www         79    0   314M   175M RUN     6   7:37  25.98%
php-fpm{php-fpm}
34826 www         79    0   314M   175M CPU1    1   7:34  25.98%
php-fpm{php-fpm}
34812 www         79    0   306M   167M RUN     6   7:33  25.88%
php-fpm{php-fpm}
34823 www         79    0   306M   168M *Name   2   7:35  25.78%
php-fpm{php-fpm}
34818 www         79    0   314M   174M *Name   0   7:42  25.68%
php-fpm{php-fpm}
34829 www         79    0   310M   172M CPU11  11   7:37  25.68%
php-fpm{php-fpm}
34806 www         79    0   310M   172M RUN     2   7:35  25.39%
php-fpm{php-fpm}
34817 www         80    0   318M   177M CPU7    7   7:38  25.29%
php-fpm{php-fpm}

Thanks.

-- 
With best regards,
Dimitri Minaev