Hi, Sorry to insist, really, but this bug is really annoying: today, two more apache servers have frozen while being scanner by a crawler:
[Sat Jul 15 14:25:40 2006] [error] [client 66.147.238.238] File does not exist: /home/abc.ch/www/data/blogs [Sat Jul 15 14:25:40 2006] [error] [client 66.147.238.238] File does not exist: /home/abc.ch/www/data/blog [Sat Jul 15 14:25:41 2006] [error] [client 66.147.238.238] File does not exist: /home/abc.ch/www/data/blogtest [Sat Jul 15 14:25:41 2006] [error] [client 66.147.238.238] File does not exist: /home/abc.ch/www/data/b2 [Sat Jul 15 14:25:42 2006] [warn] (61)Connection refused: connect to listener on 0.0.0.0:80 [Sat Jul 15 14:25:43 2006] [warn] (61)Connection refused: connect to listener on 0.0.0.0:80 [Sat Jul 15 14:25:44 2006] [warn] (61)Connection refused: connect to listener on 0.0.0.0:80 [Sat Jul 15 14:25:45 2006] [warn] (61)Connection refused: connect to listener on 0.0.0.0:80 I'm trying to figure out what happens: here is a ps before restarting apache: j25# ps -afxu USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND root 2133 0.0 0.0 1292 760 ?? IsJ 26Mar06 0:17.05 /usr/sbin/syslogd -ss root 2198 0.0 0.0 3352 1932 ?? IsJ 26Mar06 0:00.46 /usr/sbin/sshd root 2203 0.0 0.1 3396 2288 ?? SsJ 26Mar06 2:59.26 sendmail: accepting connections (sendmail) smmsp 2207 0.0 0.1 3296 2100 ?? IsJ 26Mar06 0:03.80 sendmail: Queue [EMAIL PROTECTED]:30:00 for /var/spool/clientmqueue (sendmail) root 2213 0.0 0.0 1312 864 ?? IsJ 26Mar06 0:22.97 /usr/sbin/cron -s root 2241 0.0 0.3 23208 12368 ?? IsJ 11Jul06 0:21.29 /usr/local/sbin/httpd -DNOHTTPACCEPT root 2261 0.0 0.0 1384 952 ?? IsJ 26Mar06 0:01.57 /usr/sbin/inetd -wW -a 83.222.129.25 root 41279 0.0 0.1 6096 3160 ?? IsJ 5:41PM 0:00.04 sshd: plang [priv] (sshd) plang 41281 0.0 0.1 6092 3156 ?? SJ 5:41PM 0:00.02 sshd: [EMAIL PROTECTED] (sshd) www 80889 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80891 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80892 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80893 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80894 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80897 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80903 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80909 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80910 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80911 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80917 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80924 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80928 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80936 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] www 80937 0.0 0.0 0 0 ?? REJ Sat02PM 0:00.01 [httpd] What are all these processes with the REJ state? After an apache restart, here is a ps again: j25# ps -afxu USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND root 2133 0.0 0.0 1292 760 ?? IsJ 26Mar06 0:17.06 /usr/sbin/syslogd -ss root 2198 0.0 0.0 3352 1932 ?? IsJ 26Mar06 0:00.46 /usr/sbin/sshd root 2203 0.0 0.1 3396 2288 ?? SsJ 26Mar06 2:59.27 sendmail: accepting connections (sendmail) smmsp 2207 0.0 0.1 3296 2100 ?? IsJ 26Mar06 0:03.80 sendmail: Queue [EMAIL PROTECTED]:30:00 for /var/spool/clientmqueue (sendmail) root 2213 0.0 0.0 1312 864 ?? IsJ 26Mar06 0:22.97 /usr/sbin/cron -s root 2261 0.0 0.0 1384 952 ?? IsJ 26Mar06 0:01.57 /usr/sbin/inetd -wW -a 83.222.129.25 root 41279 0.0 0.1 6096 3160 ?? IsJ 5:41PM 0:00.04 sshd: plang [priv] (sshd) plang 41281 0.0 0.1 6092 3156 ?? SJ 5:41PM 0:00.39 sshd: [EMAIL PROTECTED] (sshd) root 41657 0.0 0.3 22496 11680 ?? SsJ 5:47PM 0:00.20 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41658 0.0 0.3 22572 11756 ?? IJ 5:47PM 0:00.01 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41659 0.0 0.3 22564 11752 ?? IJ 5:47PM 0:00.01 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41660 0.0 0.3 22524 11696 ?? IJ 5:47PM 0:00.00 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41661 0.0 0.3 22524 11696 ?? IJ 5:47PM 0:00.00 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41662 0.0 0.3 22524 11696 ?? IJ 5:47PM 0:00.00 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41663 0.0 0.3 22524 11716 ?? IJ 5:47PM 0:00.00 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41664 0.0 0.3 22524 11716 ?? IJ 5:48PM 0:00.00 /usr/local/sbin/httpd -DNOHTTPACCEPT www 41665 0.0 0.3 22524 11716 ?? IJ 5:48PM 0:00.00 /usr/local/sbin/httpd -DNOHTTPACCEPT REJ has become IJ now, and the server works again. I did the same for sockstat and netstat -a, each time before and after the apache restart: Before restart: =============== j25# sockstat USER COMMAND PID FD PROTO LOCAL ADDRESS FOREIGN ADDRESS plang sshd 41281 3 tcp4 83.222.129.25:22 212.147.59.29:60307 plang sshd 41281 4 stream -> ?? root sshd 41279 3 tcp4 83.222.129.25:22 212.147.59.29:60307 root sshd 41279 5 stream -> ?? root httpd 2241 3 tcp4 83.222.129.25:80 *:* mysql mysqld 92536 3 tcp4 83.222.129.25:3306 *:* mysql mysqld 92536 4 stream /tmp/mysql.sock root inetd 2261 4 tcp4 83.222.129.25:21 *:* root inetd 2261 5 tcp4 83.222.129.25:110 *:* smmsp sendmail 2207 3 dgram -> /var/run/log root sendmail 2203 3 dgram -> /var/run/logpriv root sendmail 2203 4 tcp4 83.222.129.25:25 *:* root sendmail 2203 5 tcp4 83.222.129.25:587 *:* root sshd 2198 3 tcp4 83.222.129.25:22 *:* root syslogd 2133 3 dgram /var/run/log root syslogd 2133 4 dgram /var/run/logpriv j25# netstat -a netstat: kvm not available Active Internet connections (including servers) Proto Recv-Q Send-Q Local Address Foreign Address (state) tcp4 0 52 j25.ssh f29.60307 ESTABLISHED tcp4 248 0 j25.http crawl-66-249-65-.61967 CLOSE_WAIT tcp4 248 0 j25.http crawl-66-249-65-.39163 CLOSE_WAIT tcp4 248 0 j25.http crawl-66-249-65-.49799 CLOSE_WAIT tcp4 397 0 j25.http 165.222.186.195.56942 CLOSE_WAIT tcp4 0 0 j25.http *.* LISTEN tcp4 0 0 j25.3306 *.* LISTEN tcp4 0 0 j25.pop3 *.* LISTEN tcp4 0 0 j25.ftp *.* LISTEN tcp4 0 0 j25.submission *.* LISTEN tcp4 0 0 j25.smtp *.* LISTEN tcp4 0 0 j25.ssh *.* LISTEN netstat: kvm not available Active UNIX domain sockets Address Type Recv-Q Send-Q Inode Conn Refs Nextref Addr cce7bdac stream 0 0 0 c6213834 0 0 c6213834 stream 0 0 0 cce7bdac 0 0 ccc5b7a8 stream 0 0 c7f52dd0 0 0 0 /tmp/mysql.sock c6213230 dgram 0 0 0 c5b0294c 0 0 c5b02b7c dgram 0 0 0 c5b02af0 0 0 c5b02af0 dgram 0 0 c61df330 0 c5b02b7c 0 /var/run/logpriv c5b0294c dgram 0 0 c61df440 0 c6213230 0 /var/run/log After restart: ============== j25# sockstat USER COMMAND PID FD PROTO LOCAL ADDRESS FOREIGN ADDRESS www httpd 41665 3 tcp4 83.222.129.25:80 *:* www httpd 41664 3 tcp4 83.222.129.25:80 *:* www httpd 41663 3 tcp4 83.222.129.25:80 *:* www httpd 41662 3 tcp4 83.222.129.25:80 *:* www httpd 41661 3 tcp4 83.222.129.25:80 *:* www httpd 41660 3 tcp4 83.222.129.25:80 *:* www httpd 41659 3 tcp4 83.222.129.25:80 *:* www httpd 41658 3 tcp4 83.222.129.25:80 *:* root httpd 41657 3 tcp4 83.222.129.25:80 *:* plang sshd 41281 3 tcp4 83.222.129.25:22 212.147.59.29:60307 plang sshd 41281 4 stream -> ?? root sshd 41279 3 tcp4 83.222.129.25:22 212.147.59.29:60307 root sshd 41279 5 stream -> ?? mysql mysqld 92536 3 tcp4 83.222.129.25:3306 *:* mysql mysqld 92536 4 stream /tmp/mysql.sock root inetd 2261 4 tcp4 83.222.129.25:21 *:* root inetd 2261 5 tcp4 83.222.129.25:110 *:* smmsp sendmail 2207 3 dgram -> /var/run/log root sendmail 2203 3 dgram -> /var/run/logpriv root sendmail 2203 4 tcp4 83.222.129.25:25 *:* root sendmail 2203 5 tcp4 83.222.129.25:587 *:* root sshd 2198 3 tcp4 83.222.129.25:22 *:* root syslogd 2133 3 dgram /var/run/log root syslogd 2133 4 dgram /var/run/logpriv j25# netstat -a netstat: kvm not available Active Internet connections (including servers) Proto Recv-Q Send-Q Local Address Foreign Address (state) tcp4 0 0 j25.http *.* LISTEN tcp4 0 52 j25.ssh f29.60307 ESTABLISHED tcp4 0 0 j25.3306 *.* LISTEN tcp4 0 0 j25.pop3 *.* LISTEN tcp4 0 0 j25.ftp *.* LISTEN tcp4 0 0 j25.submission *.* LISTEN tcp4 0 0 j25.smtp *.* LISTEN tcp4 0 0 j25.ssh *.* LISTEN netstat: kvm not available Active UNIX domain sockets Address Type Recv-Q Send-Q Inode Conn Refs Nextref Addr cce7bdac stream 0 0 0 c6213834 0 0 c6213834 stream 0 0 0 cce7bdac 0 0 ccc5b7a8 stream 0 0 c7f52dd0 0 0 0 /tmp/mysql.sock c6213230 dgram 0 0 0 c5b0294c 0 0 c5b02b7c dgram 0 0 0 c5b02af0 0 0 c5b02af0 dgram 0 0 c61df330 0 c5b02b7c 0 /var/run/logpriv c5b0294c dgram 0 0 c61df440 0 c6213230 0 /var/run/log Can anyone explain what happens here, and in what direction to search? In advance, thank for any idea that could help me solve this problem! ---------------------------------- Philippe Lang, Ing. Dipl. EPFL Attik System rte de la Fonderie 2 1700 Fribourg Switzerland http://www.attiksystem.ch Tel: +41 (26) 422 13 75 Fax: +41 (26) 422 13 76 >>> Hi, >>> >>> Every now and then, Apache 2.2.2 starts filling my httpd-error.log >>> with thousands of lines like: >>> >>> [Sat Jul 08 20:57:32 2006] [warn] (61)Connection refused: >>> connect to listener on 0.0.0.0:80 [Sat Jul 08 20:57:33 2006] [warn] >>> (61)Connection refused: connect to listener on 0.0.0.0:80 [Sat Jul >>> 08 20:57:34 2006] [warn] (61)Connection >>> refused: connect to listener on 0.0.0.0:80 [Sat Jul 08 >>> 20:57:35 2006] [warn] (61)Connection refused: connect to listener on >>> 0.0.0.0:80 [Sat Jul 08 20:57:36 2006] [warn] (61)Connection refused: >>> connect to listener on 0.0.0.0:80 [Sat Jul 08 20:57:37 2006] [warn] >>> (61)Connection refused: connect to listener on 0.0.0.0:80 [Sat Jul >>> 08 20:57:38 2006] [warn] (61)Connection refused: connect to listener >>> on 0.0.0.0:80 [Sat Jul 08 20:57:39 2006] [warn] (61)Connection >>> refused: connect to listener on 0.0.0.0:80 [Sat Jul 08 20:57:40 >>> 2006] [warn] (61)Connection refused: connect to listener on >>> 0.0.0.0:80 >>> >>> I'm running Apache in FreeBSD 6.0 RELEASE-p2 jails. >>> >>> Restarting Apache cures the problem for some time, until the problem >>> appears again. It is not that frequent, but the servers are not >>> much loaded either. >>> >>> I think I saw this problem appear with Apache 2.0, 2.1, and 2.2, so >>> it's apparently here for a while. And others had this problem too: >>> >>> http://groups.google.ch/group/lucky.freebsd.apache/browse_thre >>> ad/thread/7a5735ae7a3a4c2d/e2d0d9ba4ad7266e?lnk=st&q=Connectio >> n+refused%3A+connect+to+listener+on+0.0.0.0%3A80&rnum=1> >> &hl=de#e2d0d9ba4ad7266e >>> >>> I'm pretty sure this problem must be BSD or Jails specific. >>> Does anyone have the same problem, or maybe a workaround? >>> Note that Lighttpd NEVER had this problem on this server. >> >> One more precision: of course, when apache starts filling the log >> with "Connection refused: connect to listener on 0.0.0.0:80", the web >> server does not respond anymore, until I restart it. > > Hi again, > > I did some further tests with Apache under FreeBSD 6.0 - > Jail, and unfortunately, there is still the same annoying > problem: suddenly the log starts being filled with hundreds > of lines "Connection refused: connect to listener on > 0.0.0.0:80", and Apache does not respond anymore. > > I have a log example, that shows the Apache freeze: > > -------------------------- > [Sat Jul 15 14:25:36 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/adserver > [Sat Jul 15 14:25:37 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/phpAdsNew > [Sat Jul 15 14:25:37 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/phpadsnew > [Sat Jul 15 14:25:37 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/phpads > [Sat Jul 15 14:25:37 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/Ads > [Sat Jul 15 14:25:38 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/ads > [Sat Jul 15 14:25:38 2006] [error] [client 66.147.238.238] > script '/home/verticaldrape/www/data/xmlrpc.php' not found or > unabl e to stat [Sat Jul 15 14:25:39 2006] [error] [client > 66.147.238.238] File does not exist: > /home/verticaldrape/www/data/xmlrpc > [Sat Jul 15 14:25:39 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/xmlsrv > [Sat Jul 15 14:25:39 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/blog > [Sat Jul 15 14:25:39 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/drupal > [Sat Jul 15 14:25:40 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/community > [Sat Jul 15 14:25:40 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/blogs > [Sat Jul 15 14:25:40 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/blogs > [Sat Jul 15 14:25:40 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/blog > [Sat Jul 15 14:25:41 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/blogtest > [Sat Jul 15 14:25:41 2006] [error] [client 66.147.238.238] > File does not exist: > /home/verticaldrape/www/data/b2 > [Sat Jul 15 14:25:42 2006] [warn] (61)Connection refused: > connect to listener on 0.0.0.0:80 [Sat Jul 15 14:25:43 2006] > [warn] (61)Connection refused: connect to listener on > 0.0.0.0:80 [Sat Jul 15 14:25:44 2006] [warn] (61)Connection > refused: connect to listener on 0.0.0.0:80 [Sat Jul 15 > 14:25:45 2006] [warn] (61)Connection refused: connect to > listener on 0.0.0.0:80 [Sat Jul 15 14:25:46 2006] [warn] > (61)Connection refused: connect to listener on 0.0.0.0:80 > [Sat Jul 15 14:25:47 2006] [warn] (61)Connection refused: > connect to listener on 0.0.0.0:80 [Sat Jul 15 14:25:48 2006] > [warn] (61)Connection refused: connect to listener on > 0.0.0.0:80 [Sat Jul 15 14:25:49 2006] [warn] (61)Connection > refused: connect to listener on 0.0.0.0:80 [Sat Jul 15 > 14:25:50 2006] [warn] (61)Connection refused: connect to > listener on 0.0.0.0:80 [Sat Jul 15 14:25:51 2006] [warn] > (61)Connection refused: connect to listener on 0.0.0.0:80 > > [snip] > > [Sun Jul 16 04:50:10 2006] [warn] (61)Connection refused: > connect to listener on 0.0.0.0:80 [Sun Jul 16 04:50:11 2006] > [warn] (61)Connection refused: connect to listener on > 0.0.0.0:80 [Sun Jul 16 04:50:12 2006] [warn] (61)Connection > refused: connect to listener on 0.0.0.0:80 [Sun Jul 16 > 04:50:13 2006] [warn] (61)Connection refused: connect to > listener on 0.0.0.0:80 [Sun Jul 16 04:50:14 2006] [warn] > (61)Connection refused: connect to listener on 0.0.0.0:80 > [Sun Jul 16 04:50:15 2006] [warn] (61)Connection refused: > connect to listener on 0.0.0.0:80 [Sun Jul 16 04:50:16 2006] > [warn] (61)Connection refused: connect to listener on > 0.0.0.0:80 [Sun Jul 16 04:50:17 2006] [warn] (61)Connection > refused: connect to listener on 0.0.0.0:80 [Sun Jul 16 > 04:50:18 2006] [warn] (61)Connection refused: connect to > listener on 0.0.0.0:80 [Sun Jul 16 04:50:19 2006] [warn] > (61)Connection refused: connect to listener on 0.0.0.0:80 > [Sun Jul 16 04:50:20 2006] [warn] (61)Connection refused: > connect to listener on 0.0.0.0:80 [Sun Jul 16 04:50:21 2006] > [warn] (61)Connection refused: connect to listener on 0.0.0.0:80 > > -------------------------- > > The freeze appears apparently under high load, with about 4 > connections a second from a robot. > > I made 2 changes in httpd.conf the last days, which > apparently did not help: > > 1. Commented out: > #LoadModule ssl_module libexec/apache22/mod_ssl.so > > 2. Added: > AcceptFilter http none > > > Does anyone have an idea where this problem might come from? > I'm pretty sure it must be linked to the jail system in some > way... Any chance things might be corrected in FreeBSD 6.1? > > My jails are all configured like this: > > jail_j29_hostname="j29.attiksystem.ch" > jail_j29_ip="83.222.129.29" > jail_j29_rootdir="/usr/jails/j29" > jail_j29_exec="/bin/sh /etc/rc" > jail_j29_devfs_enable="YES" > > I'm using the network interface "em" driver. > > > Thanks for your help,
smime.p7s
Description: S/MIME cryptographic signature