<p dir="ltr">The problem with these backtraces is that it shows the main thread, and syslog-ng is probably spinning somewhere else.</p>
<p dir="ltr">Can you check which thread is spinning (using top -L iirc) and then change to the appropriate thread using the thread command in gdb?</p>
<p dir="ltr">Alternatively "thread apply backtrace" should display backtrace of all threads.</p>
<p dir="ltr">But itd be better to locate the spinning thread first.</p>
<p dir="ltr">Thanks in advance.<br>
</p>
<div class="gmail_quote">On Oct 19, 2013 10:36 PM, "Alexandre Biancalana" <<a href="mailto:biancalana@gmail.com">biancalana@gmail.com</a>> wrote:<br type="attribution"><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div dir="ltr"><div>Compilling with CFLAGS="-ggdb3 -O0" does not reproduce the issue...<br><br></div>Follow the snapshots Balazs asked for:<br><br>Advancing patterndb current time because of timer tick; utc='1382204151'<br>
^C<br>Program received signal SIGINT, Interrupt.<br>0x00007ffff6544f03 in epoll_wait () from /lib64/libc.so.6<br>Missing separate debuginfos, use: debuginfo-install glib2-2.22.5-7.el6.x86_64 glibc-2.12-1.107.el6.x86_64 json-c-0.10-2.el6.x86_64 keyutils-libs-1.4-4.el6.x86_64 krb5-libs-1.10.3-10.el6.x86_64 libcom_err-1.41.12-14.el6.x86_64 libnet-1.1.5-1.el6.x86_64 libselinux-2.0.94-5.3.el6.x86_64 openssl-1.0.0-27.el6.x86_64 pcre-7.8-6.el6.x86_64 zlib-1.2.3-29.el6.x86_64<br>
(gdb) bt<br>#0 0x00007ffff6544f03 in epoll_wait () from /lib64/libc.so.6<br>#1 0x00007ffff7baaecd in iv_fd_epoll_poll (st=0x605df0, active=0x7fffffffe3c0, to=0x7fffffffe400) at iv_fd_epoll.c:131<br>#2 0x00007ffff7ba9837 in iv_fd_poll_and_run (st=0x605df0, to=0x7fffffffe400) at iv_fd.c:147<br>
#3 0x00007ffff7baa054 in iv_main () at iv_main_posix.c:117<br>#4 0x00007ffff7b8c517 in main_loop_run () at mainloop.c:736<br>#5 0x0000000000401641 in main (argc=1, argv=0x7fffffffe548) at main.c:267<br>(gdb) c<br>Continuing.<br>
Advancing patterndb current time because of timer tick; utc='1382204154'<br>Advancing patterndb current time because of timer tick; utc='1382204155'<br>Advancing patterndb current time because of timer tick; utc='1382204156'<br>
^C<br>Program received signal SIGINT, Interrupt.<br>0x00007ffff6544f03 in epoll_wait () from /lib64/libc.so.6<br>(gdb) bt<br>#0 0x00007ffff6544f03 in epoll_wait () from /lib64/libc.so.6<br>#1 0x00007ffff7baaecd in iv_fd_epoll_poll (st=0x605df0, active=0x7fffffffe3c0, to=0x7fffffffe400) at iv_fd_epoll.c:131<br>
#2 0x00007ffff7ba9837 in iv_fd_poll_and_run (st=0x605df0, to=0x7fffffffe400) at iv_fd.c:147<br>#3 0x00007ffff7baa054 in iv_main () at iv_main_posix.c:117<br>#4 0x00007ffff7b8c517 in main_loop_run () at mainloop.c:736<br>
#5 0x0000000000401641 in main (argc=1, argv=0x7fffffffe548) at main.c:267<br>(gdb) c<br>Continuing.<br>Advancing patterndb current time because of timer tick; utc='1382204161'<br>Advancing patterndb current time because of timer tick; utc='1382204162'<br>
Advancing patterndb current time because of timer tick; utc='1382204163'<br>Advancing patterndb current time because of timer tick; utc='1382204164'<br>^C<br>Program received signal SIGINT, Interrupt.<br>
0x00007ffff6544f03 in epoll_wait () from /lib64/libc.so.6<br>
(gdb) bt<br>#0 0x00007ffff6544f03 in epoll_wait () from /lib64/libc.so.6<br>#1 0x00007ffff7baaecd in iv_fd_epoll_poll (st=0x605df0, active=0x7fffffffe3c0, to=0x7fffffffe400) at iv_fd_epoll.c:131<br>#2 0x00007ffff7ba9837 in iv_fd_poll_and_run (st=0x605df0, to=0x7fffffffe400) at iv_fd.c:147<br>
#3 0x00007ffff7baa054 in iv_main () at iv_main_posix.c:117<br>#4 0x00007ffff7b8c517 in main_loop_run () at mainloop.c:736<br>#5 0x0000000000401641 in main (argc=1, argv=0x7fffffffe548) at main.c:267<br>(gdb) c<br>Continuing.<br>
<br><div><div><div class="gmail_extra"><br><br><div class="gmail_quote">On Sat, Oct 19, 2013 at 3:41 AM, Balazs Scheidler <span dir="ltr"><<a href="mailto:bazsi77@gmail.com" target="_blank">bazsi77@gmail.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><p dir="ltr">Can you make several snapshots? I mean let it run, break, backtrace and repeat this a number of times?<br>
</p>
<p dir="ltr">This backtrace shows that format-json calls the value pairs subsystem to iterate name value pairs. The question is where the infinite loop sits, that's why I would need to look at the backtrace a number of times.</p>
<p dir="ltr">Thanks in advance</p>
<div class="gmail_quote"><div><div>On Oct 18, 2013 4:06 PM, "Alexandre Biancalana" <<a href="mailto:biancalana@gmail.com" target="_blank">biancalana@gmail.com</a>> wrote:<br type="attribution">
</div></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div><div>
<div dir="ltr"><div class="gmail_extra"><br><div class="gmail_quote">On Fri, Oct 18, 2013 at 6:01 AM, Balazs Scheidler <span dir="ltr"><<a href="mailto:bazsi77@gmail.com" target="_blank">bazsi77@gmail.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><p dir="ltr">I remember a bug in that caused similar symptoms when the output template produced zero length strings.</p>
<p dir="ltr">That has been fixed though. But can you try that regardless?</p>
<p dir="ltr">Can you perhaps use gdb to check where it is spinning?</p>
<p dir="ltr">If not, I would need to reproduce it.</p></blockquote><div><br></div><div>It only happens when I parse log using patterndb mentioned earlier with format_json --scope nv-pairs.<br><br></div><div>Follow the gdb backtrace, let me know if you need anything else.<br>
</div><div><br>Program received signal SIGINT, Interrupt.<br>g_trash_stack_height (name=<value optimized out>, value=0x620d70 "10228", user_data=0x7fffffffe200) at /usr/include/glib-2.0/glib/gutils.h:413<br>
413 i++;<br>(gdb) bt<br>#0 g_trash_stack_height (name=<value optimized out>, value=0x620d70 "10228", user_data=0x7fffffffe200) at /usr/include/glib-2.0/glib/gutils.h:413<br>#1 vp_walker_name_split (name=<value optimized out>, value=0x620d70 "10228", user_data=0x7fffffffe200) at value-pairs.c:455<br>
#2 value_pairs_walker (name=<value optimized out>, value=0x620d70 "10228", user_data=0x7fffffffe200) at value-pairs.c:494<br>#3 0x00007ffff70a5876 in g_tree_foreach () from /lib64/libglib-2.0.so.0<br>#4 0x00007ffff7b9ae86 in value_pairs_foreach_sorted (vp=0x6d7590, func=0x7ffff7b9a840 <value_pairs_walker>, compare_func=<value optimized out>, msg=0x61f010, seq_num=0, user_data=0x7fffffffe200)<br>
at value-pairs.c:329<br>#5 0x00007ffff7b9afbf in value_pairs_walk (vp=0x6d7590, obj_start_func=<value optimized out>, process_value_func=<value optimized out>, obj_end_func=<value optimized out>, msg=0x61f010, seq_num=0,<br>
user_data=0x7fffffffe270) at value-pairs.c:534<br>#6 0x00007ffff3e5bca2 in tf_json_append (self=<value optimized out>, s=0x6d20c0, args=0x7fffffffe320, result=0x636c80) at format-json.c:193<br>#7 tf_json_call (self=<value optimized out>, s=0x6d20c0, args=0x7fffffffe320, result=0x636c80) at format-json.c:206<br>
#8 0x00007ffff7b98653 in log_template_append_format_with_context (self=0x6d8130, messages=0x7fffffffe3b8, num_messages=1, opts=0x6d7fa0, tz=1, seq_num=0, context_id=0x0, result=0x636c80) at templates.c:1234<br>#9 0x00007ffff7b988ff in log_template_append_format (self=<value optimized out>, lm=0x61f010, opts=<value optimized out>, tz=<value optimized out>, seq_num=<value optimized out>,<br>
context_id=<value optimized out>, result=0x636c80) at templates.c:1261<br>#10 0x00007ffff7b8b87c in log_writer_format_log (self=0x619740, lm=0x61f010, result=0x636c80) at logwriter.c:862<br>#11 0x00007ffff7b8c310 in log_writer_flush (self=0x619740, flush_mode=LW_FLUSH_NORMAL) at logwriter.c:1005<br>
#12 0x00007ffff7b8c48d in log_writer_work_perform (s=0x619740) at logwriter.c:129<br>#13 0x00007ffff7b8c4f8 in log_writer_io_flush_output (s=0x619740) at logwriter.c:209<br>#14 0x00007ffff7ba82ea in iv_run_tasks (st=0x605ba0) at iv_task.c:48<br>
#15 0x00007ffff7baa50c in iv_main () at iv_main_posix.c:106<br>#16 0x00007ffff7b8c9c7 in main_loop_run () at mainloop.c:736<br>#17 0x0000000000401641 in main ()<br>(gdb)<br> </div></div></div></div>
<br></div></div><div>______________________________________________________________________________<br>
Member info: <a href="https://lists.balabit.hu/mailman/listinfo/syslog-ng" target="_blank">https://lists.balabit.hu/mailman/listinfo/syslog-ng</a><br>
Documentation: <a href="http://www.balabit.com/support/documentation/?product=syslog-ng" target="_blank">http://www.balabit.com/support/documentation/?product=syslog-ng</a><br>
FAQ: <a href="http://www.balabit.com/wiki/syslog-ng-faq" target="_blank">http://www.balabit.com/wiki/syslog-ng-faq</a><br>
<br>
<br></div></blockquote></div>
<br>______________________________________________________________________________<br>
Member info: <a href="https://lists.balabit.hu/mailman/listinfo/syslog-ng" target="_blank">https://lists.balabit.hu/mailman/listinfo/syslog-ng</a><br>
Documentation: <a href="http://www.balabit.com/support/documentation/?product=syslog-ng" target="_blank">http://www.balabit.com/support/documentation/?product=syslog-ng</a><br>
FAQ: <a href="http://www.balabit.com/wiki/syslog-ng-faq" target="_blank">http://www.balabit.com/wiki/syslog-ng-faq</a><br>
<br>
<br></blockquote></div><br></div></div></div></div>
<br>______________________________________________________________________________<br>
Member info: <a href="https://lists.balabit.hu/mailman/listinfo/syslog-ng" target="_blank">https://lists.balabit.hu/mailman/listinfo/syslog-ng</a><br>
Documentation: <a href="http://www.balabit.com/support/documentation/?product=syslog-ng" target="_blank">http://www.balabit.com/support/documentation/?product=syslog-ng</a><br>
FAQ: <a href="http://www.balabit.com/wiki/syslog-ng-faq" target="_blank">http://www.balabit.com/wiki/syslog-ng-faq</a><br>
<br>
<br></blockquote></div>