[syslog-ng] deadlock when logging to SQL destination (PostgreSQL)

Wed Jan 7 07:19:59 CET 2015

Hello,

mine colleague prepared the backtraces.
Please, see attached file.

Let me know if there is anything elase a should provide (cfg files,
logs,..).

Thanks for any suggestions/help.
-- 
Tomáš Novosad
LinuxBox.cz, s.r.o.
28. října 168, 709 00 Ostrava

tel.:   +420 591 166 221
mobil:  +420 737 238 655
email:  tomas.novosad at linuxbox.cz
jabber: novosad at linuxbox.cz
www.linuxbox.cz

mobil servis: +420 737 238 656
email servis: servis at linuxbox.cz

On  5. 1. 12:11, Scheidler, Balázs wrote:
> Hi,
> 
> checking the backtrace again, it might actually be a genuine deadlock. can
> you give a backtrace of all the threads as syslog-ng stalls like that?
> 
> 
> -- 
> Bazsi
> 

-------------- next part --------------
Threads:
 4 Thread 0x7fc0a6892700 (LWP 4219)  0x00007fc0a4e835bc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
 3 Thread 0x7fc0a6871700 (LWP 4220)  0x00007fc0a4bc3043 in poll () from /lib64/libc.so.6
 2 Thread 0x7fc0a6850700 (LWP 4221)  0x00007fc0a4bc3043 in poll () from /lib64/libc.so.6
 1 Thread 0x7fc0a6899980 (LWP 4218)  0x00007fc0a4e86264 in __lll_lock_wait () from /lib64/libpthread.so.0

Thread 1:
#0  0x00007fc0a4e86264 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007fc0a4e81508 in _L_lock_854 () from /lib64/libpthread.so.0
#2  0x00007fc0a4e813d7 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00007fc0a40a94e3 in afsql_dd_message_became_available_in_the_queue (user_data=0xbbebe0) at afsql.c:889
#4  0x00007fc0a64319d5 in log_queue_push_notify (self=0xbfaa30) at logqueue.c:58
#5  0x00007fc0a6432b78 in log_queue_fifo_push_tail (s=0xbfaa30, msg=0xc3f1c0, path_options=0x7fffd66ae4b0) at logqueue-fifo.c:263
#6  0x00007fc0a40a9cd4 in log_queue_push_tail (s=0xbbebe0, msg=0xc3f1c0, path_options=0x7fffd66ae4b0, user_data=0x0) at ../../lib/logqueue.h:84
#7  afsql_dd_queue (s=0xbbebe0, msg=0xc3f1c0, path_options=0x7fffd66ae4b0, user_data=0x0) at afsql.c:1198
#8  0x00007fc0a642b049 in log_pipe_queue (s=0xb99db0, msg=0xc3f1c0, path_options=0x7fffd66ae600, user_data=<value optimized out>) at logpipe.h:320
#9  log_multiplexer_queue (s=0xb99db0, msg=0xc3f1c0, path_options=0x7fffd66ae600, user_data=<value optimized out>) at logmpx.c:106
#10 0x00007fc0a642b049 in log_pipe_queue (s=0xb99f10, msg=0xc3f1c0, path_options=0x7fffd66aee30, user_data=<value optimized out>) at logpipe.h:320
#11 log_multiplexer_queue (s=0xb99f10, msg=0xc3f1c0, path_options=0x7fffd66aee30, user_data=<value optimized out>) at logmpx.c:106
#12 0x00007fc0a6435029 in log_pipe_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:320
#13 log_pipe_forward_msg (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#14 log_rewrite_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logrewrite.c:68
#15 0x00007fc0a6435029 in log_pipe_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:320
#16 log_pipe_forward_msg (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#17 log_rewrite_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logrewrite.c:68
#18 0x00007fc0a6435029 in log_pipe_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:320
#19 log_pipe_forward_msg (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#20 log_rewrite_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logrewrite.c:68
#21 0x00007fc0a6435029 in log_pipe_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:320
#22 log_pipe_forward_msg (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#23 log_rewrite_queue (s=<value optimized out>, msg=0xc3f1c0, path_options=<value optimized out>, user_data=<value optimized out>) at logrewrite.c:68
#24 0x00007fc0a642e5ad in log_pipe_queue (s=<value optimized out>, msg=0xc0a800, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:320
#25 log_pipe_forward_msg (s=<value optimized out>, msg=0xc0a800, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#26 log_parser_queue (s=<value optimized out>, msg=0xc0a800, path_options=<value optimized out>, user_data=<value optimized out>) at logparser.c:81
#27 0x00007fc0a6426b7d in log_pipe_queue (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:320
#28 log_pipe_forward_msg (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#29 log_filter_pipe_queue (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>, user_data=<value optimized out>) at filter.c:731
#30 0x00007fc0a642aca0 in log_pipe_queue (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:320
#31 log_pipe_forward_msg (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#32 log_pipe_queue (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#33 log_pipe_forward_msg (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#34 log_pipe_queue (s=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#35 0x00007fc0a642b191 in log_pipe_forward_msg (s=0xb77390, msg=0xc5d440, path_options=0x7fffd66aefd0, user_data=<value optimized out>) at logpipe.h:289
#36 log_pipe_queue (s=0xb77390, msg=0xc5d440, path_options=0x7fffd66aefd0, user_data=<value optimized out>) at logpipe.h:324
#37 log_multiplexer_queue (s=0xb77390, msg=0xc5d440, path_options=0x7fffd66aefd0, user_data=<value optimized out>) at logmpx.c:106
#38 0x00007fc0a6435cc8 in log_pipe_queue (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:320
#39 log_pipe_forward_msg (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#40 log_pipe_queue (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#41 log_pipe_forward_msg (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#42 log_pipe_queue (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#43 log_pipe_forward_msg (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#44 0x00007fc0a6435e3c in log_pipe_queue (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#45 log_pipe_forward_msg (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#46 log_pipe_queue (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#47 log_pipe_forward_msg (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#48 log_pipe_queue (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:324
#49 log_pipe_forward_msg (self=<value optimized out>, msg=0xc5d440, path_options=<value optimized out>) at logpipe.h:289
#50 0x00007fc0a64364fb in log_pipe_queue (s=0xb83800, msg=0xc5d440, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:324
#51 log_pipe_forward_msg (s=0xb83800, msg=0xc5d440, path_options=<value optimized out>, user_data=<value optimized out>) at logpipe.h:289
#52 log_source_queue (s=0xb83800, msg=0xc5d440, path_options=<value optimized out>, user_data=<value optimized out>) at logsource.c:290
#53 0x00007fc0a64340c9 in log_pipe_queue (s=0xb83800) at logpipe.h:320
#54 log_reader_handle_line (s=0xb83800) at logreader.c:544
#55 log_reader_fetch_log (s=0xb83800) at logreader.c:602
#56 log_reader_work_perform (s=0xb83800) at logreader.c:119
#57 0x00007fc0a6434268 in log_reader_io_process_input (s=0xb83800) at logreader.c:225
#58 0x00007fc0a6458d47 in iv_fd_poll_and_run (st=0xb6f210, to=<value optimized out>) at iv_fd.c:163
#59 0x00007fc0a6459504 in iv_main () at iv_main_posix.c:117
#60 0x00007fc0a643abb7 in main_loop_run () at mainloop.c:736
#61 0x00000000004017c9 in main ()

