From dev-return-25685-apmail-apr-dev-archive=apr.apache.org@apr.apache.org Mon Nov 25 01:39:31 2013 Return-Path: X-Original-To: apmail-apr-dev-archive@www.apache.org Delivered-To: apmail-apr-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 1199210067 for ; Mon, 25 Nov 2013 01:39:31 +0000 (UTC) Received: (qmail 2930 invoked by uid 500); 25 Nov 2013 01:39:30 -0000 Delivered-To: apmail-apr-dev-archive@apr.apache.org Received: (qmail 2281 invoked by uid 500); 25 Nov 2013 01:39:28 -0000 Mailing-List: contact dev-help@apr.apache.org; run by ezmlm Precedence: bulk List-Post: List-Help: List-Unsubscribe: List-Id: Delivered-To: mailing list dev@apr.apache.org Received: (qmail 2272 invoked by uid 99); 25 Nov 2013 01:39:28 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 25 Nov 2013 01:39:28 +0000 X-ASF-Spam-Status: No, hits=1.5 required=5.0 tests=HTML_MESSAGE,NORMAL_HTTP_TO_IP,RCVD_IN_DNSWL_LOW,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of trawick@gmail.com designates 209.85.217.172 as permitted sender) Received: from [209.85.217.172] (HELO mail-lb0-f172.google.com) (209.85.217.172) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 25 Nov 2013 01:39:24 +0000 Received: by mail-lb0-f172.google.com with SMTP id z5so2651768lbh.17 for ; Sun, 24 Nov 2013 17:39:03 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=rK4/4wjdvC1wNbVsuiRTiEpW73m7n4psnbcqFQmXGoc=; b=p+yhH4NT4WQZzve1RUHBd7W6h1mHlDjGCXWVfB5bq9pjmZC/o8D5Y1qsah00clIRfD MWPTHSrzIbC1xBllGdgduvbWArezw761XpWpI8FC/k+DGh08S8LsmNVRNiPSNYzQtXUC nxxfqQHF9GQ4MrtiolDvCj/vDBQKbXSGNRfqB58/eH2OQQPujRBFNAsBc6vYw6NW+qcK aUmOZANC13Pa/0daM1vAs9C1DMRZMNYJXuBJwpl3rpxrVL7sBN/qXkYCbvSAzIkarCw+ A6URF/AS9jnvLRhDkoooVnmHt8wXIahQbxXg8Q+/q3YYksjiBQkEVTGE1IbmQB0Io8rg VhQA== MIME-Version: 1.0 X-Received: by 10.112.143.3 with SMTP id sa3mr19441151lbb.12.1385343542988; Sun, 24 Nov 2013 17:39:02 -0800 (PST) Received: by 10.115.4.132 with HTTP; Sun, 24 Nov 2013 17:39:02 -0800 (PST) In-Reply-To: <5291FF18.8090801@gmx.de> References: <528E8DB1.9040803@gmx.de> <5291FF18.8090801@gmx.de> Date: Sun, 24 Nov 2013 20:39:02 -0500 Message-ID: Subject: Re: Issue with apr-1.5.0 on FreeBSD 10beta3 From: Jeff Trawick To: Apache HTTP Server Development List Cc: "dev@apr.apache.org" Content-Type: multipart/alternative; boundary=089e011827aec5925b04ebf66d0a X-Virus-Checked: Checked by ClamAV on apache.org --089e011827aec5925b04ebf66d0a Content-Type: text/plain; charset=ISO-8859-1 Let's move this to dev@httpd and omit dev@apr (after this e-mail)... On Sun, Nov 24, 2013 at 8:28 AM, olli hauer wrote: > On 2013-11-22 00:08, Jeff Trawick wrote: > > On Thu, Nov 21, 2013 at 5:48 PM, olli hauer wrote: > > > >> Hi, > >> > >> sorry for late response to apr-1.5.0 ... > >> > >> I've done some tests with apr-1.5.0 on FreeBSD 10 (amd64) > >> and it seems there is an issue that breaks apache24. > >> > >> With apr-1.5.0 apache22 works but apache24 is broken. > >> apache starts fine, nothing special in the logs or during > >> start with -X but no response is coming back. > >> > >> apr/apr-util test: > >> ======================================== > >> apr-1.5.0: all tests passed [1] > >> apr-util-1.5.3: all tests passed > >> > >> > >> working configurations (FreeBSD beta3 [1] > >> ========================================= > >> apache22-2.2.26 apr-1.4.8 apr-util-1.5.3 > >> apache22-2.2.26 apr-1.5.0 apr-util-1.5.3 > >> apache24-2.4.6 apr-1.4.8 apr-util-1.5.2 > >> apache24-2.4.7 apr-1.4.8 apr-util-1.5.2 > >> apache24-2.4.6 apr-1.4.8 apr-util-1.5.3 > >> apache24-2.4.7 apr-1.4.8 apr-util-1.5.3 > >> > >> broken combinations: > >> ========================================= > >> apache24-2.4.6 apr-1.5.0 apr-util-1.5.3 > >> apache24-2.4.7 apr-1.5.0 apr-util-1.5.3 > >> > >> All tests where done with MPM worker. > >> > >> > >> FreeBSD 8.4 (amd64) seems OK in all combinations > >> FreeBSD 9.2 (amd64) seems OK in all combinations > >> > >> [1] FreeBSD 10 beta3 with iconv UTF7 patch r258316 > >> (head/lib/libiconv_modules/UTF7/citrus_utf7.c) > >> > >> Any hints where to start? > >> > > > > Set LogLevel trace8 and compare good vs. bad. > > Start with -X then attach with dtruss and compare good vs. bad. > > Get open fds displayed by lsof and compare good vs. bad. > > Is connection to client held open? Get backtraces. > > > > I just compared 1.4.8 vs. 1.5.0 and didn't see anything that looked > > remotely likely. > > > > Comparing trace8 outputs showed the request is processed > but the following code snippet in server/core_filters.c > never get TRUE except the client cancels the request. > > To get some better log entries I've used server/core_filters.c > r1510295 from trunk. > > > @@server/core_filters.c (line 510) > if (APR_BUCKET_IS_FLUSH(bucket) > || non_file_bytes_in_brigade >= THRESHOLD_MAX_BUFFER > || morphing_bucket_in_brigade > || eor_buckets_in_brigade > MAX_REQUESTS_IN_PIPELINE) { > ... > } > > [http:trace3] http_filters.c(974):[client x.x.x.x:x] Response sent with > status 200, headers: > [http:trace5] http_filters.c(983):[client x.x.x.x:x] Date: Sun, 24 Nov > 2013 10:28:37 GMT > [http:trace5] http_filters.c(986):[client x.x.x.x:x] Server: > Apache/2.4.7 (FreeBSD) > [http:trace4] http_filters.c(804):[client x.x.x.x:x] Last-Modified: Sat, > 23 Nov 2013 16:51:58 GMT > [http:trace4] http_filters.c(804):[client x.x.x.x:x] ETag: > \\"be-4ebdaf2ef2780\\" > [http:trace4] http_filters.c(804):[client x.x.x.x:x] Accept-Ranges: bytes > [http:trace4] http_filters.c(804):[client x.x.x.x:x] Content-Length: 190 > [http:trace4] http_filters.c(804):[client x.x.x.x:x] Keep-Alive: > timeout=5, max=100 > [http:trace4] http_filters.c(804):[client x.x.x.x:x] Connection: > Keep-Alive > [http:trace4] http_filters.c(804):[client x.x.x.x:x] Content-Type: > text/html > [core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: > bytes: 284, non-file bytes: 284, eor buckets: 0, morphing buckets: 0 > [core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: > bytes: 474, non-file bytes: 284, eor buckets: 0, morphing buckets: 0 > [core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: > bytes: 474, non-file bytes: 284, eor buckets: 1, morphing buckets: 0 > > > This following lines are only seen if > apr-1-5.0 was build without IPv6 support > or apache24 was build with v4-mapping enabled > or "Listen $IP:$port" is given in httpd.conf > > [core:trace6] core_filters.c(526):[client x.x.x.x:x] will flush because of > FLUSH bucket > [core:trace8] core_filters.c(528):[client x.x.x.x:x] seen in brigade so > far: bytes: 474, non-file bytes: 284, eor buckets: 1, morphing buckets: 0 > [core:trace8] core_filters.c(555):[client x.x.x.x:x] flushing now > [core:trace8] core_filters.c(568):[client x.x.x.x:x] total bytes written: > 474 > [core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: > bytes: 0, non-file bytes: 0, eor buckets: 0, morphing buckets: 0 > > However a flush is triggered if the client cancels the request, but no > data is sent over the wire ... > > > I've searched if other also have seen a similar issue and found > instead the following interesting article from Nov. 2002 ;) > http://people.apache.org/~trawick/v4mapped.html > > I haven't analyzed the trace messages you showed above. Here's what I did on FreeBSD 9: Apply this patch to fix the version check for disabling v4mapped addresses: Index: configure.in =================================================================== --- configure.in (revision 1545127) +++ configure.in (working copy) @@ -774,7 +774,10 @@ ], [ case $host in - *freebsd5*|*netbsd*|*openbsd*) + *freebsd[1234].*) + v4mapped=yes + ;; + *freebsd*|*netbsd*|*openbsd*) v4mapped=no ;; *) That gives me $ bin/apachectl -V AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message Server version: Apache/2.4.8-dev (Unix) Server built: Nov 24 2013 20:21:30 Server's Module Magic Number: 20120211:27 Server loaded: APR 1.5.1-dev, APR-UTIL 1.5.4-dev Compiled using: APR 1.5.1-dev, APR-UTIL 1.5.4-dev Architecture: 64-bit Server MPM: worker threaded: yes (fixed thread count) forked: yes (variable process count) Server compiled with.... -D APR_HAS_SENDFILE -D APR_HAS_MMAP -D APR_HAVE_IPV6 (IPv4-mapped addresses disabled) The last line shown indicates that mapped addresses are disabled in this build. The only Listen I have is "Listen 8080". procstat says I have separate sockets, as expected: 60734 httpd 3 s - rw---n--- 9 0 TCP ::.8080 ::.0 60734 httpd 4 s - rw---n--- 9 0 TCP 0.0.0.0:8080 0.0.0.0:0 >From netstat: tcp4 0 0 *.8080 *.* LISTEN tcp6 0 0 *.8080 *.* LISTEN (You had shown sockstat before; this is the same stuff.) --/-- Are you able to check for the issue on FreeBSD 9? When it hangs, are you connecting to the IPv4 listener or the IPv6 listener? Does it matter whether you use loopback or the address of a network interface? You're using a regular web browser in the failing case, right? Have you tried something as simple as netcat for the failing address/port? Example: $ echo "GET /" | nc 127.0.0.1 8080

It works!

-- Born in Roswell... married an alien... http://emptyhammock.com/ --089e011827aec5925b04ebf66d0a Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable
Let's move this to dev@httpd and omit dev@apr (after t= his e-mail)...


On Sun, Nov 24, 2013 at 8:28 AM, olli hauer <ohauer@gmx.de> wr= ote:
On 2013-11-22 00:08, Jeff Trawick wrote:=
> On Thu, Nov 21, 2013 at 5:48 PM, olli hau= er <ohauer@gmx.de> wrote:
>
>> Hi,
>>
>> sorry for late response to apr-1.5.0 ...
>>
>> I've done some tests with apr-1.5.0 on FreeBSD 10 (amd64)
>> and it seems there is an issue that breaks apache24.
>>
>> With apr-1.5.0 apache22 works but apache24 is broken.
>> apache starts fine, nothing special in the logs or during
>> start with -X but no response is coming back.
>>
>> apr/apr-util test:
>> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
>> apr-1.5.0: =A0 =A0 =A0all tests passed [1]
>> apr-util-1.5.3: all tests passed
>>
>>
>> working configurations (FreeBSD beta3 [1]
>> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
>> apache22-2.2.26 apr-1.4.8 apr-util-1.5.3
>> apache22-2.2.26 apr-1.5.0 apr-util-1.5.3
>> apache24-2.4.6 =A0apr-1.4.8 apr-util-1.5.2
>> apache24-2.4.7 =A0apr-1.4.8 apr-util-1.5.2
>> apache24-2.4.6 =A0apr-1.4.8 apr-util-1.5.3
>> apache24-2.4.7 =A0apr-1.4.8 apr-util-1.5.3
>>
>> broken combinations:
>> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
>> apache24-2.4.6 =A0apr-1.5.0 apr-util-1.5.3
>> apache24-2.4.7 =A0apr-1.5.0 apr-util-1.5.3
>>
>> All tests where done with MPM worker.
>>
>>
>> FreeBSD 8.4 (amd64) seems OK in all combinations
>> FreeBSD 9.2 (amd64) seems OK in all combinations
>>
>> [1] FreeBSD 10 beta3 with iconv UTF7 patch r258316
>> (head/lib/libiconv_modules/UTF7/citrus_utf7.c)
>>
>> Any hints where to start?
>>
>
> Set LogLevel trace8 and compare good vs. bad.
> Start with -X then attach with dtruss and compare good vs. bad.
> Get open fds displayed by lsof and compare good vs. bad.
> Is connection to client held open? =A0Get backtraces.
>
> I just compared 1.4.8 vs. 1.5.0 and didn't see anything that looke= d
> remotely likely.
>

Comparing trace8 outputs showed the request is processed
but the following code snippet in server/core_filters.c
never get TRUE except the client cancels the request.

To get some better log entries I've used server/core_filters.c
r1510295 from trunk.


@@server/core_filters.c (line 510)
if (APR_BUCKET_IS_FLUSH(bucket)
=A0 =A0 || non_file_bytes_in_brigade >=3D THRESHOLD_MAX_BUFFER
=A0 =A0 || morphing_bucket_in_brigade
=A0 =A0 || eor_buckets_in_brigade > MAX_REQUESTS_IN_PIPELINE) {
...
}

[http:trace3] http_filters.c(974):[client x.x.x.x:x] Response sent with sta= tus 200, headers:
[http:trace5] http_filters.c(983):[client x.x.x.x:x] =A0 Date: Sun, 24 Nov = 2013 10:28:37 GMT
[http:trace5] http_filters.c(986):[client x.x.x.x:x] =A0 Server: Apache/2.4= .7 (FreeBSD)
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 Last-Modified: Sat= , 23 Nov 2013 16:51:58 GMT
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 ETag: \\"be-4= ebdaf2ef2780\\"
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 Accept-Ranges: byt= es
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 Content-Length: 19= 0
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 Keep-Alive: timeou= t=3D5, max=3D100
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 Connection: Keep-A= live
[http:trace4] http_filters.c(804):[client x.x.x.x:x] =A0 Content-Type: text= /html
[core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: byte= s: 284, non-file bytes: 284, eor buckets: 0, morphing buckets: 0
[core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: byte= s: 474, non-file bytes: 284, eor buckets: 0, morphing buckets: 0
[core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: byte= s: 474, non-file bytes: 284, eor buckets: 1, morphing buckets: 0


This following lines are only seen if
=A0 apr-1-5.0 was build without IPv6 support
=A0 or apache24 was build with v4-mapping enabled
=A0 or "Listen $IP:$port" is given in httpd.conf

[core:trace6] core_filters.c(526):[client x.x.x.x:x] will flush because of = FLUSH bucket
[core:trace8] core_filters.c(528):[client x.x.x.x:x] seen in brigade so far= : bytes: 474, non-file bytes: 284, eor buckets: 1, morphing buckets: 0
[core:trace8] core_filters.c(555):[client x.x.x.x:x] flushing now
[core:trace8] core_filters.c(568):[client x.x.x.x:x] total bytes written: 4= 74
[core:trace8] core_filters.c(576):[client x.x.x.x:x] brigade contains: byte= s: 0, non-file bytes: 0, eor buckets: 0, morphing buckets: 0

However a flush is triggered if the client cancels the request, but no data= is sent over the wire ...


I've searched if other also have seen a similar issue and found
instead the following interesting article from Nov. 2002 ;)
http://people.apache.org/~trawick/v4mapped.html


I haven't analyzed the trace messages you showed= above. =A0Here's what I did on FreeBSD 9:

Apply this patch to fix the versio= n check for disabling v4mapped addresses:

Index: configure.in
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D
--- configure.in= (revision 1545127)
+++ configur= e.in (working copy)
@@ -774,7 +774,10 @@
=A0],
=A0[
=A0 =A0 =A0case $host in
- =A0 =A0*fre= ebsd5*|*netbsd*|*openbsd*)
+ =A0 =A0*freebsd[1234].*)
+ =A0 =A0 =A0 =A0v4mapped=3Dyes
= + =A0 =A0 =A0 =A0;;
+ =A0 =A0*freebsd*|*net= bsd*|*openbsd*)
=A0 =A0 =A0 =A0 =A0v4mapped=3Dno
=A0 =A0 = =A0 =A0 =A0;;
=A0 =A0 =A0*)

<= /div>
That gives me

$ bin/apachectl -V
AH00558: httpd: Could not reliably determine the server's fully= qualified domain name, using 127.0.0.1. Set the 'ServerName' direc= tive globally to suppress this message
Server version: Apache/2.4.8-dev (Unix)
Server built: =A0 No= v 24 2013 20:21:30
Server's Module Magic Number: 20120211:27<= /div>
Server loaded: =A0APR 1.5.1-dev, APR-UTIL 1.5.4-dev
Com= piled using: APR 1.5.1-dev, APR-UTIL 1.5.4-dev
Architecture: =A0 64-bit
Server MPM: =A0 =A0 worker
=A0 threaded: =A0 =A0 yes (fixed thread count)
=A0 =A0 forked: = =A0 =A0 yes (variable process count)
Server compiled with....
=A0-D APR_HAS_SENDFILE
=A0-D APR_HAS_MMAP
=A0-D APR_HAVE_IPV6 (IPv4-mapped addresse= s disabled)
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0=A0
The last line shown indicates that mapped addresses are disabled in this= build.

The only Listen I have is "Listen 8080". =A0p= rocstat says I have separate sockets, as expected:

60734 httpd =A0 =A0 =A0 =A0 =A0 =A0 =A0 3 s - rw---n--- =A0 9 =A0 =A0= =A0 0 TCP ::.8080 ::.0
60734 httpd =A0 =A0 =A0 =A0 =A0 =A0 =A0 4 s - rw---n--- =A0 9 =A0 =A0 = =A0 0 TCP 0.0.0.0:8080 0.0.0.0:0

From netstat:

tcp4 =A0 =A0 =A0 0 =A0 =A0 =A00 *.8080 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= *.* =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0LISTEN
tcp6 =A0 =A0 = =A0 0 =A0 =A0 =A00 *.8080 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 *.* =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0LISTEN

(You had s= hown sockstat before; this is the same stuff.)

--/--

Are you able to check fo= r the issue on FreeBSD 9?

When it hangs, are you c= onnecting to the IPv4 listener or the IPv6 listener? =A0Does it matter whet= her you use loopback or the address of a network interface?

You're using a regular web browser in the failing c= ase, right? =A0Have you tried something as simple as netcat for the failing= address/port? =A0Example:

$ echo "GET /= " | nc 127.0.0.1 8080
<html><body><h1>It works!</h1></body><= ;/html>

--
Born in Roswell... married an a= lien...
http://em= ptyhammock.com/
--089e011827aec5925b04ebf66d0a--