[Swan] some threading bugs solved, some not yet

[D. Hugh Redelmeier]

| From: Paul Wouters <paul at nohats.ca>


| Although syslog was not in the list of "unsafe functions" in "man
| pthreads", it does seem to cause an issue in a thread:

Well, you only seem to have given us the backtrace for one thread.
You don't even say what kind of a crash was observed.

| #0  __lll_lock_wait_private () at

This thread seems to be waiting on a lock.  Is that a crash?

| ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:93
| #1  0x00007ffff6399221 in _L_lock_10627 () at malloc.c:5209
| #2  0x00007ffff6396fa7 in __GI___libc_malloc (bytes=140737327712032) at
| malloc.c:2921
| #3  0x00007ffff7de7900 in _dl_map_object_deps (map=0x7ffff7fef4e8,
| preloads=<optimized out>, npreloads=<optimized out>, trace_mode=0,
|     open_mode=-2147483648) at dl-deps.c:517
| #4  0x00007ffff7ded8a9 in dl_open_worker (a=0x7fffffffb440) at dl-open.c:262
| #5  0x00007ffff7de9176 in _dl_catch_error (objname=0x7fffffffb488,
| errstring=0x7fffffffb490, mallocedp=0x7fffffffb49f,
|     operate=0x7ffff7ded700 <dl_open_worker>, args=0x7fffffffb440) at
| dl-error.c:178
| #6  0x00007ffff7ded31a in _dl_open (file=0x7ffff648d298 "libgcc_s.so.1",
| mode=-2147483647, caller_dlopen=0x7ffff641e8f5, nsid=-2, argc=4,
|     argv=<optimized out>, env=0x7fffffffe6d0) at dl-open.c:639
| #7  0x00007ffff6444602 in do_dlopen (ptr=0x7fffffffb640) at dl-libc.c:89
| #8  0x00007ffff7de9176 in _dl_catch_error (objname=0x7fffffffb670,
| errstring=0x7fffffffb660, mallocedp=0x7fffffffb67f,
|     operate=0x7ffff64445c0 <do_dlopen>, args=0x7fffffffb640) at dl-error.c:178
| #9  0x00007ffff64446c4 in dlerror_run (args=0x7fffffffb640,
| operate=0x7ffff64445c0 <do_dlopen>) at dl-libc.c:48
| #10 __GI___libc_dlopen_mode (name=<optimized out>, mode=<optimized out>) at
| dl-libc.c:165
| #11 0x00007ffff641e8f5 in init () at ../sysdeps/x86_64/../ia64/backtrace.c:53
| #12 0x00007ffff7684400 in pthread_once () at
| ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_once.S:104
| #13 0x00007ffff641ea14 in __GI___backtrace (array=<optimized out>, size=64) at
| ../sysdeps/x86_64/../ia64/backtrace.c:104
| #14 0x00007ffff63883af in __libc_message (do_abort=2, fmt=0x7ffff6492008 "***
| glibc detected *** %s: %s: 0x%s ***\n")
|     at ../sysdeps/unix/sysv/linux/libc_fatal.c:180

This looks grave.  It is the kind of thing that might result from a
non-threadsafe library call.

| #15 0x00007ffff6392b96 in malloc_printerr (action=3, str=0x7ffff648e8f6
| "corrupted double-linked list", ptr=<optimized out>)
|     at malloc.c:5007
| #16 0x00007ffff6392ec8 in malloc_consolidate (av=0x7ffff66cc720) at
| malloc.c:4246
| #17 0x00007ffff6394436 in malloc_consolidate (av=0x7ffff66cc720) at
| malloc.c:4215

It looks like malloc is trying to reorganize its arena and finds
corruption.

| #18 _int_malloc (av=0x7ffff66cc720, bytes=8192) at malloc.c:3532
| #19 0x00007ffff6398365 in __libc_calloc (n=<optimized out>,
| elem_size=<optimized out>) at malloc.c:3274
| #20 0x00007ffff6386cd9 in __GI_open_memstream (bufloc=0x7fffffffc260,
| sizeloc=0x7fffffffc270) at memstream.c:86
| #21 0x00007ffff640368b in __GI___vsyslog_chk (pri=87, flag=-1, fmt=0x4da8f0
| "%c %s", ap=0x7fffffffc2c8) at ../misc/syslog.c:169
| #22 0x00007ffff6403cdf in __syslog (pri=<optimized out>, fmt=<optimized out>)
| at ../misc/syslog.c:119

It looks like the malloc call was from syslog.

Note: this call provoked malloc to examine its arena.  This does not
mean that this call is the problem.

| #23 0x000000000041c2f1 in libreswan_DBG_log (message=0x4da725 "%s") at
| /root/libreswan-3.1dr3/programs/pluto/log.c:758
| #24 0x000000000041c587 in libreswan_DBG_dump (label=0x4e02d3 "del:",
| p=0x78df80, len=0) at /root/libreswan-3.1dr3/programs/pluto/log.c:829
| #25 0x00000000004320b4 in process_packet_tail (mdp=0x735e28) at
| /root/libreswan-3.1dr3/programs/pluto/ikev1.c:2023
| #26 0x000000000043118b in process_v1_packet (mdp=0x735e28) at
| /root/libreswan-3.1dr3/programs/pluto/ikev1.c:1621
| #27 0x00000000004663f6 in process_packet (mdp=0x735e28) at
| /root/libreswan-3.1dr3/programs/pluto/demux.c:171
| #28 0x0000000000466483 in comm_handle (ifp=0x76edf0) at
| /root/libreswan-3.1dr3/programs/pluto/demux.c:225
| #29 0x00000000004271e1 in call_server () at
| /root/libreswan-3.1dr3/programs/pluto/server.c:787
| #30 0x0000000000423b53 in main (argc=4, argv=0x7fffffffe6a8) at
| /root/libreswan-3.1dr3/programs/pluto/plutomain.c:1262
| 
| _______________________________________________
| Swan mailing list
| Swan at lists.libreswan.org
| https://lists.libreswan.org/mailman/listinfo/swan
| 
|