httpd-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Alexis Huxley <ahux...@gmx.net>
Subject "(97)Address family not supported by protocol" causes "disk ticking"?
Date Sat, 21 Feb 2004 11:00:25 GMT
I'm running apache 2.1dev, and I've posted to the -user list with
no response, so now I'm a bit stuck as to where next to try, so I'm
posting here.  Apologies if this is the wrong place.

About once every three weeks it happens that the hard disk of the
machine where I run apache2 starts audibly "ticking" - i.e. it starts
making some sort of non-cached access (maybe the log writing below?) at
a rate of once per second.

The server could still serve other pages without problem, so there
was no DoS.

The first few times it happened I rebooted, assuming the disk or
controller had got its knickers in a twist. The next times I shutdown
all of the locally added init.d scripts which fixed it. The next
time I shut down half of those init.d scripts which worked. Next
time half of that half, and so on until eventually I traced it down
to the httpd daemon, which was yesterday!

I checked the apache logs and I see this in error_log:

        [Mon Feb 16 23:35:33 2004] [warn] (97)Address family not supported by protocol: get
socket to connect to listener
        [Mon Feb 16 23:35:34 2004] [warn] (97)Address family not supported by protocol: get
socket to connect to listener
        [Mon Feb 16 23:35:35 2004] [warn] (97)Address family not supported by protocol: get
socket to connect to listener
        [Mon Feb 16 23:35:36 2004] [warn] (97)Address family not supported by protocol: get
socket to connect to listener
        [Mon Feb 16 23:35:37 2004] [warn] (97)Address family not supported by protocol: get
socket to connect to listener
        ...

The first entry above was the first entry caused yesterday's 'incident',
but the log entries went on - at one second intervals - until I killed 
httpd.

I wondered if some access had triggered it so I checked the access_log
and immediately before 23:35:33 I have the following (sorry for very
long lines!):

        cache-mtc-aa06.proxy.aol.com - - [16/Feb/2004:23:35:16 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/
HTTP/1.0" 200 8755 "http://www.google.com/search?q=Schliersee&hl=en&lr=&ie=UTF-8&start=310&sa=N"
"Mozilla/4.0 (compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ak04.proxy.aol.com - - [16/Feb/2004:23:35:18 +0100] "GET /~alexis/STABLE/css/standard.css
HTTP/1.0" 200 5017 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ab10.proxy.aol.com - - [16/Feb/2004:23:35:21 +0100] "GET /~alexis/STABLE/images/d_arrow_7rows.gif
HTTP/1.0" 200 242 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ab10.proxy.aol.com - - [16/Feb/2004:23:35:21 +0100] "GET /~alexis/STABLE/images/d_arrow_2rows.gif
HTTP/1.1" 200 111 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-aa08.proxy.aol.com - - [16/Feb/2004:23:35:21 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-map.jpg
HTTP/1.0" 200 3005 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ad09.proxy.aol.com - - [16/Feb/2004:23:35:21 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-5_20021110-0981_de-gindelalmschneid-tegernsee_michael-light-snow.jpg
HTTP/1.0" 200 2279 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ad14.proxy.aol.com - - [16/Feb/2004:23:35:22 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-5_20021110-0982_de-gindelalmschneid-tegernsee_michael-medium-snow.jpg
HTTP/1.0" 200 1478 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ad08.proxy.aol.com - - [16/Feb/2004:23:35:22 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-5_20021110-0985_de-gindelalmschneid-gindelalm_michael-heavy-snow.jpg
HTTP/1.0" 200 1487 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ad13.proxy.aol.com - - [16/Feb/2004:23:35:23 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-5_20021110-0987_de-gindelalmschneid-au_sunny-lake.jpg
HTTP/1.0" 200 2571 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ac08.proxy.aol.com - - [16/Feb/2004:23:35:25 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-5_20021110-0989_de-gindelalmschneid-schwaig_view-of-schliersee.jpg
HTTP/1.0" 200 2011 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ab01.proxy.aol.com - - [16/Feb/2004:23:35:27 +0100] "GET /~alexis/STABLE/images/valid-html401.png
HTTP/1.0" 200 2948 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ah02.proxy.aol.com - - [16/Feb/2004:23:35:27 +0100] "GET /~alexis/STABLE/images/vcss.png
HTTP/1.0" 200 1134 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"
        cache-mtc-ac02.proxy.aol.com - - [16/Feb/2004:23:35:27 +0100] "GET /~alexis/STABLE/hiking/tegernschlier/images/tn-5_20021110-0991_de-gindelalmschneid-schliersee_lake-view-east.jpg
HTTP/1.0" 200 2084 "http://dione.no-ip.org/~alexis/STABLE/hiking/tegernschlier/" "Mozilla/4.0
(compatible; MSIE 6.0; AOL 8.0; Windows 98)"

The pages on this host get hit only a dozen times per hour, so two
accesses with only ten seconds between them (I mean the last thing
in access_log and the first in error_log) probably are caused by the
same client.

I trust apache enough to that I have not found a bug :-) but what
is it? 