Thread 2:
#0  0x00007fc0a4bc3043 in poll () from /lib64/libc.so.6
#1  0x00007fc0a2b8726f in ?? () from /usr/pgsql-9.2/lib/libpq.so.5
#2  0x00007fc0a2b872f0 in ?? () from /usr/pgsql-9.2/lib/libpq.so.5
#3  0x00007fc0a2b86969 in PQgetResult () from /usr/pgsql-9.2/lib/libpq.so.5
#4  0x00007fc0a2b86bf8 in ?? () from /usr/pgsql-9.2/lib/libpq.so.5
#5  0x00007fc0a2da53ff in dbd_query () from /usr/lib64/dbd/libdbdpgsql.so
#6  0x00007fc0a3e9bf14 in dbi_conn_query () from /usr/lib64/libdbi.so.0
#7  0x00007fc0a40a9f89 in afsql_dd_run_query (self=0xbbebe0, query=0x7fc0a40ad4ed "COMMIT", silent=0, result=0x0) at afsql.c:344
#8  0x00007fc0a40aa269 in afsql_dd_commit_txn (self=0xbbebe0) at afsql.c:595
#9  0x00007fc0a40ab193 in afsql_dd_database_thread (arg=0xbbebe0) at afsql.c:933
#10 0x00007fc0a643c84b in worker_thread_func (st=<value optimized out>) at misc.c:580
#11 0x00007fc0a59361b4 in ?? () from /lib64/libglib-2.0.so.0
#12 0x00007fc0a4e7f9d1 in start_thread () from /lib64/libpthread.so.0
#13 0x00007fc0a4bcc86d in clone () from /lib64/libc.so.6

Thread 3:
#0  0x00007fc0a4bc3043 in poll () from /lib64/libc.so.6
#1  0x00007fc0a2b8726f in ?? () from /usr/pgsql-9.2/lib/libpq.so.5
#2  0x00007fc0a2b872f0 in ?? () from /usr/pgsql-9.2/lib/libpq.so.5
#3  0x00007fc0a2b86969 in PQgetResult () from /usr/pgsql-9.2/lib/libpq.so.5
#4  0x00007fc0a2b86bf8 in ?? () from /usr/pgsql-9.2/lib/libpq.so.5
#5  0x00007fc0a2da53ff in dbd_query () from /usr/lib64/dbd/libdbdpgsql.so
#6  0x00007fc0a3e9bf14 in dbi_conn_query () from /usr/lib64/libdbi.so.0
#7  0x00007fc0a40a9f89 in afsql_dd_run_query (self=0xb9c050, query=0x7fc0a40ad4ed "COMMIT", silent=0, result=0x0) at afsql.c:344
#8  0x00007fc0a40aa269 in afsql_dd_commit_txn (self=0xb9c050) at afsql.c:595
#9  0x00007fc0a40ab193 in afsql_dd_database_thread (arg=0xb9c050) at afsql.c:933
#10 0x00007fc0a643c84b in worker_thread_func (st=<value optimized out>) at misc.c:580
#11 0x00007fc0a59361b4 in ?? () from /lib64/libglib-2.0.so.0
#12 0x00007fc0a4e7f9d1 in start_thread () from /lib64/libpthread.so.0
#13 0x00007fc0a4bcc86d in clone () from /lib64/libc.so.6

Thread 4:
#0  0x00007fc0a4e835bc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007fc0a40ab211 in afsql_dd_database_thread (arg=0xb9b870) at afsql.c:943
#2  0x00007fc0a643c84b in worker_thread_func (st=<value optimized out>) at misc.c:580
#3  0x00007fc0a59361b4 in ?? () from /lib64/libglib-2.0.so.0
#4  0x00007fc0a4e7f9d1 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fc0a4bcc86d in clone () from /lib64/libc.so.6