Graceful restart not so graceful

justme

Well-Known Member
#1
1) Ubuntu 10.04LTS amd64
2) 4.1.10std
3) PHP 5.3.2-1ubuntu4.10 FCGI+PHP-FPM

2012-01-18 21:06:12.384 [ERROR] HttpListener::start(): Can't listen at address *:80: Address already in use!
2012-01-18 21:06:12.384 [ERROR] HttpServer::addListener(*:80) failed to create new listener
2012-01-18 21:06:12.384 [ERROR] [config:server:listener:*:80] failed to start listener on address [ANY]:80!

I did not have this issue with <4.1 versions. I either need to manually stop and restart lsws, or wait a good while (a minute or two at least).
 

justme

Well-Known Member
#3
Have you tried LSPHP (LSAPI + PHP) which is much better than FCGI+PHP+FPM?
Well, it is not better in my situation:
-running on low volume and -std, performance does not matter much (and do you have benches LSAPI vs FCGI+PHP+FPM?)
-having to compile a new LSAPI module each time there is a PHP upgrade is a PITA
And I did not have this issue with previous versions of Litespeed even using FCGI.
thanks for your help!
 

NiteWave

Administrator
#4
2012-01-18 21:06:12.384 [ERROR] HttpListener::start(): Can't listen at address *:80: Address already in use!
2012-01-18 21:06:12.384 [ERROR] HttpServer::addListener(*:80) failed to create new listener
2012-01-18 21:06:12.384 [ERROR] [config:server:listener:*:80] failed to start listener on address [ANY]:80!
is there another process already listen to port 80 ?

please run
#netstat -ntlp
 

justme

Well-Known Member
#5
is there another process already listen to port 80 ?

