Re: Issue with apr-1.5.0 on FreeBSD 10beta3
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
===
Re: svn commit: r1544876 - in /httpd/httpd/trunk/server/mpm: event/event.c eventopt/eventopt.c
On Sat, Nov 23, 2013 at 3:29 PM, wrote:
> Author: jim
> Date: Sat Nov 23 20:29:55 2013
> New Revision: 1544876
>
> URL: http://svn.apache.org/r1544876
> Log:
> Just critically warn people... but keep pushing through.
>
> Modified:
> httpd/httpd/trunk/server/mpm/event/event.c
> httpd/httpd/trunk/server/mpm/eventopt/eventopt.c
>
> Modified: httpd/httpd/trunk/server/mpm/event/event.c
> URL:
> http://svn.apache.org/viewvc/httpd/httpd/trunk/server/mpm/event/event.c?rev=1544876&r1=1544875&r2=1544876&view=diff
>
> ==
> --- httpd/httpd/trunk/server/mpm/event/event.c (original)
> +++ httpd/httpd/trunk/server/mpm/event/event.c Sat Nov 23 20:29:55 2013
> @@ -3057,8 +3057,8 @@ static int event_pre_config(apr_pool_t *
> i = apr_atomic_dec32(&foo);
> if (i >= 0) {
> ap_log_error(APLOG_MARK, APLOG_CRIT, 0, NULL, APLOGNO(02405)
> - "atomics not working as expected");
> -return HTTP_INTERNAL_SERVER_ERROR;
> + "atomics not working as expected - Event MPM may
> not work");
> +/* return HTTP_INTERNAL_SERVER_ERROR; */
>
I guess I like the old version better, however painful and untimely it
might have been to see it in action :)
> }
> rv = apr_pollset_create(&event_pollset, 1, plog,
> APR_POLLSET_THREADSAFE |
> APR_POLLSET_NOCOPY);
>
> Modified: httpd/httpd/trunk/server/mpm/eventopt/eventopt.c
> URL:
> http://svn.apache.org/viewvc/httpd/httpd/trunk/server/mpm/eventopt/eventopt.c?rev=1544876&r1=1544875&r2=1544876&view=diff
>
> ==
> --- httpd/httpd/trunk/server/mpm/eventopt/eventopt.c (original)
> +++ httpd/httpd/trunk/server/mpm/eventopt/eventopt.c Sat Nov 23 20:29:55
> 2013
> @@ -3033,8 +3033,8 @@ static int event_pre_config(apr_pool_t *
> i = apr_atomic_dec32(&foo);
> if (i >= 0) {
> ap_log_error(APLOG_MARK, APLOG_CRIT, 0, NULL, APLOGNO(02406)
> - "atomics not working as expected");
> -return HTTP_INTERNAL_SERVER_ERROR;
> + "atomics not working as expected - EventOpt MPM
> may not work");
> +/* return HTTP_INTERNAL_SERVER_ERROR; */
> }
> rv = apr_pollset_create(&event_pollset, 1, plog,
> APR_POLLSET_WAKEABLE|APR_POLLSET_NOCOPY);
>
>
>
--
Born in Roswell... married an alien...
http://emptyhammock.com/
Re: svn commit: r1410459 - in /httpd/httpd/trunk: docs/log-message-tags/next-number server/mpm/event/event.c server/mpm/eventopt/eventopt.c
On Sat, Nov 23, 2013 at 5:39 PM, Yann Ylavic wrote:
> Couldn't ap_queue_info_try_get_idler() and the event_pre_config() check
> use :
>
>
> prev_idlers = apr_atomic_add32((apr_uint32_t *)&(queue_info->idlers),
> -1);
>
> like ap_queue_info_wait_for_idler() does ?
>
I think that's correct...
What the code really wants is new_idlers, so edit that slightly to
new_idlers = apr_atomic_add32((apr_uint32_t *)&(queue_info->idlers), -1) -
1;
if (new_idlers <= 0) {
...
return APR_EAGAIN;
}
>
> Or maybe queue_info->idlers be declared uint32_t and negatives computed
> relative to 2^31 ?
>
The comments say that the uint/int discrepancy is the problem, but the
actual problem is the expectation that apr_atomic_dec32() returns the new
value, when all that is promised is a zero/non-zero flag. The new value is
what is returned in almost all implementations, but that is not actually
promised by the API, and promising new value (perhaps in apr-future) is
rather ugly with a declared return type of int.
> Regards,
> Yann.
>
>
>
>
> On Fri, Nov 22, 2013 at 9:40 PM, Jeff Trawick wrote:
>
>> On Fri, Nov 22, 2013 at 3:24 PM, Jeff Trawick wrote:
>>
>>> On Fri, Nov 22, 2013 at 2:52 PM, Jim Jagielski wrote:
>>>
Note, the only think changed in event now (via
https://svn.apache.org/viewvc?view=revision&revision=1542560)
is that event *checks* that atomics work as required for
event... if the check fails, it means that event has
been "broken" on that system, assuming it ever hit
blocked idlers, for a *long* time...
>>>
>>> Got it... fdqueue.c is asking for trouble...
>>>
>>> I'm using atomic/unix/ia32.c with icc too.
>>>
>>> Need to compare generated code... I hate stuff like "int foo() {
>>> unsigned char x; ... return x; }"
>>>
>>>
>> APR is documented as returning "zero if the value becomes zero on
>> decrement, otherwise non-zero".
>>
>> With gcc we use get __sync_sub_and_fetch(), which returns the new value
>> after the decrement.
>>
>> With icc we use the assembler implementation in APR. I think that's
>> returning 1 instead of -1.
>>
>> Here is where fdqueue needs to be able to see a negative return code:
>>
>> apr_status_t ap_queue_info_try_get_idler(fd_queue_info_t * queue_info)
>> {
>> int prev_idlers;
>> prev_idlers = apr_atomic_dec32((apr_uint32_t *)&(queue_info->idlers));
>> if (prev_idlers <= 0) {
>> apr_atomic_inc32((apr_uint32_t *)&(queue_info->idlers));/*
>> back out dec */
>> return APR_EAGAIN;
>> }
>> return APR_SUCCESS;
>> }
>>
>> ("prev" in the ia32.c version of apr_atomic_dec32() and "prev_idlers"
>> here is deceiving.)
>>
>>
>>>
You should be seeing it in trunk as well...
On Nov 22, 2013, at 2:43 PM, Jeff Trawick wrote:
> On Fri, Nov 22, 2013 at 2:39 PM, Jim Jagielski
wrote:
>
> On Nov 22, 2013, at 2:22 PM, Jeff Trawick wrote:
>
> > On Sat, Nov 17, 2012 at 6:00 AM, Ruediger Pluem
wrote:
> >
> >
> > j...@apache.org wrote:
> > > +i = apr_atomic_dec32(&foo);
> > > +if (i >= 0) {
> >
> > Why can we expect i < 0? apr_atomic_dec32 returns 0 if the dec
causes foo to become zero and it returns non zero
> > otherwise. Shouldn't this behavior the same across all platforms?
And if not should that be fixed in APR?
> >
> > icc (Intel) builds of httpd 2.4.7 event MPM (with apr-1.5.0) bomb
here.
> >
> > --enable-nonportable-atomics is specified for apr, though I haven't
checked what that does with icc.
> >
>
> As noted back with the orig update, this test is due to the
> fdqueue code in the new event:
>
> apr_status_t ap_queue_info_set_idle(fd_queue_info_t * queue_info,
> apr_pool_t * pool_to_recycle)
> {
> apr_status_t rv;
> int prev_idlers;
>
> ap_push_pool(queue_info, pool_to_recycle);
>
> /* Atomically increment the count of idle workers */
> /*
> * TODO: The atomics expect unsigned whereas we're using signed.
> * Need to double check that they work as expected or else
> * rework how we determine blocked.
> * UPDATE: Correct operation is performed during open_logs()
> */
> prev_idlers = apr_atomic_inc32((apr_uint32_t
*)&(queue_info->idlers));
>
> /* If other threads are waiting on a worker, wake one up */
> if (prev_idlers < 0) {
>
>
> See the comments ("The atomics expect unsigned whereas...") for
> the reason, etc.
>
> When you say "icc (Intel) builds of httpd 2.4.7 event MPM (with
apr-1.5.0) bomb here."
> do you mean that you get the 'atomics not working as expected' error
> (and the internal server error) or that it core dumps?
>
>
> "atomics not working as expected"
>
Re: svn commit: r1410459 - in /httpd/httpd/trunk: docs/log-message-tags/next-number server/mpm/event/event.c server/mpm/eventopt/eventopt.c
On Sun, Nov 24, 2013 at 7:33 AM, Eric Covener wrote: > On Sun, Nov 24, 2013 at 5:24 AM, Rainer Jung > wrote: > > On 24.11.2013 01:03, Eric Covener wrote: > I'm curious what other scenarios will fail though. I can try Sun > Studio on > Solaris 10 x86_64 (32-bit and 64-bit builds) "soon". But Sun Studio > on > SPARC presumably uses different explicit code in APR and I don't have > access > to that. > >>> > >>> I will try to get that one up and running on 2.4.7. > >> > >> No startup error with 2.4.7 + event on sparc32 or sparc64 with sun > >> studio 12 (cc 5.9) > > > > For the sake of completeness: was apr build with the nonportable atomics > > switch enabled? Don't know whether that really matters, but want to make > > sure we understand the test case. > > Defaults before, retested with no difference under > --enable-nonportable-atomics > Solaris 10 on Intel/AMD, Sun Studio, --enable-nonportable-atomics, 32-bit and 64-bit, 2.4.x HEAD, apr 1.5.x HEAD, apr-util 1.5.x HEAD no problem; uses Solaris-specific atomic implementation, which uses the return-new-value version of decrement The portable, "mutex" version of atomics clearly returns the new value too, though I didn't test with it. -- Born in Roswell... married an alien... http://emptyhammock.com/
Re: svn commit: r1410459 - in /httpd/httpd/trunk: docs/log-message-tags/next-number server/mpm/event/event.c server/mpm/eventopt/eventopt.c
On Nov 23, 2013, at 5:39 PM, Yann Ylavic wrote: > > Or maybe queue_info->idlers be declared uint32_t and negatives computed > relative to 2^31 ? > What I was thinking was simply doing an offset... There is no way we would ever use a full 32bits, signed or not, so making the "zero point" ~ 2^31 would allow us to keep the logic, without worrying about the behavior of atomics.
Re: svn commit: r1410459 - in /httpd/httpd/trunk: docs/log-message-tags/next-number server/mpm/event/event.c server/mpm/eventopt/eventopt.c
On Sun, Nov 24, 2013 at 5:24 AM, Rainer Jung wrote: > On 24.11.2013 01:03, Eric Covener wrote: I'm curious what other scenarios will fail though. I can try Sun Studio on Solaris 10 x86_64 (32-bit and 64-bit builds) "soon". But Sun Studio on SPARC presumably uses different explicit code in APR and I don't have access to that. >>> >>> I will try to get that one up and running on 2.4.7. >> >> No startup error with 2.4.7 + event on sparc32 or sparc64 with sun >> studio 12 (cc 5.9) > > For the sake of completeness: was apr build with the nonportable atomics > switch enabled? Don't know whether that really matters, but want to make > sure we understand the test case. Defaults before, retested with no difference under --enable-nonportable-atomics
Re: svn commit: r1410459 - in /httpd/httpd/trunk: docs/log-message-tags/next-number server/mpm/event/event.c server/mpm/eventopt/eventopt.c
On 24.11.2013 01:03, Eric Covener wrote: >>> I'm curious what other scenarios will fail though. I can try Sun Studio on >>> Solaris 10 x86_64 (32-bit and 64-bit builds) "soon". But Sun Studio on >>> SPARC presumably uses different explicit code in APR and I don't have access >>> to that. >> >> I will try to get that one up and running on 2.4.7. > > No startup error with 2.4.7 + event on sparc32 or sparc64 with sun > studio 12 (cc 5.9) For the sake of completeness: was apr build with the nonportable atomics switch enabled? Don't know whether that really matters, but want to make sure we understand the test case. Regards, Rainer
