[Swan] thread locked

[Paul Wouters]

On Fri, 1 Mar 2013, Paul Wouters wrote:

We just saw it again. It looks like the do_authentication() thread is
fighting with the the main or crypto helper thread, deadlocking...

Philippe, would you have any pointers to where we should look for this
bug?

(gdb) status
Undefined command: "status".  Try "help".
(gdb) where
#0  __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:93
#1  0x00007f90c48d7221 in _L_lock_10627 () at malloc.c:5209
#2  0x00007f90c48d4fa7 in __GI___libc_malloc (bytes=140259752978208) at malloc.c:2921
#3  0x00007f90c48c4cad in __GI_open_memstream (bufloc=0x7fff448d7790, sizeloc=0x7fff448d77a0) at memstream.c:79
#4  0x00007f90c494168b in __GI___vsyslog_chk (pri=83, flag=-1, fmt=0x7f90c49d0008 "*** glibc detected *** %s: %s: 0x%s ***\n",
     ap=0x7fff448d7ff8) at ../misc/syslog.c:169
#5  0x00007f90c48c62df in __libc_message (do_abort=2, fmt=0x7f90c49d0008 "*** glibc detected *** %s: %s: 0x%s ***\n")
     at ../sysdeps/unix/sysv/linux/libc_fatal.c:169
#6  0x00007f90c48d0b96 in malloc_printerr (action=3, str=0x7f90c49cc8f6 "corrupted double-linked list", ptr=<optimized out>)
     at malloc.c:5007
#7  0x00007f90c48d3640 in _int_malloc (av=0x7f90c4c0a720, bytes=512) at malloc.c:3795
#8  0x00007f90c48d6365 in __libc_calloc (n=<optimized out>, elem_size=<optimized out>) at malloc.c:3274
#9  0x00007f90bf096018 in ?? () from /usr/lib/x86_64-linux-gnu/nss/libfreebl3.so
#10 0x00007f90bf098f3a in ?? () from /usr/lib/x86_64-linux-gnu/nss/libfreebl3.so
#11 0x00007f90bf099297 in ?? () from /usr/lib/x86_64-linux-gnu/nss/libfreebl3.so
#12 0x00007f90bf099597 in ?? () from /usr/lib/x86_64-linux-gnu/nss/libfreebl3.so
#13 0x00007f90bf06ff9a in ?? () from /usr/lib/x86_64-linux-gnu/nss/libfreebl3.so
#14 0x00007f90bf08d0bf in ?? () from /usr/lib/x86_64-linux-gnu/nss/libfreebl3.so
#15 0x00007f90bf512f80 in ?? () from /usr/lib/x86_64-linux-gnu/nss/libsoftokn3.so
#16 0x00007f90bf50ac81 in ?? () from /usr/lib/x86_64-linux-gnu/nss/libsoftokn3.so
#17 0x00007f90c604fd02 in PK11_Sign () from /usr/lib/x86_64-linux-gnu/libnss3.so
#18 0x000000000046738c in sign_hash_nss (k=0x19229b0,
     hash_val=0x7fff448d8db0 "\033t\370\017\066\244\202\312s\371\354\264\\\035^\301\024A\204\235", hash_len=20,
     sig_val=0x7fff448d89b0 "NTACT msgid=00000000", sig_len=256) at /root/libreswan-3.1dr2/programs/pluto/keys.c:232
#19 0x0000000000467145 in sign_hash (k=0x19229b0,
     hash_val=0x7fff448d8db0 "\033t\370\017\066\244\202\312s\371\354\264\\\035^\301\024A\204\235", hash_len=20,
     sig_val=0x7fff448d89b0 "NTACT msgid=00000000", sig_len=256) at /root/libreswan-3.1dr2/programs/pluto/keys.c:174
#20 0x0000000000434d35 in RSA_sign_hash (c=0x1ac5e60, sig_val=0x7fff448d89b0 "NTACT msgid=00000000",
     hash_val=0x7fff448d8db0 "\033t\370\017\066\244\202\312s\371\354\264\\\035^\301\024A\204\235", hash_len=20)
     at /root/libreswan-3.1dr2/programs/pluto/ikev1_main.c:418
#21 0x0000000000438a07 in main_inI3_outR3_tail (md=0x19201a0, kc=0x0) at /root/libreswan-3.1dr2/programs/pluto/ikev1_main.c:2110
#22 0x00000000004384f7 in main_inI3_outR3 (md=0x19201a0) at /root/libreswan-3.1dr2/programs/pluto/ikev1_main.c:1968
#23 0x0000000000432254 in process_packet_tail (mdp=0x733e48) at /root/libreswan-3.1dr2/programs/pluto/ikev1.c:2070
#24 0x0000000000431217 in process_v1_packet (mdp=0x733e48) at /root/libreswan-3.1dr2/programs/pluto/ikev1.c:1622
#25 0x0000000000466426 in process_packet (mdp=0x733e48) at /root/libreswan-3.1dr2/programs/pluto/demux.c:171
#26 0x00000000004664b3 in comm_handle (ifp=0x1906e60) at /root/libreswan-3.1dr2/programs/pluto/demux.c:225
#27 0x00000000004272c1 in call_server () at /root/libreswan-3.1dr2/programs/pluto/server.c:787
#28 0x0000000000423c33 in main (argc=4, argv=0x7fff448dab28) at /root/libreswan-3.1dr2/programs/pluto/plutomain.c:1262
(gdb) thread 2
[Switching to thread 2 (Thread 0x7f90bf06b700 (LWP 19326))]
#0  __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:93
93	in ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S
(gdb) bt
#0  __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:93
#1  0x00007f90c48a036a in _L_lock_12836 () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007f90c48a020f in buffered_vfprintf (s=0x18ed2a0, format=<optimized out>, args=<optimized out>) at vfprintf.c:2320
#3  0x00007f90c489abde in _IO_vfprintf_internal (s=0x18ed2a0, format=0x4d9c19 "%s: %s\n", ap=0x7f90bf06a728) at vfprintf.c:1316
#4  0x00007f90c48a5837 in __fprintf (stream=<optimized out>, format=<optimized out>) at fprintf.c:33
#5  0x000000000041b391 in libreswan_log (message=0x4f3548 "XAUTH: User %s: Attempting to login")
     at /root/libreswan-3.1dr2/programs/pluto/log.c:450
#6  0x00000000004875a1 in do_authentication (varg=0x1e552d0) at /root/libreswan-3.1dr2/programs/pluto/xauth.c:1399
#7  0x00007f90c5bbce9a in start_thread (arg=0x7f90bf06b700) at pthread_create.c:308
#8  0x00007f90c4945cbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#9  0x0000000000000000 in ?? ()