please run
#netstat -ntlp
Before restart:
Code:
# netstat -nlpt|grep ":80"
tcp6       0      0 :::80                   :::*                    LISTEN      9852/litespeed (lsh
After restart:
Code:
# netstat -nlpt|grep ":80"
tcp6       0      0 :::80                   :::*                    LISTEN      9852/litespeed (lsh
# netstat -nlpt|grep ":443 "
tcp        0      0 188.165.55.67:443       0.0.0.0:*               LISTEN      9852/litespeed (lsh
tcp        0      0 87.98.157.151:443       0.0.0.0:*               LISTEN      9852/litespeed (lsh
And 443 is OK, 80 is not.

After a couple minutes, another graceful fixes port 80:
Code:
# netstat -nlpt|grep ":443 "
tcp        0      0 188.165.55.67:443       0.0.0.0:*               LISTEN      24034/litespeed (ls
tcp        0      0 87.98.157.151:443       0.0.0.0:*               LISTEN      24034/litespeed (ls
# netstat -nlpt|grep ":80 "
tcp6       0      0 :::80                   :::*                    LISTEN      24034/litespeed (ls
 

webizen

Well-Known Member
#6
Can you paste few entries around (before and after) the ERROR entries you pasted above? Just to see any trace/cause of the problem.
 

justme

Well-Known Member
#8
2012-01-19 09:36:49.313 [NOTICE] Loading LiteSpeed/4.1.10 Standard ...
2012-01-19 09:36:49.325 [NOTICE] [ADMIN] server socket: uds://usr/local/lsws/admin/tmp/admin.sock.7734
2012-01-19 09:36:49.325 [NOTICE] Loading configuration from /usr/local/lsws/conf/httpd_config.xml ...
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [[::]:80]
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [87.98.157.151:443]
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [*:7080]
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [188.165.55.67:443]
2012-01-19 09:36:49.328 [INFO] old priority: 0, new priority: 0
2012-01-19 09:36:49.328 [INFO] [config:server:basic] For better obscurity, server version number is hidden in the response header.
2012-01-19 09:36:49.371 [NOTICE] [PID: 21093]: start cgid: 21094, /usr/local/lsws/bin/httpd
2012-01-19 09:36:49.734 [ERROR] HttpListener::start(): Can't listen at address *:80: Address already in use!
2012-01-19 09:36:49.734 [ERROR] HttpServer::addListener(*:80) failed to create new listener
2012-01-19 09:36:49.734 [ERROR] [config:server:listener:*:80] failed to start listener on address [ANY]:80!
2012-01-19 09:36:49.763 [NOTICE] The maximum number of file descriptor limit is set to 4096.
2012-01-19 09:36:49.864 [INFO] [config:vhost:x:logging] no separate logging set up.
2012-01-19 09:36:49.866 [INFO] [config:vhost:y:logging] no separate logging set up.
2012-01-19 09:36:49.906 [INFO] [config:vhost:z:logging] no separate logging set up.
2012-01-19 09:36:49.907 [INFO] [config:vhost:k:logging] no separate logging set up.
2012-01-19 09:36:49.908 [INFO] [config:vhost:v:logging] no separate logging set up.
2012-01-19 09:36:49.924 [INFO] [config:vhost:w:logging] no separate logging set up.
2012-01-19 09:36:49.935 [INFO] Stop listener [::]:80.
2012-01-19 09:36:49.936 [NOTICE] litespeed (21093) is ready
2012-01-19 09:36:49.937 [NOTICE] [AutoRestarter] new child process with pid=21095 is forked!
2012-01-19 09:36:49.938 [NOTICE] [child: 21095] Successfully change current user to www-data
2012-01-19 09:36:49.938 [NOTICE] [Child: 21095] Core dump is enabled.
2012-01-19 09:36:49.938 [NOTICE] [Child: 21095] Setup swapping space...
2012-01-19 09:36:49.950 [NOTICE] [Child: 21095] LiteSpeed/4.1.10 Standard starts successfully!
2012-01-19 09:36:50.109 [NOTICE] [AutoUpdate] Checking for new releases..., pid=21096
2012-01-19 09:36:50.182 [NOTICE] Start to clean up cache directory, pid=21097
2012-01-19 09:36:50.424 [INFO] [AutoUpdate] No new update.
2012-01-19 09:37:09.942 [NOTICE] [Child: 9855] Shut down successfully!
2012-01-19 09:37:09.942 [NOTICE] [php-fpm] stop worker processes
2012-01-19 09:37:09.942 [NOTICE] [AdminPHP] stop worker processes
2012-01-19 09:39:56.785 [NOTICE] Server restart request from admin interface!
2012-01-19 09:39:56.786 [NOTICE] [PID: 21093]: start cgid: 24031, /usr/local/lsws/bin/lscgid
2012-01-19 09:39:56.786 [NOTICE] [Child: 21095] Start shutting down gracefully ...
2012-01-19 09:39:56.787 [INFO] Pass listener 87.98.157.151:443.
2012-01-19 09:39:56.787 [INFO] Pass listener *:7080.
2012-01-19 09:39:56.787 [INFO] Pass listener 188.165.55.67:443.
2012-01-19 09:39:56.787 [INFO] Stop listener 87.98.157.151:443.
2012-01-19 09:39:56.787 [INFO] Stop listener *:7080.
2012-01-19 09:39:56.787 [INFO] Stop listener 188.165.55.67:443.
2012-01-19 09:39:56.902 [NOTICE] New litespeed process is ready, litespeed (21095) stops listeners
 

webizen

Well-Known Member
#10
2012-01-19 09:36:49.313 [NOTICE] Loading LiteSpeed/4.1.10 Standard ...
2012-01-19 09:36:49.325 [NOTICE] [ADMIN] server socket: uds://usr/local/lsws/admin/tmp/admin.sock.7734
2012-01-19 09:36:49.325 [NOTICE] Loading configuration from /usr/local/lsws/conf/httpd_config.xml ...
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [[::]:80]
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [87.98.157.151:443]
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [*:7080]
2012-01-19 09:36:49.328 [NOTICE] Recovering server socket: [188.165.55.67:443]
2012-01-19 09:36:49.328 [INFO] old priority: 0, new priority: 0
2012-01-19 09:36:49.328 [INFO] [config:server:basic] For better obscurity, server version number is hidden in the response header.
2012-01-19 09:36:49.371 [NOTICE] [PID: 21093]: start cgid: 21094, /usr/local/lsws/bin/httpd
2012-01-19 09:36:49.734 [ERROR] HttpListener::start(): Can't listen at address *:80: Address already in use!
2012-01-19 09:36:49.734 [ERROR] HttpServer::addListener(*:80) failed to create new listener
2012-01-19 09:36:49.734 [ERROR] [config:server:listener:*:80] failed to start listener on address [ANY]:80!
2012-01-19 09:36:49.763 [NOTICE] The maximum number of file descriptor limit is set to 4096.
2012-01-19 09:36:49.864 [INFO] [config:vhost:x:logging] no separate logging set up.
2012-01-19 09:36:49.866 [INFO] [config:vhost:y:logging] no separate logging set up.
2012-01-19 09:36:49.906 [INFO] [config:vhost:z:logging] no separate logging set up.
2012-01-19 09:36:49.907 [INFO] [config:vhost:k:logging] no separate logging set up.
2012-01-19 09:36:49.908 [INFO] [config:vhost:v:logging] no separate logging set up.
2012-01-19 09:36:49.924 [INFO] [config:vhost:w:logging] no separate logging set up.
2012-01-19 09:36:49.935 [INFO] Stop listener [::]:80.
2012-01-19 09:36:49.936 [NOTICE] litespeed (21093) is ready
2012-01-19 09:36:49.937 [NOTICE] [AutoRestarter] new child process with pid=21095 is forked!
2012-01-19 09:36:49.938 [NOTICE] [child: 21095] Successfully change current user to www-data
2012-01-19 09:36:49.938 [NOTICE] [Child: 21095] Core dump is enabled.
2012-01-19 09:36:49.938 [NOTICE] [Child: 21095] Setup swapping space...
2012-01-19 09:36:49.950 [NOTICE] [Child: 21095] LiteSpeed/4.1.10 Standard starts successfully!
2012-01-19 09:36:50.109 [NOTICE] [AutoUpdate] Checking for new releases..., pid=21096
2012-01-19 09:36:50.182 [NOTICE] Start to clean up cache directory, pid=21097
2012-01-19 09:36:50.424 [INFO] [AutoUpdate] No new update.
2012-01-19 09:37:09.942 [NOTICE] [Child: 9855] Shut down successfully!
2012-01-19 09:37:09.942 [NOTICE] [php-fpm] stop worker processes
2012-01-19 09:37:09.942 [NOTICE] [AdminPHP] stop worker processes
2012-01-19 09:39:56.785 [NOTICE] Server restart request from admin interface!
2012-01-19 09:39:56.786 [NOTICE] [PID: 21093]: start cgid: 24031, /usr/local/lsws/bin/lscgid
2012-01-19 09:39:56.786 [NOTICE] [Child: 21095] Start shutting down gracefully ...
2012-01-19 09:39:56.787 [INFO] Pass listener 87.98.157.151:443.
2012-01-19 09:39:56.787 [INFO] Pass listener *:7080.
2012-01-19 09:39:56.787 [INFO] Pass listener 188.165.55.67:443.
2012-01-19 09:39:56.787 [INFO] Stop listener 87.98.157.151:443.
2012-01-19 09:39:56.787 [INFO] Stop listener *:7080.
2012-01-19 09:39:56.787 [INFO] Stop listener 188.165.55.67:443.
2012-01-19 09:39:56.902 [NOTICE] New litespeed process is ready, litespeed (21095) stops listeners
do 'lsof | grep :80' in between server shutdown and new httpd pick up. it is to see any related processes hold :80 during the time in question.
 

justme

Well-Known Member
#11
No pending :80, but I just changed the main binding from [ANY] IPV6 to ANY. And so far so good! Let's try to change it back and see.. Nope, still fine. I am at loss to explain what caused it, fingers crossed :D
 
Top