httpd-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gabriel Petrovay <gabipetro...@gmail.com>
Subject Re: Apache waits too long?
Date Tue, 26 Oct 2010 23:00:35 GMT
Some more clues on this, if this can help:

In: server/mpm/winnt/child.c(1151)

        dwRet = WaitForMultipleObjects(min(threads_created - watch_thread,
                                           MAXIMUM_WAIT_OBJECTS),
                                       child_handles + watch_thread, 0, 0);

threads_created = 299
watch_thread = 250 .. 1

every iteration dwRet == 299 (see the "else" message in the log
fragments below; child.c(1171)) until watch_thread == 1.

When watch_thread == 1, WaitForMultipleObjects blocks every time and
waits in chunks of 100ms for those 5-15 seconds. I added some log
messages and the result is in the log fragment below. The question is
WHY is WaitForMultipleObjects blocking for those 100ms if
dwMilliseconds parameter == 0. MSDN do says:

"If dwMilliseconds is zero, the function does not enter a wait state
if the specified objects are not signaled; it always returns
immediately."

Does this mean that "if if the specified objects [ARE] signaled" must
it enter the wait state. At least no such statement is made in the
documentation.

So:
1. Why waiting if dwMilliseconds == 0?
2. If it is correct to wait, why waiting for 100ms, every time causing
a timeout?
3. Why does it break the loop after several seconds (my initial question)?

See below (after the following log fragment) another weird behaviour.
For both examples below, see the times between the original Apache log
messages: "Released the start mutex" and "All worker threads have
exited."

...
[Wed Oct 27 00:23:03 2010] [notice] Child 6020: Released the start mutex
...
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607]
threads_created [299] watch_thread [4]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607] else dwRet [299]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607] cleanup_thread
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607]
threads_created [299] watch_thread [3]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607] else dwRet [299]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607] cleanup_thread
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607]
threads_created [299] watch_thread [2]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607] else dwRet [299]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561607] cleanup_thread
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561707]
threads_created [299] watch_thread [1]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561707]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561707] continue
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561807]
threads_created [299] watch_thread [1]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561807]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561807] continue
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561907]
threads_created [299] watch_thread [1]
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561907]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:03 2010] [warn] -----------: [3936561907] continue
...
[Wed Oct 27 00:23:11 2010] [warn] -----------: [3936569807]
threads_created [299] watch_thread [1]
[Wed Oct 27 00:23:11 2010] [warn] -----------: [3936569807]
WaitForMultipleObjects(...)
[Wed Oct 27 00:23:11 2010] [warn] -----------: [3936569807] else dwRet [299]
[Wed Oct 27 00:23:11 2010] [warn] -----------: [3936569807] cleanup_thread(...)
[Wed Oct 27 00:23:11 2010] [notice] Child 3112: All worker threads have exited.

-------------------------------------------

Another weird behaviour (THE CORRECT ONE)

But if I try to debug the problem (attach the VS debugger) the
behaviour is the expected one! (see the log fragment below). So just
the fact that I attach a debugger the WaitForMultipleObjects (doesn't
wait anymore when reaching watch_thread==1; "just attaching" == attach
in release mode or in debug mode without pdb files => this implies NO
breaking during execution)


...
[Wed Oct 27 00:39:31 2010] [notice] Child 6020: Released the start mutex
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551428]
threads_created [299] watch_thread [250]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551428]
WaitForMultipleObjects(...)
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551429] else
...
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
cleanup_thread threads_created [299]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
threads_created [299] watch_thread [3]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
WaitForMultipleObjects(299)
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464] else
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
cleanup_thread threads_created [299]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
threads_created [299] watch_thread [2]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
WaitForMultipleObjects(299)
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464] else
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
cleanup_thread threads_created [299]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
threads_created [299] watch_thread [1]
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
WaitForMultipleObjects(299)
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464] else
[Wed Oct 27 00:39:32 2010] [warn] -----------: [3937551464]
cleanup_thread threads_created [299]
[Wed Oct 27 00:39:32 2010] [notice] Child 6020: All worker threads have exited.
...


What is the problem here?


Regards,
Gabriel


On Tue, Oct 26, 2010 at 7:46 PM, Gabriel Petrovay
<gabipetrovay@gmail.com> wrote:
> Hi,
>
> Do you know probable causes why Apache would wait so much (10-15 sec)
> on Windows? This long wait happens only when mod_fcgid starts a
> handling process. I have traced mod_fcgi and all the cleanup takes a
> little more than 1 second always.
>
> From the error log:
> ...
> [Tue Oct 26 19:29:43 2010] [notice] Parent: Received shutdown signal
> -- Shutting down the server.
> [Tue Oct 26 19:29:43 2010] [notice] Child 3200: Exit event signaled.
> Child process is ending.
> -> [Tue Oct 26 19:29:44 2010] [notice] Child 3200: Released the start mutex
> -> [Tue Oct 26 19:29:59 2010] [notice] Child 3200: All worker threads
> have exited.
> [Tue Oct 26 19:30:00 2010] [notice] Child 3200: Child process is exiting
> [Tue Oct 26 19:30:00 2010] [notice] Parent: Child process exited successfully.
> ...
>
> I start apache with:
> mod_alias.so
> mod_authz_host.so
> mod_autoindex.so
> mod_env.so
> mod_fcgid.so
> mod_log_config.so
> mod_mime.so
> mod_rewrite.so
> mod_setenvif.so
>
>
> Thanks!
>
> --
> MSc Gabriel Petrovay
> Mobile: +41(0)787978034
> www.28msec.com
>



-- 
MSc Gabriel Petrovay
Mobile: +41(0)787978034
www.28msec.com

Mime
View raw message