Re: Strange hanging bug in a simple milter

On 09.09.2013 15:36, Vesa-Matti J Kari wrote:
> It looks like a deadlock situation of some kind...
>
> (gdb) thread 2
> [Switching to thread 2 (Thread 0x7fe62f7fe700 (LWP 27284))]
> #0 0x00007fe64c0b589c in __lll_lock_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
> (gdb) bt
> #0 0x00007fe64c0b589c in __lll_lock_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
> #1 0x00007fe64c0b1065 in _L_lock_858 () from /lib/x86_64-linux-gnu/libpthread.so.0
> #2 0x00007fe64c0b0eba in pthread_mutex_lock () from /lib/x86_64-linux-gnu/libpthread.so.0
> #3 0x00007fe64c2df200 in ?? () from /usr/lib/libpq.so.5
> #4 0x00007fe64b78a5f5 in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #5 0x00007fe64b77a915 in RSA_new_method () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #6 0x00007fe64b77d64d in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #7 0x00007fe64b7b9bf2 in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #8 0x00007fe64b7bc6d1 in ASN1_item_ex_d2i () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #9 0x00007fe64b7bd0c4 in ASN1_item_d2i () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #10 0x00007fe64b77ea2f in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #11 0x00007fe64b7b461a in X509_PUBKEY_get () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #12 0x00007fe64b7d119a in X509_get_pubkey_parameters () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #13 0x00007fe64b7d1398 in X509_verify_cert () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #14 0x00007fe64bac52f8 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
> #15 0x00007fe64baa2ef3 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
> #16 0x00007fe64baa7222 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
> #17 0x00007fe64c2dffcb in ?? () from /usr/lib/libpq.so.5
> #18 0x00007fe64c2d0c5e in PQconnectPoll () from /usr/lib/libpq.so.5
> #19 0x00007fe64c2d1e3e in ?? () from /usr/lib/libpq.so.5
> #20 0x00007fe64c2d26f8 in PQsetdbLogin () from /usr/lib/libpq.so.5
> #21 0x0000000000401ba5 in authmilt_connect (ctx=0xe81b60, hostname=0x7fe6200008c0 "localhost", hostaddr=0x7fe62f7fdce0) at authmilter.c:212
> #22 0x00007fe64c4f69dc in ?? () from /usr/lib/libmilter.so.1.0.1
> #23 0x00007fe64c4f5f5f in mi_engine () from /usr/lib/libmilter.so.1.0.1
> #24 0x00007fe64c4fada6 in ?? () from /usr/lib/libmilter.so.1.0.1
> #25 0x00007fe64c0aee9a in start_thread () from
> /lib/x86_64-linux-gnu/libpthread.so.0
> #26 0x00007fe64bddbccd in clone () from /lib/x86_64-linux-gnu/libc.so.6
> #27 0x0000000000000000 in ?? ()
>
> (gdb) thread 3
> [Switching to thread 3 (Thread 0x7fe62ffff700 (LWP 27283))]
> #0 0x00007fe64c0b589c in __lll_lock_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
> (gdb) bt
> #0 0x00007fe64c0b589c in __lll_lock_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
> #1 0x00007fe64c0b1065 in _L_lock_858 () from /lib/x86_64-linux-gnu/libpthread.so.0
> #2 0x00007fe64c0b0eba in pthread_mutex_lock () from /lib/x86_64-linux-gnu/libpthread.so.0
> #3 0x00007fe64c2df200 in ?? () from /usr/lib/libpq.so.5
> #4 0x00007fe64b78a5f5 in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #5 0x00007fe64b77a915 in RSA_new_method () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #6 0x00007fe64b77d64d in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #7 0x00007fe64b7b9bf2 in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #8 0x00007fe64b7bc6d1 in ASN1_item_ex_d2i () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #9 0x00007fe64b7bd0c4 in ASN1_item_d2i () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #10 0x00007fe64b77ea2f in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #11 0x00007fe64b7b461a in X509_PUBKEY_get () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #12 0x00007fe64b7d119a in X509_get_pubkey_parameters () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #13 0x00007fe64b7d1398 in X509_verify_cert () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
> #14 0x00007fe64bac52f8 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
> #15 0x00007fe64baa2ef3 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
> #16 0x00007fe64baa7222 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
> #17 0x00007fe64c2dffcb in ?? () from /usr/lib/libpq.so.5
> #18 0x00007fe64c2d0c5e in PQconnectPoll () from /usr/lib/libpq.so.5
> #19 0x00007fe64c2d1e3e in ?? () from /usr/lib/libpq.so.5
> #20 0x00007fe64c2d26f8 in PQsetdbLogin () from /usr/lib/libpq.so.5
> #21 0x0000000000401ba5 in authmilt_connect (ctx=0xe818e0, hostname=0x7fe6280008c0 "localhost", hostaddr=0x7fe62fffece0) at authmilter.c:212
> #22 0x00007fe64c4f69dc in ?? () from /usr/lib/libmilter.so.1.0.1
> #23 0x00007fe64c4f5f5f in mi_engine () from /usr/lib/libmilter.so.1.0.1
> #24 0x00007fe64c4fada6 in ?? () from /usr/lib/libmilter.so.1.0.1
> #25 0x00007fe64c0aee9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
> #26 0x00007fe64bddbccd in clone () from /lib/x86_64-linux-gnu/libc.so.6
> #27 0x0000000000000000 in ?? ()
>
> If I interpret this correctly, threads #2 and #3 are waiting for the same
> lock but they make no progress.

A-ha, the deadlock happens while doing SSL stuff. I didn't have SSL
enabled in my test server. As soon as I turned it on, it hung.

Attached is a small stand-alone test program to reproduce it. You can
pass a libpq connection string as argument to it.

I'll dig into that, but right now it seems like an OpenSSL or libcrypto
bug to me. Or something in the way we use them, although I can't see
anything obviously wrong in the libpq code at a quick glance.

- Heikki