4.1.12 broken

raphidae

Well-Known Member
#1
I upgraded a server from 4.1.10 to 4.1.12 today and it completely broke php and the web console.

All php scripts result in 503, as does accessing the web console.

there are numerous unhelpful errors in stderr.log:
2012-04-05 23:18:03.006 [STDERR] lscgid: recv_fd() failed: No such file or directory
2012-04-05 23:18:03.007 [STDERR] lscgid: recv_fd() failed: No such file or directory
2012-04-05 23:18:14.947 [STDERR] lscgid: recv_fd() failed: No such file or directory
and some more in my admin error log:

2012-04-05 23:15:25.057 [INFO] [xx.44.172.93:54313-0#_AdminVHost] ExtConn timed out while processing.
2012-04-05 23:15:25.057 [INFO] [xx.44.172.93:54313-0#_AdminVHost] connection to [/tmp/lshttpd/admin_php.sock] on request #0, confirmed, 0, associated process: 1952543827, running: 0, error: Operation timed out!
2012-04-05 23:15:25.057 [NOTICE] [xx.44.172.93:54313-0#_AdminVHost] Suspicious request timeout, associated process: 1952543827, running: 0.
Reverting to 4.1.10 solved all problems instantly.

Additionally, since upgrading I've noticed a new file: /tmp/secret/lscgid.sock

I can't find any references to this file in any of the config files, so I'm unsure of the purpose. Other servers that still run 4.1.10 don't have this file.

I tried deleting it, but that results in:

stderr.log:2012-04-05 23:40:58.785 [STDERR] lscgid: failed to open secret file: /tmp/secret/lscgid.sock.724!
stderr.log:lscgid: secret is not set properly!
Reverting back to 4.1.10 did not remove the need for this file for some reason.
 

raphidae

Well-Known Member
#2
Maybe I should have noted that this is on FreeBSD 8-STABLE. Are your testing procedures for FreeBSD the same as for Linux?

It seems every time I upgrade there is one issue or another. If you're not testing the FreeBSD builds the same as the Linux builds I'd like to know, since I'm paying the same as a Linux user.
 

raphidae

Well-Known Member
#3
FYI: I just tried 4.1.11 to see whether that version works, and it doesn't have these issues. It seems to be new in 4.1.12.
 

webizen

Well-Known Member
#6
not seen /tmp/secret/lscgid.sock file in our lab following your upgrade path (4.1.10 -> 4.1.12 -> 4.1.11). try full stop/start and see if that clears.
 

priestjim

Well-Known Member
#7
I get extremely high loads on 4.1.12. The error log says:

2012-04-10 13:15:44.416 [WARN] Remove looping fd: 50, event: 1
2012-04-10 13:15:44.465 [WARN] Remove looping fd: 797, event: 1
2012-04-10 13:15:44.521 [WARN] Remove looping fd: 822, event: 1
2012-04-10 13:15:44.730 [WARN] Remove looping fd: 747, event: 1
2012-04-10 13:15:44.863 [WARN] Remove looping fd: 833, event: 1
2012-04-10 13:15:44.913 [WARN] Remove looping fd: 840, event: 1
2012-04-10 13:15:45.079 [WARN] Remove looping fd: 139, event: 1
2012-04-10 13:15:45.128 [WARN] Remove looping fd: 494, event: 1
2012-04-10 13:15:45.180 [WARN] Remove looping fd: 522, event: 1
2012-04-10 13:15:45.241 [WARN] Remove looping fd: 723, event: 1
2012-04-10 13:15:45.271 [WARN] Remove looping fd: 509, event: 1
2012-04-10 13:15:45.409 [WARN] Remove looping fd: 529, event: 1
2012-04-10 13:15:46.577 [WARN] Remove looping fd: 851, event: 1
2012-04-10 13:15:47.018 [WARN] Remove looping fd: 73, event: 1
2012-04-10 13:15:47.425 [WARN] Remove looping fd: 859, event: 1
2012-04-10 13:15:47.743 [WARN] Remove looping fd: 887, event: 1
2012-04-10 13:15:49.231 [WARN] Remove looping fd: 319, event: 1

And strace-ing the litespeed process gives out A LOT of:

mincore(0x7ff7b9ac5000, 443819, 0x7fffc0296aa0) = -1 ENOMEM (Cannot allocate memory)
 

raphidae

Well-Known Member
#11
not seen /tmp/secret/lscgid.sock file in our lab following your upgrade path (4.1.10 -> 4.1.12 -> 4.1.11). try full stop/start and see if that clears.
That doesn't help.

I'm venturing a guess that only the location of the file is weird then, since the stderr.log entries specifically refer to it. also my other servers have the file as well, but instead of in /tmp it's somewhere below /usr/local/lsws/admin.

can you explain the purpose of this file please? without knowing what it's for I cannot assess required security, and the whole 'secret' part makes me think it has to do with (internal) password/key exchange or the like and then it would need to be secure.

Not knowing the purpose of a 'secret' file makes me nervous, especially since lsws is proprietary software.

Also, id like to note that I pay (substantially) for support, but that I rather receive it here, on the forums -where it might benefit others later- instead of in private email. Please send me a message if you need confirmation of my support contracts. Thanks.
 
Last edited:

raphidae

Well-Known Member
#12
I get extremely high loads on 4.1.12. The error log says:

2012-04-10 13:15:44.416 [WARN] Remove looping fd: 50, event: 1
2012-04-10 13:15:44.465 [WARN] Remove looping fd: 797, event: 1
[snip]
And strace-ing the litespeed process gives out A LOT of:

mincore(0x7ff7b9ac5000, 443819, 0x7fffc0296aa0) = -1 ENOMEM (Cannot allocate memory)
Respectfully: please don't hijack my thread, your issue does not seem related and is better placed in it's own thread.
 

webizen

Well-Known Member
#15
I upgraded a server from 4.1.10 to 4.1.12 today and it completely broke php and the web console.

All php scripts result in 503, as does accessing the web console.

there are numerous unhelpful errors in stderr.log:


and some more in my admin error log:



Reverting to 4.1.10 solved all problems instantly.

Additionally, since upgrading I've noticed a new file: /tmp/secret/lscgid.sock

I can't find any references to this file in any of the config files, so I'm unsure of the purpose. Other servers that still run 4.1.10 don't have this file.

I tried deleting it, but that results in:



Reverting back to 4.1.10 did not remove the need for this file for some reason.
4.1.12 is ready. Please do force reinstall.
 

webizen

Well-Known Member
#16
...
can you explain the purpose of this file please? without knowing what it's for I cannot assess required security, and the whole 'secret' part makes me think it has to do with (internal) password/key exchange or the like and then it would need to be secure.

Not knowing the purpose of a 'secret' file makes me nervous, especially since lsws is proprietary software.

...
the "/usr/local/lsws/admin/cgid/secret" folder (not file) is for internal secure communication (lscgid.sock) of admin console. only root user has access to it.

drwx------ 2 root wheel 512 Apr 27 19:43 secret
 

raphidae

Well-Known Member
#17
4.1.12 is ready. Please do force reinstall.
Obviously you did not test this, since it doesn't work from the session manager:

Error: Failed to download release 4.1.12! Please try upgrade manually.

2012-05-06 01:45:25.305 [NOTICE] [xx.xx.172.93:49481-1#_AdminVHost] [STDERR] PHP Warning: file_get_contents(http://download.litespeedtech.com/packages/latest/lsws-4.1.12-ent-x86_64-freebsd.tar.gz) [<a href='function.file-get-contents'>function.file-get-contents</a>]: failed to open stream: HTTP request failed! HTTP/1.0 404 Not Found
in /usr/local/lsws/admin/html.4.1.12/classes/ws/Service.php on line 607
I tried upgrading manually, but this doesn't completely fix the problem. There's still an intermittent problem with php throwing 503's, around 1 in 10. Version of PHP doesn't matter, and even reverting to 4.1.10 doesn't fix it.

4.1.12 seems to have permanently broken something, possibly related to the weird location of the secret dir, which is in /tmp/:

[root@virasena /tmp/secret]# ls -la
total 26
drwx------ 2 root wheel 512 May 6 01:54 .
drwxrwxrwt 10 root wheel 21504 May 6 01:54 ..
-rw------- 1 root wheel 16 May 6 01:54 lscgid.sock.305
Code:
2012-05-06 01:56:50.381 [NOTICE] Loading LiteSpeed/4.1.12 Enterprise ...
2012-05-06 01:56:50.382 [NOTICE] [ADMIN] server socket: uds://usr/local/lsws/admin/tmp/admin.sock.7144
2012-05-06 01:56:50.383 [NOTICE] Loading configuration from /usr/local/lsws/conf/httpd_config.xml ...
2012-05-06 01:56:50.384 [NOTICE] [config] chroot is disabled.
2012-05-06 01:56:50.385 [INFO] old priority: 0, new priority: 0
2012-05-06 01:56:50.385 [INFO] [config:server:basic] For better obscurity, server version number is hidden in the response header.
2012-05-06 01:56:50.387 [NOTICE] [PID: 25237]: start cgid: 25241, /usr/local/lsws/bin/httpd
2012-05-06 01:56:50.389 [NOTICE] The maximum number of file descriptor limit is set to 115891.
2012-05-06 01:56:50.412 [NOTICE] litespeed (25237) is ready
2012-05-06 01:56:50.412 [NOTICE] [AutoRestarter] new child process with pid=25243 is forked!
2012-05-06 01:56:50.413 [NOTICE] [AutoRestarter] new child process with pid=25244 is forked!
2012-05-06 01:56:50.413 [NOTICE] [AutoRestarter] new child process with pid=25245 is forked!
2012-05-06 01:56:50.414 [INFO] Stop listener 217.195.117.160:280.
2012-05-06 01:56:50.414 [NOTICE] [AutoRestarter] new child process with pid=25246 is forked!
2012-05-06 01:56:50.414 [NOTICE] Core dump is enabled.
2012-05-06 01:56:50.414 [NOTICE] [child: 25243] Successfully change current user to www
2012-05-06 01:56:50.414 [INFO] Stop listener 217.195.117.160:280.
2012-05-06 01:56:50.414 [NOTICE] Core dump is enabled.
2012-05-06 01:56:50.414 [NOTICE] [child: 25244] Successfully change current user to www
2012-05-06 01:56:50.414 [NOTICE] [Child: 25243] Setup swapping space...
2012-05-06 01:56:50.414 [INFO] Stop listener 217.195.117.160:280.
2012-05-06 01:56:50.414 [NOTICE] Core dump is enabled.
2012-05-06 01:56:50.414 [NOTICE] [child: 25245] Successfully change current user to www
2012-05-06 01:56:50.415 [NOTICE] [Child: 25243] LiteSpeed/4.1.12 Enterprise starts successfully!
2012-05-06 01:56:50.415 [NOTICE] [Child: 25244] Setup swapping space...
2012-05-06 01:56:50.415 [NOTICE] [Child: 25245] Setup swapping space...
2012-05-06 01:56:50.415 [NOTICE] [Child: 25244] LiteSpeed/4.1.12 Enterprise starts successfully!
2012-05-06 01:56:50.415 [NOTICE] Core dump is enabled.
2012-05-06 01:56:50.415 [NOTICE] [child: 25246] Successfully change current user to www
2012-05-06 01:56:50.415 [NOTICE] [Child: 25245] LiteSpeed/4.1.12 Enterprise starts successfully!
2012-05-06 01:56:50.415 [NOTICE] [Child: 25246] Setup swapping space...
2012-05-06 01:56:50.415 [NOTICE] [Child: 25246] LiteSpeed/4.1.12 Enterprise starts successfully!
2012-05-06 01:56:51.448 [NOTICE] [AutoUpdate] Checking for new releases..., pid=25247
2012-05-06 01:56:51.457 [NOTICE] Start to clean up cache directory, pid=25248
2012-05-06 01:56:51.775 [INFO] [AutoUpdate] No new update.
2012-05-06 01:56:54.127 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.128 [NOTICE] Graceful stop process group lead by pid: 25308
2012-05-06 01:56:54.143 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.143 [NOTICE] Graceful stop process group lead by pid: 25310
2012-05-06 01:56:54.149 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.152 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.152 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.152 [NOTICE] [xx.xx.172.93:49846-0#ra.phid.ae] Max retries has been reached, 503!
2012-05-06 01:56:54.152 [NOTICE] [xx.xx.172.93:49846-0#ra.phid.ae] oops! 503 Service Unavailable
2012-05-06 01:56:54.152 [NOTICE] [xx.xx.172.93:49846-0#ra.phid.ae] Content len: 0, Request line: 'GET /gallery/d/4992-9/08-10-31.jpg HTTP/1.1'
2012-05-06 01:56:54.152 [NOTICE] [xx.xx.172.93:49846-0#ra.phid.ae] Redirect: #1, URL: /gallery/main.php
2012-05-06 01:56:54.725 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.725 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.725 [INFO] [uds://tmp/lsphp5-ra.phid.ae.sock] Connection refused, restart!
2012-05-06 01:56:54.725 [NOTICE] [xx.xx.172.93:49867-0#ra.phid.ae] Max retries has been reached, 503!
2012-05-06 01:56:54.725 [NOTICE] [xx.xx.172.93:49867-0#ra.phid.ae] oops! 503 Service Unavailable
2012-05-06 01:56:54.725 [NOTICE] [xx.xx.172.93:49867-0#ra.phid.ae] Content len: 0, Request line: 'GET /gallery/v/party2k8/ HTTP/1.1'
2012-05-06 01:56:54.725 [NOTICE] [xx.xx.172.93:49867-0#ra.phid.ae] Redirect: #1, URL: /gallery/main.php
2012-05-06 01:57:00.097 [NOTICE] All pending requests are finished, stop process group lead by pid: 25310
2012-05-06 01:57:00.098 [NOTICE] All pending requests are finished, stop process group lead by pid: 25308
2012-05-06 01:57:00.248 [INFO] [CLEANUP] Clean up child process with pid: 25308
2012-05-06 01:57:00.352 [INFO] [CLEANUP] Clean up child process with pid: 25310
in stderr.log:

Code:
2012-05-06 02:02:48.057 [STDERR] lscgid: recv_fd() failed: Unknown error: 0
2012-05-06 02:05:15.468 [STDERR] No $home variable set.
2012-05-06 02:05:15.469 [STDERR] "~/.mailrc": No match.
2012-05-06 02:10:15.470 [STDERR] No $home variable set.
2012-05-06 02:10:15.470 [STDERR] "~/.mailrc": No match.
 
Last edited:

raphidae

Well-Known Member
#18
OK so I thought it'd be a good idea to start over from scratch.

-moved /usr/local/lsws to /usr/local/lsws.old

-reinstalled 4.1.12

-webadmin is completely broken

Code:
2012-05-06 02:19:54.520 [NOTICE] Free software update of your owned license will expire in 39 days.
2012-05-06 02:19:54.520 [NOTICE] Loading LiteSpeed/4.1.12 Enterprise ...
2012-05-06 02:19:54.522 [NOTICE] [ADMIN] server socket: uds://usr/local/lsws/admin/tmp/admin.sock.7032
2012-05-06 02:19:54.522 [NOTICE] Loading configuration from /usr/local/lsws/conf/httpd_config.xml ...
2012-05-06 02:19:54.524 [NOTICE] [config] chroot is disabled.
2012-05-06 02:19:54.524 [INFO] old priority: 0, new priority: -19
2012-05-06 02:19:54.524 [INFO] [config:server:basic] For better obscurity, server version number is hidden in the response header.
2012-05-06 02:19:54.527 [NOTICE] [PID: 28015]: start cgid: 28019, /usr/local/lsws/bin/httpd
2012-05-06 02:19:54.528 [NOTICE] The maximum number of file descriptor limit is set to 115891.
2012-05-06 02:19:54.532 [NOTICE] litespeed (28015) is ready
2012-05-06 02:19:54.532 [NOTICE] [AutoRestarter] new child process with pid=28021 is forked!
2012-05-06 02:19:54.533 [NOTICE] [AutoRestarter] new child process with pid=28022 is forked!
2012-05-06 02:19:54.533 [NOTICE] [AutoRestarter] new child process with pid=28023 is forked!
2012-05-06 02:19:54.533 [INFO] Stop listener *:280.
2012-05-06 02:19:54.533 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.534 [NOTICE] [child: 28021] Successfully change current user to www
2012-05-06 02:19:54.533 [NOTICE] [AutoRestarter] new child process with pid=28024 is forked!
2012-05-06 02:19:54.534 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.534 [NOTICE] [child: 28022] Successfully change current user to www
2012-05-06 02:19:54.534 [INFO] Stop listener *:280.
2012-05-06 02:19:54.534 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.534 [NOTICE] [child: 28023] Successfully change current user to www
2012-05-06 02:19:54.534 [INFO] Stop listener *:280.
2012-05-06 02:19:54.534 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.534 [NOTICE] [child: 28024] Successfully change current user to www
2012-05-06 02:19:54.545 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28023 !
2012-05-06 02:19:54.545 [NOTICE] [AutoRestarter] child process with pid=28023 exited with status=1!
2012-05-06 02:19:54.545 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28022 !
2012-05-06 02:19:54.545 [NOTICE] [AutoRestarter] child process with pid=28022 exited with status=1!
2012-05-06 02:19:54.545 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28024 !
2012-05-06 02:19:54.649 [NOTICE] [AutoRestarter] child process with pid=28024 exited with status=1!
2012-05-06 02:19:54.649 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28021 !
2012-05-06 02:19:54.754 [NOTICE] [AutoRestarter] child process with pid=28021 exited with status=1!
2012-05-06 02:19:54.755 [NOTICE] [AutoRestarter] new child process with pid=28025 is forked!
2012-05-06 02:19:54.755 [NOTICE] [AutoRestarter] new child process with pid=28026 is forked!
2012-05-06 02:19:54.756 [NOTICE] [AutoRestarter] new child process with pid=28027 is forked!
2012-05-06 02:19:54.756 [INFO] Stop listener *:280.
2012-05-06 02:19:54.756 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.756 [NOTICE] [child: 28025] Successfully change current user to www
2012-05-06 02:19:54.756 [NOTICE] [AutoRestarter] new child process with pid=28028 is forked!
2012-05-06 02:19:54.756 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.756 [NOTICE] [child: 28026] Successfully change current user to www
2012-05-06 02:19:54.756 [INFO] Stop listener *:280.
2012-05-06 02:19:54.757 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.757 [NOTICE] [child: 28027] Successfully change current user to www
2012-05-06 02:19:54.757 [INFO] Stop listener *:280.
2012-05-06 02:19:54.757 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.757 [NOTICE] [child: 28028] Successfully change current user to www
2012-05-06 02:19:54.758 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28025 !
2012-05-06 02:19:54.759 [NOTICE] [AutoRestarter] child process with pid=28025 exited with status=1!
2012-05-06 02:19:54.759 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28026 !
2012-05-06 02:19:54.759 [NOTICE] [AutoRestarter] child process with pid=28026 exited with status=1!
2012-05-06 02:19:54.759 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28027 !
2012-05-06 02:19:54.760 [NOTICE] [AutoRestarter] child process with pid=28027 exited with status=1!
2012-05-06 02:19:54.760 [NOTICE] [AutoRestarter] cleanup children processes and unix sockets of process with pid=28028 !
2012-05-06 02:19:54.864 [NOTICE] [AutoRestarter] child process with pid=28028 exited with status=1!
2012-05-06 02:19:54.865 [NOTICE] [AutoRestarter] new child process with pid=28029 is forked!
2012-05-06 02:19:54.866 [NOTICE] [AutoRestarter] new child process with pid=28030 is forked!
2012-05-06 02:19:54.866 [NOTICE] [AutoRestarter] new child process with pid=28031 is forked!
2012-05-06 02:19:54.866 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.866 [NOTICE] [child: 28029] Successfully change current user to www
2012-05-06 02:19:54.866 [INFO] Stop listener *:280.
2012-05-06 02:19:54.866 [NOTICE] [AutoRestarter] new child process with pid=28032 is forked!
2012-05-06 02:19:54.867 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.867 [NOTICE] [child: 28030] Successfully change current user to www
2012-05-06 02:19:54.867 [INFO] Stop listener *:280.
2012-05-06 02:19:54.867 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.867 [NOTICE] [child: 28031] Successfully change current user to www
2012-05-06 02:19:54.867 [INFO] Stop listener *:280.
2012-05-06 02:19:54.867 [NOTICE] Core dump is enabled.
2012-05-06 02:19:54.867 [NOTICE] [child: 28032] Successfully change current user to www
[etc]
2012-05-06 02:20:57.999 [WARN] [AutoRestarter] forking too frequently, suspend for a while!
 

raphidae

Well-Known Member
#19
I've updated and recompiled everything on the server, kernel, world, ports. Problem is still there. Problem is also there on a clean install + updates of FreeBSD 8.3.

"FreeBSD virasena.mediamonks.net 8.3-STABLE FreeBSD 8.3-STABLE #0: Sun May 6 02:31:53 CEST 2012 terrence@virasena.mediamonks.net:/usr/obj/usr/src/sys/VIRASENA-SMP amd64"
 
Last edited:
Top