FreeBSD 6 Jails - REJ apache processes? [was: Apache 2 in 6.0 jails: Connection refused: connect to listener on 0.0.0.0:80]

Philippe Lang philippe.lang at attiksystem.ch
Tue Jul 18 16:19:51 UTC 2006


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 runner at 00: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: plang at ttyp0 (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 runner at 00: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: plang at ttyp0 (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,

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 3125 bytes
Desc: not available
Url : http://lists.freebsd.org/pipermail/freebsd-questions/attachments/20060718/62c20d35/smime.bin


More information about the freebsd-questions mailing list