On Wed, Sep 02, 2020 at 12:36:26PM +0200, Ruediger Pluem wrote:
> will always fail since node->endp[index] should be zero. Hence it should not
> find a pool. Or am I off now?
I think we get very little ordering constraints without memory
synchronisation, regardless of the order of the C statements another
thread can see a different/inconsistent memory state, but not really
sure.
I tried reproducing locally and can trigger crashes in these code paths
quite easily with running ab against pool-debug/event build with
memcache or shmcb configured as session cache.
In this case one thread is walking the pool heirarchy and trying to lock
a pool mutex which has already been deleted, which triggers a libc
assert() instead. The mutex is in ptrans, I assume from another event
thread.
If we see this regularly I'd conclude the apr_pool_find() stuff is
simply unsafe and should be turned off.
(gdb) where
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f842445f895 in __GI_abort () at abort.c:79
#2 0x00007f842445f769 in __assert_fail_base (fmt=0x7f84245cd0b8 "%s%s%s:%u:
%s%sAssertion `%s' failed.\n%n",
assertion=0x7f8424652110 "new_prio == -1 || (new_prio >= fifo_min_prio &&
new_prio <= fifo_max_prio)",
file=0x7f8424652104 "tpp.c", line=82, function=<optimized out>) at
assert.c:92
#3 0x00007f842446ee76 in __GI___assert_fail (
assertion=assertion@entry=0x7f8424652110 "new_prio == -1 || (new_prio >=
fifo_min_prio && new_prio <= fifo_max_prio)",
file=file@entry=0x7f8424652104 "tpp.c", line=line@entry=82,
function=function@entry=0x7f84246521c0 <__PRETTY_FUNCTION__.0>
"__pthread_tpp_change_priority") at assert.c:101
#4 0x00007f842464f849 in __pthread_tpp_change_priority
(previous_prio=previous_prio@entry=-1, new_prio=new_prio@entry=2088)
at tpp.c:82
#5 0x00007f84246458a0 in __pthread_mutex_lock_full (mutex=0x7f83f80c8b18) at
../nptl/pthread_mutex_lock.c:545
#6 0x00007f8424645e05 in __GI___pthread_mutex_lock
(mutex=mutex@entry=0x7f83f80c8b18) at ../nptl/pthread_mutex_lock.c:73
#7 0x00007f84246f3e0a in apr_thread_mutex_lock (mutex=0x7f83f80c8b10) at
locks/unix/thread_mutex.c:127
#8 0x00007f84246f437e in apr_pool_walk_tree (data=0x7f83b9ffabc8,
fn=0x7f84246f4190 <pool_find>, pool=0x7f839000d680)
at memory/unix/apr_pools.c:1505
#9 apr_pool_walk_tree (pool=0x7f839000d680, fn=0x7f84246f4190 <pool_find>,
data=0x7f83b9ffabc8) at memory/unix/apr_pools.c:1492
#10 0x00007f84246f439e in apr_pool_walk_tree (data=0x7f83b9ffabc8,
fn=0x7f84246f4190 <pool_find>, pool=0x1482e30)
at memory/unix/apr_pools.c:1511
#11 apr_pool_walk_tree (pool=0x1482e30, fn=0x7f84246f4190 <pool_find>,
data=0x7f83b9ffabc8) at memory/unix/apr_pools.c:1492
#12 0x00007f84246f439e in apr_pool_walk_tree (data=0x7f83b9ffabc8,
fn=0x7f84246f4190 <pool_find>, pool=0x14828b0)
at memory/unix/apr_pools.c:1511
#13 apr_pool_walk_tree (pool=0x14828b0, fn=0x7f84246f4190 <pool_find>,
data=0x7f83b9ffabc8) at memory/unix/apr_pools.c:1492
#14 0x00007f84246f54d8 in apr_pool_walk_tree (data=0x7f83b9ffabc8,
fn=0x7f84246f4190 <pool_find>, pool=0x14822d0)
at memory/unix/apr_pools.c:1511
#15 apr_pool_walk_tree (data=0x7f83b9ffabc8, fn=0x7f84246f4190 <pool_find>,
pool=0x14822d0) at memory/unix/apr_pools.c:1492
#16 apr_pool_find (mem=mem@entry=0x7f83a4023f06) at memory/unix/apr_pools.c:2291
#17 0x00007f84246e72cd in apr_table_addn (t=0x7f83a4023ab0,
key=key@entry=0x7f83a4023f00 "Host",
val=val@entry=0x7f83a4023f06 "localhost:8532") at tables/apr_tables.c:823
#18 0x0000000000455bb4 in ap_get_mime_headers_core (r=r@entry=0x7f83a4002370,
bb=bb@entry=0x7f83a40230a0) at protocol.c:1353
#19 0x0000000000458a3f in ap_read_request (conn=conn@entry=0x7f83a401b340) at
protocol.c:1513
#20 0x0000000000434f6f in ap_process_http_async_connection (c=0x7f83a401b340)
at http_core.c:148
#21 ap_process_http_connection (c=0x7f83a401b340) at http_core.c:252
#22 0x000000000044cb00 in ap_run_process_connection (c=c@entry=0x7f83a401b340)
at connection.c:42
#23 0x00007f842488c8f1 in process_socket (thd=thd@entry=0x7f8408004920,
p=<optimized out>, sock=0x7f8390001480,
cs=0x7f83a4015ef0, my_child_num=my_child_num@entry=3,
my_thread_num=my_thread_num@entry=23) at event.c:1106
#24 0x00007f842488cfd8 in worker_thread (thd=0x7f8408004920, dummy=<optimized
out>) at event.c:2396
#25 0x00007f84246ff57e in dummy_worker (opaque=0x7f8408004920) at
threadproc/unix/thread.c:145
#26 0x00007f8424643432 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#27 0x00007f842453b913 in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(gdb) up 7
#7 0x00007f84246f3e0a in apr_thread_mutex_lock (mutex=0x7f83f80c8b10) at
locks/unix/thread_mutex.c:127
127 rv = pthread_mutex_lock(&mutex->mutex);
(gdb) print *mutex
$1 = {pool = 0x0, mutex = {__data = {__lock = 1094795585, __count = 1094795585,
__owner = 1094795585, __nusers = 1094795585,
__kind = 1094795585, __spins = 16705, __elision = 16705, __list = {__prev
= 0x4141414141414141,
__next = 0x4141414141414141}}, __size = 'A' <repeats 40 times>, __align
= 4702111234474983745},
cond = 0x4141414141414141, locked = 1094795585, num_waiters = 1094795585}