I can include the httpd.conf if necessary, but for the moment I'll
just post that I'm running:

        Apache/2.1.0-dev (Unix) DAV/2 SVN/0.36.0+ Server at dione.myth.net Port 80

(dione.myth.net is the name of the host on my home-net, and
dione.no-ip.org is the world-accessible name.)

But I have encountered the same problem since - give or take one minor
release - the time of 2.0.45.

Googling turns up no references to the above error. Has anybody any 
ideas what's going on? Many thanks!

Alexis Huxley
ahuxley@gmx.net

PS I posted the above about a week ago, and since then it has already
   happened again. Here is what was in access_log just before it,
   starting with the first entry made be the host making the accesses
   that trigger the behaviour:

	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:26 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1261_de-wank-panorama_logging-and-lift.jpg
HTTP/1.1" 200 3345 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1268_de-wank-eckenberg_cloud-lars-paola.jpg
HTTP/1.1" 200 1608 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1265_de-wank-eckenberg_steps-lars-paola-karin.jpg
HTTP/1.1" 200 2787 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:26 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-map.jpg
HTTP/1.1" 200 2714 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:26 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1264_de-wank_karin-paola-lars.jpg
HTTP/1.1" 200 2220 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:26 +0100] "GET /~alexis/STABLE/images/d_arrow_7rows.gif
HTTP/1.1" 200 242 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:26 +0100] "GET /~alexis/STABLE/images/d_arrow_2rows.gif
HTTP/1.1" 200 111 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1272_de-wank-eckenberg_view-of-hoher-fricken-bischof-krottenkopf.jpg
HTTP/1.1" 200 2470 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1270_de-wank-eckenberg_view-of-esterberg-alm.jpg
HTTP/1.1" 200 2171 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1274_de-wank-saddle_eckenberg.jpg
HTTP/1.1" 200 1756 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/hiking/wank/images/tn-5_20030525-1277_de-wank-saddle_ameisberg.jpg
HTTP/1.1" 200 2931 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/images/valid-html401.png
HTTP/1.1" 200 2948 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:27 +0100] "GET /~alexis/STABLE/images/vcss.png
HTTP/1.1" 200 1134 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:25 +0100] "GET /~alexis/STABLE/hiking/wank/
HTTP/1.0" 200 9304 "XXXX:++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++"
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"
	cache6-midd.server.ntli.net - - [20/Feb/2004:21:27:30 +0100] "GET /~alexis/STABLE/css/standard.css
HTTP/1.1" 200 5017 "http://dione.no-ip.org/~alexis/STABLE/hiking/wank/" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; Hotbar 4.3.5.0; .NET CLR 1.0.3705)"

-- end --


Mime
View raw message