lsphp process problem

Discussion in 'Bug Reports' started by PSS, Jan 3, 2009.

  1. PSS

    PSS Member

    PHP 5.2.6
    Name: phpLsapi
    Address: uds://tmp/lshttpd/lsphp.sock
    Notes : Not Set
    Max Connections: 500
    Environment:
    PHP_LSAPI_MAX_REQUESTS=2000
    PHP_LSAPI_CHILDREN=500
    LSAPI_MAX_PROCESS_TIME=3000

    Initial Request Timeout (secs): 100
    Retry Timeout (secs): 0
    Persistent Connection: Not Set
    Connection Keepalive Timeout: Not Set
    Response Buffering: No
    Auto Start: Yes
    Command: $SERVER_ROOT/fcgi-bin/lsphp -c ../php
    Back Log: 100
    Instances: 1
    Run On Start Up: Yes
    Max Idle Time: Not Set
    Priority: 0
    Memory Soft Limit (bytes): 0
    Memory Hard Limit (bytes): 0
    Process Soft Limit: 0
    Process Hard Limit: 0

    APC 3.0.19
    MySQL 5.0.45
    Litespeed Web Server Enterprise v3.3.23, 4 CPU
    2 * dual Woodcrest, 8GB RAM
    RHEL 5 64-bit
    No CP's, no other http servers.

    I don't know if this really LS bug but this happened yesterday:

    Symptoms:
    1. Suddenly (withing 2 minutes) there were 700 "lsphp -c ../php" processes which were not doing anything.
    2. System load dropped to near zero (as nothing was served).
    3. Pages were not served, or in rare attempts partially.

    Log has 5 times "oops! 503 Service Unavailable" and after that no more 503's but tons of "Content len: 0" lines like

    2009-01-02 20:01:08.901 [NOTICE] [121.44.19.108:19988-0#domain:lsapi] Content len: 0, Request line:
    GET /thisurl HTTP/1.1


    I restarted the server gracefully and it was back to full speed. But there were still 600 extra lsphp processes there.
    In the end of log you have

    2009-01-02 20:01:09.529 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 9213 !
    2009-01-02 20:01:09.529 [INFO] [AutoRestater] Clean up child process with pid: 9214
    2009-01-02 20:01:09.529 [INFO] [AutoRestater] Clean up child process with pid: 22544
    2009-01-02 20:01:09.529 [INFO] [AutoRestater] Clean up child process with pid: 22920
    2009-01-02 20:01:09.630 [NOTICE] [AutoRestarter] child process with pid=9213 exited with status=0!
    2009-01-02 20:01:40.121 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 9217 !
    2009-01-02 20:01:40.121 [INFO] [AutoRestater] Clean up child process with pid: 9223
    2009-01-02 20:01:40.222 [NOTICE] [AutoRestarter] child process with pid=9217 exited with status=0!
    2009-01-02 20:01:40.222 [NOTICE] [PID:3400] Server Stopped!


    Next error log has:

    2009-01-02 20:05:24.677 [INFO] Pass listener *:80.
    2009-01-02 20:05:24.677 [INFO] Pass listener *:7080.
    2009-01-02 20:05:24.677 [NOTICE] [Child: 22930] Start shutting down gracefully ...
    2009-01-02 20:05:24.677 [NOTICE] [Child: 22928] Start shutting down gracefully ...
    2009-01-02 20:05:24.953 [NOTICE] [ADMINS_IP_HERE:62898-80#_AdminVHost] [STDERR] PHP Warning: file_get_contents(/tmp/lshttpd/.rtreport) [<a href='function.file-get-contents'>function.file-get-contents</a>]: failed to open stream: No such file or directory in /opt/lsws/admin/html.3.3.23/classes/STATS.php on line 160
    2009-01-02 20:05:25.832 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 22932 !
    2009-01-02 20:05:25.832 [INFO] [AutoRestater] Clean up child process with pid: 22941
    2009-01-02 20:05:25.933 [NOTICE] [AutoRestarter] child process with pid=22932 exited with status=0!
    2009-01-02 20:05:26.664 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 22931 !
    2009-01-02 20:05:26.664 [INFO] [AutoRestater] Clean up child process with pid: 22945
    2009-01-02 20:05:26.765 [NOTICE] [AutoRestarter] child process with pid=22931 exited with status=0!
    2009-01-02 20:05:27.520 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 22928 !
    2009-01-02 20:05:27.520 [INFO] [AutoRestater] Clean up child process with pid: 22929
    2009-01-02 20:05:27.520 [INFO] [AutoRestater] Clean up child process with pid: 22978
    2009-01-02 20:05:27.520 [INFO] [AutoRestater] Clean up child process with pid: 23499
    2009-01-02 20:05:27.622 [NOTICE] [AutoRestarter] child process with pid=22928 exited with status=0!
    2009-01-02 20:05:28.060 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 22930 !
    2009-01-02 20:05:28.060 [INFO] [AutoRestater] Clean up child process with pid: 22937
    2009-01-02 20:05:28.161 [NOTICE] [AutoRestarter] child process with pid=22930 exited with status=0!
    2009-01-02 20:05:28.161 [NOTICE] [PID:22926] Server Stopped!


    I stopped and started the server from shell as root and still this processes were there. Pids for those where around 23000-24000, they were started about 19:46-19:47 (as far as I can recall).
    Process tree revealed that those 700 processes did not have parent, so apparently that was why LS could not kill them.
    I stopped the server, killed them manually with "killall lsphp" and started the server.

    There is no core dump (it's disabled).

    I know it's vague, but I reported this because to me it does not look like "as designed" that LS can have parentless lsphp's that do not deliver content at all (although LS seemed to think they were usable and ok), and also to me it is a problem that LS can not detect and restart server when it serves zero content continuously. Luckily I was there this time.

    If there are any settings above that needs tweaking to prevent situations like this, I'll be happy to try them.
  2. mistwang

    mistwang LiteSpeed Staff

    If it happen again, please "strace" those lsphp processes. Maybe them stuck at a system call.

    Also, you may want to recompile PHP to make sure the latest php-lsapi code is used. With latest php-lsapi code, a parentless lsphp should quit by itself.
  3. PSS

    PSS Member

    Still haven't updated to latest php-lsapi :rolleyes:, so I got this again.

    trace shows:
    lsphp -c ../php
    parent process: init[3], id 1, root
    CPU 0%

    Code:
    time        system call            parameters
    16:27:31    futex                  0x2ab9d5070070, FUTEX_WAIT, 2, NULL
    16:28:12    rt_sigreturn           0xa
    Only that one line came out, nothing else happened. I'll update php to latest php-lsapi ASAP, but I thought to report this just in case it's something else.
    Last edited: Jan 20, 2009
  4. mistwang

    mistwang LiteSpeed Staff

    The latest php-lsapi should not block at one system call, if it happen again, please let us know.
  5. PSS

    PSS Member

    With latest php lsapi happened today, this time there were no zombie processes, LS was down completely for about hour before I was noted about it and did

    lswsctrl stop
    lswsctrl start

    same errors all the time:

    2009-03-17 04:33:49.895 [NOTICE] [xx.xx.xx.xx:59570-0#domain.com:lsapi] oops! 503 Service Unavailable
    2009-03-17 04:33:51.201 [NOTICE] [xx.xx.xx.xx:59570-0#domain.com:lsapi] Content len: 0, Request line:
    GET /url/to/script.php HTTP/1.1

    Then

    2009-03-17 04:36:16.000 [NOTICE] [Child: 7605] Shut down successfully!
    2009-03-17 04:36:16.000 [NOTICE] [phpLsapi] stop worker processes
    2009-03-17 04:36:16.000 [INFO] [phpLsapi] 3 request being processed, kill external app later.
    2009-03-17 04:36:16.001 [NOTICE] [Child: 7603] Shut down successfully!
    2009-03-17 04:36:16.001 [INFO] [phpLsapi] kill pid: 7607
    2009-03-17 04:36:16.043 [NOTICE] [Child: 7606] Shut down successfully!
    2009-03-17 04:36:16.043 [NOTICE] [phpLsapi] stop worker processes
    2009-03-17 04:36:16.043 [INFO] [phpLsapi] 12 request being processed, kill external app later.
    2009-03-17 04:36:16.043 [NOTICE] [Child: 7604] Shut down successfully!
    2009-03-17 04:36:16.043 [NOTICE] [phpLsapi] stop worker processes
    2009-03-17 04:36:16.043 [INFO] [phpLsapi] 7 request being processed, kill external app later.



    but again the problem continues.

    Last logs:

    2009-03-17 04:36:25.513 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 7604 !
    2009-03-17 04:36:25.513 [INFO] [AutoRestater] Clean up child process with pid: 7611
    2009-03-17 04:36:26.375 [NOTICE] [AutoRestarter] child process with pid=7604 exited with status=0!
    2009-03-17 04:36:29.726 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 7606 !
    2009-03-17 04:36:29.726 [INFO] [AutoRestater] Clean up child process with pid: 7608
    2009-03-17 04:36:29.826 [NOTICE] [AutoRestarter] child process with pid=7606 exited with status=0!
    2009-03-17 04:36:40.569 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 7603 !
    2009-03-17 04:36:40.569 [INFO] [AutoRestater] Clean up child process with pid: 7607
    2009-03-17 04:36:40.684 [NOTICE] [AutoRestarter] child process with pid=7603 exited with status=0!
    2009-03-17 04:36:43.620 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets belong to process 7605 !
    2009-03-17 04:36:43.813 [INFO] [AutoRestater] Clean up child process with pid: 7614
    2009-03-17 04:36:43.913 [NOTICE] [AutoRestarter] child process with pid=7605 exited with status=0!
    2009-03-17 04:36:43.914 [NOTICE] [PID:7599] Server Stopped!

    So, stopping LS and starting it from shell cleared the problem.

    What I wonder is that if lsapi does not continuously respond (content len 0) why can't LS see something is wrong and stop/start it(self) cleanly? The must be a way to monitor if php actually comes up with response, if nothing else than have LS run phpinfo(); internally every minute and if there is 0 response size then restart php.
    Last edited: Mar 17, 2009
  6. anewday

    anewday Moderator

    Any updates on this?

Share This Page