lsphp process problem

[PSS]

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.

[mistwang]

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.

[PSS]

Originally Posted by mistwang

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.

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

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

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.

[mistwang]

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

[PSS]

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.

[anewday]

Any updates on this?