You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@httpd.apache.org by Thomas Eckert <th...@gmail.com> on 2013/05/02 12:00:48 UTC
mod_proxy seg faulting ?
Lately, I've been seeing httpd/mod_proxy seg faulting in reverse proxy
setups, frequency increasing.
#0 apr_palloc (pool=0x8b52518, in_size=16) at memory/unix/apr_pools.c:684
#1 0xf756fc10 in apr_pool_cleanup_register (p=0x8b52518, data=0x8b52528,
plain_cleanup_fn=0xf756edb0 <thread_cond_cleanup>,
child_cleanup_fn=0x8069e20 <ap...@plt>) at
memory/unix/apr_pools.c:2218
#2 0xf756ef9c in apr_thread_cond_create (cond=0x8b524e0, pool=0x8b52390)
at locks/unix/thread_cond.c:55
#3 0xf76fac64 in apr_reslist_create (reslist=0x8a6c488, min=0, smax=50,
hmax=50, ttl=0, con=0xf72cb8d0 <connection_constructor>, de=0xf72cb890
<connection_destructor>,
params=0x89a8268, pool=0x8b52390) at misc/apr_reslist.c:299
#4 0xf72cc0d8 in ap_proxy_initialize_worker (worker=0x89a8268,
s=0x89b3a50, p=0x890b0a8) at proxy_util.c:1751
#5 0xf72c7d8f in proxy_handler (r=0x8b3e1f0) at mod_proxy.c:1011
#6 0x0808ba41 in ap_run_handler (r=0x8b3e1f0) at config.c:168
#7 0x0808f8e6 in ap_invoke_handler (r=0x8b3e1f0) at config.c:432
#8 0x080a200a in ap_process_async_request (r=0x8b3e1f0) at
http_request.c:317
#9 0x080a213d in ap_process_request (r=0x8b3e1f0) at http_request.c:363
#10 0x0809ea60 in ap_process_http_sync_connection (c=<optimized out>) at
http_core.c:190
#11 ap_process_http_connection (c=0x8b3a390) at http_core.c:231
#12 0x08095e51 in ap_run_process_connection (c=0x8b3a390) at connection.c:41
#13 0x080a9470 in process_socket (bucket_alloc=<optimized out>,
my_thread_num=<optimized out>, my_child_num=<optimized out>,
sock=<optimized out>, p=<optimized out>,
thd=<optimized out>) at worker.c:620
#14 worker_thread (thd=0x8a6ddf8, dummy=0x8ac73f8) at worker.c:979
#15 0xf757cf96 in dummy_worker (opaque=0x8a6ddf8) at
threadproc/unix/thread.c:142
#16 0xf7503809 in start_thread () from /lib/libpthread.so.0
#17 0xf746430e in clone () from /lib/libc.so.6
Backtrace stopped: Not enough registers or memory available to unwind
further
(gdb) frame 0
#0 apr_palloc (pool=0x8b52518, in_size=16) at memory/unix/apr_pools.c:684
684 in memory/unix/apr_pools.c
(gdb) info locals
active = 0x0
node = <optimized out>
mem = <optimized out>
size = 16
free_index = <optimized out>
This is awkward. Shall I assume httpd ran out of memory ? That's about the
only plausible reason I could see why the apr would run into active=0x0.
#0 0xf74aa2ed in pthread_mutex_lock () from /lib/libpthread.so.0
#1 0xf75140c0 in apr_thread_mutex_lock (mutex=0x0) at
locks/unix/thread_mutex.c:92
#2 0xf769f702 in apr_reslist_maintain (reslist=0x9dc2da8) at
misc/apr_reslist.c:184
#3 0xf769fc79 in apr_reslist_create (reslist=0x9dbe448, min=0, smax=50,
hmax=50, ttl=0, con=0xf72708d0 <connection_constructor>, de=0xf7270890
<connection_destructor>,
params=0x9cfa268, pool=0x9dc2cb0) at misc/apr_reslist.c:305
#4 0xf72710d8 in ap_proxy_initialize_worker (worker=0x9cfa268,
s=0x9d05a50, p=0x9c5d0a8) at proxy_util.c:1751
#5 0xf726cd8f in proxy_handler (r=0xdc9004c0) at mod_proxy.c:1011
#6 0x0808ba41 in ap_run_handler (r=0xdc9004c0) at config.c:168
#7 0x0808f8e6 in ap_invoke_handler (r=0xdc9004c0) at config.c:432
#8 0x080a200a in ap_process_async_request (r=0xdc9004c0) at
http_request.c:317
#9 0x080a213d in ap_process_request (r=0xdc9004c0) at http_request.c:363
#10 0x0809ea60 in ap_process_http_sync_connection (c=<optimized out>) at
http_core.c:190
#11 ap_process_http_connection (c=0x9e5f940) at http_core.c:231
#12 0x08095e51 in ap_run_process_connection (c=0x9e5f940) at connection.c:41
#13 0x080a9470 in process_socket (bucket_alloc=<optimized out>,
my_thread_num=<optimized out>, my_child_num=<optimized out>,
sock=<optimized out>, p=<optimized out>,
thd=<optimized out>) at worker.c:620
#14 worker_thread (thd=0x9dbfd98, dummy=0x9e19318) at worker.c:979
#15 0xf7521f96 in dummy_worker (opaque=0x9dbfd98) at
threadproc/unix/thread.c:142
#16 0xf74a8809 in start_thread () from /lib/libpthread.so.0
#17 0xf740930e in clone () from /lib/libc.so.6
This is even stranger: it's trying to lock on a null pointer.
I'm just starting to dig into this myself. Has anyone seen stuff like this
(recently) ? I checked the bug reports but didn't see anything obvious.
Re: mod_proxy seg faulting ?
Posted by Jim Jagielski <ji...@jaguNET.com>.
I've cleaned it up and bit and put the mutex where it really
belongs, making the function itself thread-safe. I also
leveraged a mutex field we hadn't used up to now, saving
any API changes...
Re: mod_proxy seg faulting ?
Posted by Jim Jagielski <ji...@jaguNET.com>.
+1.
PS: The ap_proxy_define_balancer() stuff is there for future enhancements
(creating balancers on the fly, instead of just workers).
On May 7, 2013, at 4:07 AM, Thomas Eckert <th...@gmail.com> wrote:
> > However, looking at your patch, having to lock the mutex for
> > ap_proxy_get_worker() looks wrong. I think it should be passed r->pool
> > instead of conf->pool.
>
> I checked how ap_proxy_get_worker() is used in other places and also what
> is done with the pool inside and you are right. It really shouldn't be in a persistent
> pool. Corrected patch is attached.
>
> > Hmm. I thought there was some introductory documentation, but I didn't
> > find much. There is a short note at the end of
> > http://apr.apache.org/docs/apr/1.4/apr__pools_8h.html . Basically, only
> > the functions in http://apr.apache.org/docs/apr/1.4/group__apr__pools.html
> > that are explicitly marked as thread safe may safely operate on a pool
> > from different threads without locking.
>
> Which is basically saying "only the create-sub-pool functions" ;-)
> <fix_mod_proxy_thread_unsafety.patch>
Re: mod_proxy seg faulting ?
Posted by Thomas Eckert <th...@gmail.com>.
> However, looking at your patch, having to lock the mutex for
> ap_proxy_get_worker() looks wrong. I think it should be passed r->pool
> instead of conf->pool.
I checked how ap_proxy_get_worker() is used in other places and also what
is done with the pool inside and you are right. It really shouldn't be in a
persistent
pool. Corrected patch is attached.
> Hmm. I thought there was some introductory documentation, but I didn't
> find much. There is a short note at the end of
> http://apr.apache.org/docs/apr/1.4/apr__pools_8h.html . Basically, only
> the functions in http://apr.apache.org/docs/apr/1.4/group__apr__pools.html
> that are explicitly marked as thread safe may safely operate on a pool
> from different threads without locking.
Which is basically saying "only the create-sub-pool functions" ;-)
Re: mod_proxy seg faulting ?
Posted by Stefan Fritsch <sf...@sfritsch.de>.
On Mon, 6 May 2013, Thomas Eckert wrote:
> Based on Stefan's reply I replaced mod_proxy's config pool with a sub-pool
> and wrapped a mutex around the pool usage. Basic testing went well but I
> have to do some more thorough parallel testing.
Nice.
> One thing which had me confused was the balancers. In
> ap_proxy_define_balancer() they are handed a pointer to mod_proxy's config
> (via balancer->sconf). So I also had to check whether the pool is ever
> accessed via a balancer but to my surprise that pointer is never used at
> all. I suggest removing the balancers' reference to mod_proxy's
> configuration pool, since that makes managing that pool a lot eaiser in the
> future. It's really only 2 lines that have to be edited.
I am not very familiar with the mod_proxy internals. I would have to do
some more thorough code reading to comment on this, but don't have the
time at the moment.
However, looking at your patch, having to lock the mutex for
ap_proxy_get_worker() looks wrong. I think it should be passed r->pool
instead of conf->pool.
Apr has some pool debugging functionality that can also check which thread
accesses which pool. Unfortunately, this does not quite work with the
threaded mpms, yet. But I hope I will make some progress on this in the
next weeks.
Cheers,
Stefan
Re: mod_proxy seg faulting ?
Posted by Thomas Eckert <th...@gmail.com>.
Based on Stefan's reply I replaced mod_proxy's config pool with a sub-pool
and wrapped a mutex around the pool usage. Basic testing went well but I
have to do some more thorough parallel testing.
One thing which had me confused was the balancers. In
ap_proxy_define_balancer() they are handed a pointer to mod_proxy's config
(via balancer->sconf). So I also had to check whether the pool is ever
accessed via a balancer but to my surprise that pointer is never used at
all. I suggest removing the balancers' reference to mod_proxy's
configuration pool, since that makes managing that pool a lot eaiser in the
future. It's really only 2 lines that have to be edited.
On Sat, May 4, 2013 at 8:20 PM, Micha Lenk <mi...@lenk.info> wrote:
> Hi Stefan,
>
> Am 03.05.2013 14:09, schrieb Stefan Fritsch:
> > On Thursday 02 May 2013, Thomas Eckert wrote:
> >> > Lately, I've been seeing httpd/mod_proxy seg faulting in reverse
> >> > proxy setups, frequency increasing.
> >
> > I am pretty sure that this is a thread-unsafe pool usage.
> > create_proxy_config() puts the global config pool into
> > (proxy_server_conf)->pool. It is later (during request processing)
> > used all over the place without further locking. This must be a sub-
> > pool instead, and it must be protected with a mutex. Or new sub-pools
> > must be created wherever conf->pool is used.
>
> Can you please elaborate the problem of thread-unsafe pool usage a bit
> more so that we can better understand why this is causing a segmentation
> fault? Or alternatively, do you have any pointer to documentation,
> mailinglists, what ever, where to read more about it?
>
> Thanks in advance,
> Micha
>
Re: mod_proxy seg faulting ?
Posted by Stefan Fritsch <sf...@sfritsch.de>.
On Sat, 4 May 2013, Micha Lenk wrote:
> > I am pretty sure that this is a thread-unsafe pool usage.
> > create_proxy_config() puts the global config pool into
> > (proxy_server_conf)->pool. It is later (during request processing)
> > used all over the place without further locking. This must be a sub-
> > pool instead, and it must be protected with a mutex. Or new sub-pools
> > must be created wherever conf->pool is used.
>
> Can you please elaborate the problem of thread-unsafe pool usage a bit
> more so that we can better understand why this is causing a segmentation
> fault? Or alternatively, do you have any pointer to documentation,
> mailinglists, what ever, where to read more about it?
Hmm. I thought there was some introductory documentation, but I didn't
find much. There is a short note at the end of
http://apr.apache.org/docs/apr/1.4/apr__pools_8h.html . Basically, only
the functions in http://apr.apache.org/docs/apr/1.4/group__apr__pools.html
that are explicitly marked as thread safe may safely operate on a pool
from different threads without locking.
In most use cases, a pool is tied to some object like a connection or a
request and at a given time only a single worker thread processes this
connection or request. Therefore the pools can be used without locking in
those cases.
But there is only one pool tied to the global configuration, and that pool
must not be used from the worker threads.
Cheers,
Stefan
Re: mod_proxy seg faulting ?
Posted by Micha Lenk <mi...@lenk.info>.
Hi Stefan,
Am 03.05.2013 14:09, schrieb Stefan Fritsch:
> On Thursday 02 May 2013, Thomas Eckert wrote:
>> > Lately, I've been seeing httpd/mod_proxy seg faulting in reverse
>> > proxy setups, frequency increasing.
>
> I am pretty sure that this is a thread-unsafe pool usage.
> create_proxy_config() puts the global config pool into
> (proxy_server_conf)->pool. It is later (during request processing)
> used all over the place without further locking. This must be a sub-
> pool instead, and it must be protected with a mutex. Or new sub-pools
> must be created wherever conf->pool is used.
Can you please elaborate the problem of thread-unsafe pool usage a bit
more so that we can better understand why this is causing a segmentation
fault? Or alternatively, do you have any pointer to documentation,
mailinglists, what ever, where to read more about it?
Thanks in advance,
Micha
Re: mod_proxy seg faulting ?
Posted by Stefan Fritsch <sf...@sfritsch.de>.
On Thursday 02 May 2013, Thomas Eckert wrote:
> Lately, I've been seeing httpd/mod_proxy seg faulting in reverse
> proxy setups, frequency increasing.
I am pretty sure that this is a thread-unsafe pool usage.
create_proxy_config() puts the global config pool into
(proxy_server_conf)->pool. It is later (during request processing)
used all over the place without further locking. This must be a sub-
pool instead, and it must be protected with a mutex. Or new sub-pools
must be created wherever conf->pool is used.
> #0 apr_palloc (pool=0x8b52518, in_size=16) at
> memory/unix/apr_pools.c:684 #1 0xf756fc10 in
> apr_pool_cleanup_register (p=0x8b52518, data=0x8b52528,
> plain_cleanup_fn=0xf756edb0 <thread_cond_cleanup>,
> child_cleanup_fn=0x8069e20 <ap...@plt>) at
> memory/unix/apr_pools.c:2218
> #2 0xf756ef9c in apr_thread_cond_create (cond=0x8b524e0,
> pool=0x8b52390) at locks/unix/thread_cond.c:55
> #3 0xf76fac64 in apr_reslist_create (reslist=0x8a6c488, min=0,
> smax=50, hmax=50, ttl=0, con=0xf72cb8d0 <connection_constructor>,
> de=0xf72cb890 <connection_destructor>,
> params=0x89a8268, pool=0x8b52390) at misc/apr_reslist.c:299
> #4 0xf72cc0d8 in ap_proxy_initialize_worker (worker=0x89a8268,
> s=0x89b3a50, p=0x890b0a8) at proxy_util.c:1751
> #5 0xf72c7d8f in proxy_handler (r=0x8b3e1f0) at mod_proxy.c:1011
> #6 0x0808ba41 in ap_run_handler (r=0x8b3e1f0) at config.c:168
> #7 0x0808f8e6 in ap_invoke_handler (r=0x8b3e1f0) at config.c:432
> #8 0x080a200a in ap_process_async_request (r=0x8b3e1f0) at
> http_request.c:317
> #9 0x080a213d in ap_process_request (r=0x8b3e1f0) at
> http_request.c:363 #10 0x0809ea60 in
> ap_process_http_sync_connection (c=<optimized out>) at
> http_core.c:190
> #11 ap_process_http_connection (c=0x8b3a390) at http_core.c:231
> #12 0x08095e51 in ap_run_process_connection (c=0x8b3a390) at
> connection.c:41 #13 0x080a9470 in process_socket
> (bucket_alloc=<optimized out>, my_thread_num=<optimized out>,
> my_child_num=<optimized out>, sock=<optimized out>, p=<optimized
> out>,
> thd=<optimized out>) at worker.c:620
> #14 worker_thread (thd=0x8a6ddf8, dummy=0x8ac73f8) at worker.c:979
> #15 0xf757cf96 in dummy_worker (opaque=0x8a6ddf8) at
> threadproc/unix/thread.c:142
> #16 0xf7503809 in start_thread () from /lib/libpthread.so.0
> #17 0xf746430e in clone () from /lib/libc.so.6
> Backtrace stopped: Not enough registers or memory available to
> unwind further
> (gdb) frame 0
> #0 apr_palloc (pool=0x8b52518, in_size=16) at
> memory/unix/apr_pools.c:684 684 in memory/unix/apr_pools.c
> (gdb) info locals
> active = 0x0
> node = <optimized out>
> mem = <optimized out>
> size = 16
> free_index = <optimized out>
>
> This is awkward. Shall I assume httpd ran out of memory ? That's
> about the only plausible reason I could see why the apr would run
> into active=0x0.
>
>
>
> #0 0xf74aa2ed in pthread_mutex_lock () from /lib/libpthread.so.0
> #1 0xf75140c0 in apr_thread_mutex_lock (mutex=0x0) at
> locks/unix/thread_mutex.c:92
> #2 0xf769f702 in apr_reslist_maintain (reslist=0x9dc2da8) at
> misc/apr_reslist.c:184
> #3 0xf769fc79 in apr_reslist_create (reslist=0x9dbe448, min=0,
> smax=50, hmax=50, ttl=0, con=0xf72708d0 <connection_constructor>,
> de=0xf7270890 <connection_destructor>,
> params=0x9cfa268, pool=0x9dc2cb0) at misc/apr_reslist.c:305
> #4 0xf72710d8 in ap_proxy_initialize_worker (worker=0x9cfa268,
> s=0x9d05a50, p=0x9c5d0a8) at proxy_util.c:1751
> #5 0xf726cd8f in proxy_handler (r=0xdc9004c0) at mod_proxy.c:1011
> #6 0x0808ba41 in ap_run_handler (r=0xdc9004c0) at config.c:168
> #7 0x0808f8e6 in ap_invoke_handler (r=0xdc9004c0) at config.c:432
> #8 0x080a200a in ap_process_async_request (r=0xdc9004c0) at
> http_request.c:317
> #9 0x080a213d in ap_process_request (r=0xdc9004c0) at
> http_request.c:363 #10 0x0809ea60 in
> ap_process_http_sync_connection (c=<optimized out>) at
> http_core.c:190
> #11 ap_process_http_connection (c=0x9e5f940) at http_core.c:231
> #12 0x08095e51 in ap_run_process_connection (c=0x9e5f940) at
> connection.c:41 #13 0x080a9470 in process_socket
> (bucket_alloc=<optimized out>, my_thread_num=<optimized out>,
> my_child_num=<optimized out>, sock=<optimized out>, p=<optimized
> out>,
> thd=<optimized out>) at worker.c:620
> #14 worker_thread (thd=0x9dbfd98, dummy=0x9e19318) at worker.c:979
> #15 0xf7521f96 in dummy_worker (opaque=0x9dbfd98) at
> threadproc/unix/thread.c:142
> #16 0xf74a8809 in start_thread () from /lib/libpthread.so.0
> #17 0xf740930e in clone () from /lib/libc.so.6
>
> This is even stranger: it's trying to lock on a null pointer.
>
>
> I'm just starting to dig into this myself. Has anyone seen stuff
> like this (recently) ? I checked the bug reports but didn't see
> anything obvious.