Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 25 May 2011 00:25:52 -0700
From:      Jeremy Chadwick <freebsd@jdc.parodius.com>
To:        Doug Barton <dougb@FreeBSD.org>
Cc:        freebsd-apache@FreeBSD.org, alfred@freebsd.org
Subject:   Re: Interesting apache 2.2 + accept filter problem
Message-ID:  <20110525072552.GA31990@icarus.home.lan>
In-Reply-To: <4DDC9B15.2090703@FreeBSD.org>
References:  <4DDC9B15.2090703@FreeBSD.org>

next in thread | previous in thread | raw e-mail | index | archive | help
On Tue, May 24, 2011 at 11:00:53PM -0700, Doug Barton wrote:
> I have an odd one here, and I'm hoping to get some insight. I'm
> using apache 2.2 (latest ports version) along with the accf_http
> kernel module (which is loaded). If I start it the "normal" way,
> everything works just fine. However if I start it with -D FOREGROUND
> then I get the following error in httpd-error.log:
> 
> (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
> 
> So I reduced everything down to a test case, and I can easily
> reproduce it with nothing but a clean ports install (minus SSL,
> which doesn't make a difference in the outcome, but simplified the
> ktrace).
> 
> I've run 'ktrace httpd' and 'ktrace httpd -D FOREGROUND' numerous
> times, and there is one very clear difference. The first, which
> works, looks like this:
> 
>  48226 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_REUSEADDR,0x7fffffffe80c,0x4)
>  48226 initial thread RET   setsockopt 0
>  48226 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_KEEPALIVE,0x7fffffffe80c,0x4)
>  48226 initial thread RET   setsockopt 0
>  48226 initial thread CALL  setsockopt(0x3,0x6,0x1,0x7fffffffe7ec,0x4)
>  48226 initial thread RET   setsockopt 0
>  48226 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_ACCEPTFILTER,0x7fffffffe6e0,0x100)
>  48226 initial thread RET   setsockopt 0
> 
> The weird thing is that the second one, which produces the error, is
> exactly the same, except that there is one extra call at the end,
> which is the one that fails:
> 
>  48208 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_REUSEADDR,0x7fffffffe7ec,0x4)
>  48208 initial thread RET   setsockopt 0
>  48208 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_KEEPALIVE,0x7fffffffe7ec,0x4)
>  48208 initial thread RET   setsockopt 0
>  48208 initial thread CALL  setsockopt(0x3,0x6,0x1,0x7fffffffe7cc,0x4)
>  48208 initial thread RET   setsockopt 0
>  48208 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_ACCEPTFILTER,0x7fffffffe6c0,0x100)
>  48208 initial thread RET   setsockopt 0
>  48208 initial thread CALL
> setsockopt(0x3,SOL_SOCKET,SO_ACCEPTFILTER,0x7fffffffe6c0,0x100)
>  48208 initial thread RET   setsockopt -1 errno 22 Invalid argument
> 
> I cannot figure out what it is about running in the foreground that
> is causing that last call, and I've run out of things to test or
> try, so I'm asking for help. Any ideas?
> 
> BTW, not sure it matters but the the reason that I want to add -D
> FOREGROUND is for use with daemontools. However I've managed to
> isolate the error to just 'httpd -D FOREGROUND' on the command line
> without anything else involved.

For what it's worth, I've seen this exact error for many years now
(since 2.0 at least, possibly earlier).  I always assumed it had
something to do with the apache22 rc.d script auto-loading http_accf,
followed by Apache itself trying to load the same module thus throwing
the error.  I imagine on SIGUSR1 it also tries to re-load the module and
thusly fails.

We use the following in rc.conf:

apache22_enable="yes"
apache22_http_accept_enable="yesA

Proof of my statement, re: log rotation and SIGUSR1 showing the same
problem, and also re: we don't use -D FOREGROUND:

$ grep httpready /var/log/httpd-error*
/var/log/httpd-error.log.0:[Wed May 25 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.1:[Tue May 24 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.10:[Sun May 15 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.11:[Sat May 14 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.12:[Fri May 13 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.13:[Thu May 12 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.2:[Mon May 23 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.3:[Sun May 22 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.4:[Sat May 21 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.5:[Fri May 20 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.6:[Thu May 19 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.7:[Wed May 18 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.8:[Tue May 17 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter
/var/log/httpd-error.log.9:[Mon May 16 00:00:01 2011] [warn] (22)Invalid argument: Failed to enable the 'httpready' Accept Filter

It doesn't seem to harm anything from what I can tell.

The setsockopt(2) man page might shed some light on what's going on, but
I'd really have to look at the Apache source + kernel source again to
see if I could figure out what was going on.  errno 22 is EINVAL, thus:

  [EINVAL]           Installing an accept_filter(9) on a non-listening
                     socket was attempted.

Alfred was involved in making this module, so I'm CC'ing him here.  I
doubt we'd be able to reach David Filo at this point in time.  ;-)

-- 
| Jeremy Chadwick                                   jdc@parodius.com |
| Parodius Networking                       http://www.parodius.com/ |
| UNIX Systems Administrator                  Mountain View, CA, USA |
| Making life hard for others since 1977.               PGP 4BD6C0CB |




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20110525072552.GA31990>