You are viewing a plain text version of this content. The canonical link for it is here.
Posted to bugs@httpd.apache.org by bu...@apache.org on 2014/03/04 17:28:22 UTC
[Bug 56216] New: multiple reqtimeout_con_cfg created for each
request -> wrong timeout behavior
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
Bug ID: 56216
Summary: multiple reqtimeout_con_cfg created for each request
-> wrong timeout behavior
Product: Apache httpd-2
Version: 2.4.7
Hardware: PC
OS: Linux
Status: NEW
Severity: normal
Priority: P2
Component: mod_reqtimeout
Assignee: bugs@httpd.apache.org
Reporter: frank.meier@ergon.ch
Created attachment 31365
--> https://issues.apache.org/bugzilla/attachment.cgi?id=31365&action=edit
patch: only create reqtimeout_con_cfg once per connection
while testing mod_reqtimout, I sometimes got strange timeouts i couldn't
explain. After adding some debug code to mod_reqtimeout.c I found out that:
1) reqtimeout_init() is called before each request (not only at the start of
the connection)
2) therefore for each request a new reqtimeout_con_cfg is created and set as
context to the connection config: ap_set_module_config(c->conn_config,
&reqtimeout_module, ccfg) and is added to the input filter:
ap_add_input_filter("reqtimeout", ccfg, NULL, c);
3) For subsequent Requests I got then calls to reqtimeout_filter(), with each
registered reqtimeout_con_cfg. That means during the first Request
reqtimeout_filter() was called with the correct reqtime_con_cfg, in the second
Request reqtimeout_filter() was called twice() one time with the actual
reqtimeout_con_cfg and one time with the one from the first Request. And so
forth.
4) Then one call to reqtimeout_filter() with the obsolete ccfg decided to
detect a timeout, and the request was aborted
It looks to me, it was thought, reqtimeout_init() reqistered in hook
'ap_hook_process_connection' shall only be called once. But since it is called
multiple times, it has to be secured, not to create and register a new
reqtimeout_con_cfg each time. See proposed attached patch.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #4 from Frank Meier <fr...@ergon.ch> ---
Created attachment 31371
--> https://issues.apache.org/bugzilla/attachment.cgi?id=31371&action=edit
apache error_log with debug info during 2 requests on same connection
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
Eric Covener <co...@gmail.com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Keywords| |FixedInTrunk
--- Comment #10 from Eric Covener <co...@gmail.com> ---
Thanks for the report/patch, committed to trunk with some style changes
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #8 from Frank Meier <fr...@ergon.ch> ---
Funny thing. I cannot reproduce this behavior with the worker MPM. There
reqtimeout_init() is only called once at the beginning of the first request.
So it seems the event MPM does not handle the ap_hook_process_connection() hook
the same way as the worker MPM. This could potentially break other modules
depending on this hook.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #11 from Eric Covener <co...@gmail.com> ---
Thanks for the report/patch, committed to trunk with some style changes in
1580568. Will propose for 2.4.10.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #5 from Frank Meier <fr...@ergon.ch> ---
I got you 2 backtraces in reqtimeout_init. 2 Request on the same connection
with telnet:
Breakpoint 1, reqtimeout_init (c=0x7ffff0007d00) at mod_reqtimeout.c:338
338 cfg = ap_get_module_config(c->base_server->module_config,
(gdb) bt
#0 reqtimeout_init (c=0x7ffff0007d00) at mod_reqtimeout.c:338
#1 0x00005555555ba380 in ap_run_process_connection (c=0x7ffff0007d00) at
connection.c:41
#2 0x00005555555d2845 in process_socket (my_thread_num=1, my_child_num=0,
cs=0x7ffff0007c88, sock=0x7ffff0007a80, p=<optimized out>, thd=0x555555842038)
at event.c:970
#3 worker_thread (thd=0x555555842038, dummy=<optimized out>) at event.c:1815
#4 0x00007ffff6c96f3a in start_thread () from /lib/libpthread.so.0
#5 0x00007ffff67ccc3d in clone () from /lib/libc.so.6
(gdb) cont
Continuing.
[Switching to Thread 0x7ffff5cd0700 (LWP 15328)]
Breakpoint 1, reqtimeout_init (c=0x7ffff0007d00) at mod_reqtimeout.c:338
338 cfg = ap_get_module_config(c->base_server->module_config,
(gdb) bt
#0 reqtimeout_init (c=0x7ffff0007d00) at mod_reqtimeout.c:338
#1 0x00005555555ba380 in ap_run_process_connection (c=0x7ffff0007d00) at
connection.c:41
#2 0x00005555555d2845 in process_socket (my_thread_num=0, my_child_num=0,
cs=0x7ffff0007c88, sock=0x7ffff0007a80, p=<optimized out>, thd=0x555555842008)
at event.c:970
#3 worker_thread (thd=0x555555842008, dummy=<optimized out>) at event.c:1815
#4 0x00007ffff6c96f3a in start_thread () from /lib/libpthread.so.0
#5 0x00007ffff67ccc3d in clone () from /lib/libc.so.6
(gdb) cont
Continuing.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #3 from Frank Meier <fr...@ergon.ch> ---
Created attachment 31370
--> https://issues.apache.org/bugzilla/attachment.cgi?id=31370&action=edit
mod_reqtimeout.c with more debug logs
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
Christophe JAILLET <ch...@wanadoo.fr> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
Resolution|--- |FIXED
--- Comment #12 from Christophe JAILLET <ch...@wanadoo.fr> ---
Fixed and released in 2.4.10
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
nada <ap...@valgronda.com> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |apache_bugzilla@valgronda.c
| |om
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
Frank Meier <fr...@ergon.ch> changed:
What |Removed |Added
----------------------------------------------------------------------------
Attachment #31365|0 |1
is obsolete| |
--- Comment #6 from Frank Meier <fr...@ergon.ch> ---
Created attachment 31372
--> https://issues.apache.org/bugzilla/attachment.cgi?id=31372&action=edit
only create reqtimeout_con_cfg once per connection / reset properly
added improved patch: initialize reqtimeout_con_cfg with zeros in case of
reusage.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #7 from Ruediger Pluem <rp...@apache.org> ---
I see that you are using the event MPM. Can you still reproduce this using the
worker MPM?
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
Edward Lu <Ch...@gmail.com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |NEEDINFO
--- Comment #1 from Edward Lu <Ch...@gmail.com> ---
Could you post some backtraces of the execution to verify that
reqtimeout_init() is indeed being run multiple times in a single connection?
It'd be interesting to see where it's getting called from.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
Eric Covener <co...@gmail.com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEEDINFO |NEW
--- Comment #9 from Eric Covener <co...@gmail.com> ---
This seems to be a basic difference between event and worker, worker loops over
requests in its 1 call to ap_hook_process_connection() whereas event pulls one
off and returns afterwards as the MPM drives ap_run_process_connection() over
and over.
Very few consumers in-tree of ap_hook_process_connection. Seems a bit odd.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org
[Bug 56216] multiple reqtimeout_con_cfg created for each request ->
wrong timeout behavior
Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=56216
--- Comment #2 from Frank Meier <fr...@ergon.ch> ---
I put some additional debug log into mod_reqtimeout.c (see attachment:
mod_reqtimeout.c.debug) and made two requests (with telnet) on the same TCP
connection. The resulting log (see attachment:
two_requests_on_same_connection_debug.log) shows, that the method
reqtimeout_init() is indeed called for each request (first at 10:57:51.982062,
second: 10:58:01.277638).
Further we can see, that in the first request the method reqtimeout_filter() is
called with the context:0x58037d30 which was created in the first
reqtimeout_init() call; and in the second request it is again called with the
context from the first request and also with the new one 0x58037f50 created in
the second reqtimeout_init() call.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org