[syslog-ng] I have a question
Roberto Nibali
ratz at drugphish.ch
Wed Sep 21 01:40:22 CEST 2005
> This indeed is a bit strange as -HUP should not kill the process per se
> with regard to syslog-ng. I've just tested this and and if I do it by
> hand the syslog-ng process is indeed killed by this, although not all
> the time. Some short time digging reveiled following:
It's actually 100% reproducable, so I spent 1 hour looking at this. I've
suspected an internal glib error first but this is not the case. I am
now using the newest glib-2.8.1 (earlier using glib-2.2.3), plus I have
added some debugging code and some implicit g_string_sized_new() calls:
Files syslog-ng-1.9.5+20050921/doc/reference/syslog-ng.html.tar.gz and
syslog-ng-1.9.5+20050920-ratz/doc/reference/syslog-ng.html.tar.gz differ
diff -ur syslog-ng-1.9.5+20050921/src/afinter.c
syslog-ng-1.9.5+20050920-ratz/src/afinter.c
--- syslog-ng-1.9.5+20050921/src/afinter.c 2005-09-21 00:11:46.000000000
+0200
+++ syslog-ng-1.9.5+20050920-ratz/src/afinter.c 2005-09-21
00:55:29.904839541 +0200
@@ -26,6 +26,10 @@
#include "messages.h"
+/* ratz */
+#include <stdio.h>
+#include <stdlib.h>
+
extern GQueue *internal_msg_queue;
static gboolean
@@ -68,6 +72,10 @@
static void
afinter_source_dispatch_msg(LogPipe *pipe, LogMessage *msg)
{
+ msg->host = g_string_sized_new(30);
+ g_string_assign(msg->host, "Too many callbacks ;)");
+ fprintf(stderr, "%s:%d (val=%s len=%d)\n", __FILE__, __LINE__,
+ msg->host->str, msg->host->len);
log_pipe_queue(pipe, msg, 0);
}
diff -ur syslog-ng-1.9.5+20050921/src/logwriter.c
syslog-ng-1.9.5+20050920-ratz/src/logwriter.c
--- syslog-ng-1.9.5+20050921/src/logwriter.c 2005-09-21
00:11:47.000000000 +0200
+++ syslog-ng-1.9.5+20050920-ratz/src/logwriter.c 2005-09-21
00:52:40.761085687 +0200
@@ -29,6 +29,10 @@
#include <unistd.h>
#include <assert.h>
+/* ratz */
+#include <stdio.h>
+#include <stdlib.h>
+
typedef struct _LogWriterWatch
{
GSource super;
diff -ur syslog-ng-1.9.5+20050921/src/messages.c
syslog-ng-1.9.5+20050920-ratz/src/messages.c
--- syslog-ng-1.9.5+20050921/src/messages.c 2005-09-21
00:11:43.000000000 +0200
+++ syslog-ng-1.9.5+20050920-ratz/src/messages.c 2005-09-21
00:55:50.283712086 +0200
@@ -54,6 +54,7 @@
LogMessage *m;
g_snprintf(buf, sizeof(buf), "<%d> syslog-ng[%d]: %s\n", prio,
getpid(), msg);
+ fprintf(stderr, "%s:%d: (msg=%s)\n", __FILE__, __LINE__, buf);
m = log_msg_new(buf, strlen(buf), NULL, LP_INTERNAL | LP_LOCAL);
g_queue_push_tail(internal_msg_queue, m);
}
diff -ur syslog-ng-1.9.5+20050921/src/sgroup.c
syslog-ng-1.9.5+20050920-ratz/src/sgroup.c
--- syslog-ng-1.9.5+20050921/src/sgroup.c 2005-09-21 00:11:43.000000000
+0200
+++ syslog-ng-1.9.5+20050920-ratz/src/sgroup.c 2005-09-21
00:55:08.479179283 +0200
@@ -27,6 +27,10 @@
#include <time.h>
+/* ratz */
+#include <stdio.h>
+#include <stdlib.h>
+
static gboolean
log_source_group_init(LogPipe *s, GlobalConfig *cfg, PersistentConfig
*persist)
{
@@ -84,6 +88,8 @@
GString *name;
name = resolve_hostname(msg->saddr, self->use_dns, self->use_fqdn);
+ fprintf(stderr, "%s:%d (val=%s len=%d)\n", __FILE__, __LINE__,
+ name->str, name->len);
if (self->chain_hostnames)
{
if (msg->flags & LF_LOCAL)
@@ -102,7 +108,10 @@
if (msg->host->len)
g_string_sprintfa(msg->host, "/%s", name->str);
else
+ msg->host = g_string_sized_new(name->len);
g_string_assign(msg->host, name->str);
+ fprintf(stderr, "%s:%d (val=%s len=%d)\n", __FILE__,
__LINE__,
+ msg->host->str, msg->host->len);
}
}
else
Due to the 'msg->host = g_string_sized_new(name->len)' the trace stop
later now and looks different:
webphish:~ # /sbin/syslog-ng-1.9.5 -v -d -d -F
messages.c:57: (msg=<5> syslog-ng[31639]: syslog-ng starting up;
version='1.9.5'
)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
messages.c:57: (msg=<5> syslog-ng[31639]: Initializing destination file
writer; filename='/var/log/allmessages', template='/var/log/allmessages'
)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
[here the killall -HUP will be sent]
messages.c:57: (msg=<5> syslog-ng[31639]: SIGHUP received, reloading
configuration;
)
messages.c:57: (msg=<5> syslog-ng[31639]: Closing log reader fd; fd='3'
)
messages.c:57: (msg=<5> syslog-ng[31639]: Closing log reader fd; fd='4'
)
messages.c:57: (msg=<5> syslog-ng[31639]: Closing log reader fd; fd='5'
)
messages.c:57: (msg=<5> syslog-ng[31639]: Closing log writer fd; fd='6'
)
messages.c:57: (msg=<5> syslog-ng[31639]: New configuration initialized;
)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
messages.c:57: (msg=<5> syslog-ng[31639]: Initializing destination file
writer; filename='/var/log/allmessages', template='/var/log/allmessages'
)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
afinter.c:77 (val=Too many callbacks ;) len=21)
sgroup.c:91 (val=webphish len=8)
Segmentation fault (core dumped)
webphish:~ # gdb -q /sbin/syslog-ng-1.9.5 ./core
Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `/sbin/syslog-ng-1.9.5 -v -d -d -F'.
Program terminated with signal 11, Segmentation fault.
warning: current_sos: Can't read pathname for load map: Input/output error
Reading symbols from /lib/libnsl.so.1...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /usr/local/lib/libglib-2.0.so.0...done.
Loaded symbols for /usr/local/lib/libglib-2.0.so.0
Reading symbols from /usr/local/lib/libiconv.so.2...done.
Loaded symbols for /usr/local/lib/libiconv.so.2
Reading symbols from /usr/local/lib/libevtlog.so.0...done.
Loaded symbols for /usr/local/lib/libevtlog.so.0
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
#0 0x08054cef in log_writer_format_log (self=0x8067eb8, lm=0x806c028,
result=0x807246c) at logwriter.c:216
216 g_string_sprintf(result, "%s %s %s\n", ts->str,
lm->host->str, lm->msg->str);
(gdb) bt
#0 0x08054cef in log_writer_format_log (self=0x8067eb8, lm=0x806c028,
result=0x807246c) at logwriter.c:216
#1 0x08054ed0 in log_writer_flush_log (self=0x8067eb8, fd=0x8066920)
at logwriter.c:280
#2 0x08054a15 in log_writer_fd_dispatch (source=0x8068f70, callback=0,
user_data=0x0) at logwriter.c:98
#3 0x4006e44e in IA__g_main_context_dispatch (context=0x80627c8)
at gmain.c:1934
#4 0x4007073b in g_main_context_iterate (context=Variable "context" is
not available.
) at gmain.c:2565
#5 0x40070825 in IA__g_main_context_iteration (context=Variable
"context" is not available.
) at gmain.c:2624
#6 0x0804b00e in main_loop_run (cfg=0x8070b28) at main.c:142
#7 0x0804b5de in main (argc=5, argv=0xbffff344) at main.c:387
(gdb) list *0x08054cef
0x8054cef is in log_writer_format_log (logwriter.c:216).
211 ts_free = FALSE;
212 ts = lm->date;
213 }
214 if (self->flags & LW_FORMAT_FILE)
215 {
216 g_string_sprintf(result, "%s %s %s\n", ts->str,
lm->host->str, lm->msg->str);
217
218 }
219 else if (self->flags & LW_FORMAT_PROTO)
220 {
(gdb) q
webphish:~ #
I'm a bit out of ideas right now. It looks like some uninitialised
G_Strings in the LogMessage struct after cfg reload but this is a wild
guess.
Bazsi, the code is still very hard to read (too many callbacks, too
deply nested, too much OOA/OOD for C), but a lot better than 1.6.x :).
There's still a few places which need explanation and/or code.
Generally, what would you think about a patch which updates all the
deprecated glib functions in the syslog-ng-1.9.x tree to the actually
preferred ones? What comes to mind are things like g_string_sprintf(),
g_main_iteration() or g_main_new() ...
Oh, and I have used a simple config without filter targets:
options {
long_hostnames(off);
sync(0);
};
source src {
internal();
unix-dgram("/dev/log");
};
destination allmessages {
file("/var/log/allmessages");
};
log {
source(src);
destination(allmessages);
};
If I configure some filters, the backtrace of the core file looks as
follows:
webphish:~ # gdb -q /sbin/syslog-ng-1.9.5 ./core
Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `/sbin/syslog-ng-1.9.5 -v -d -d -F'.
Program terminated with signal 11, Segmentation fault.
warning: current_sos: Can't read pathname for load map: Input/output error
Reading symbols from /lib/libnsl.so.1...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /usr/local/lib/libglib-2.0.so.0...done.
Loaded symbols for /usr/local/lib/libglib-2.0.so.0
Reading symbols from /usr/local/lib/libiconv.so.2...done.
Loaded symbols for /usr/local/lib/libiconv.so.2
Reading symbols from /usr/local/lib/libevtlog.so.0...done.
Loaded symbols for /usr/local/lib/libevtlog.so.0
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
#0 0x0804ebcb in filter_match_eval (s=0x8073108, msg=0x806f8a0)
at filter.c:293
293 return filter_re_eval((FilterRE *) s, msg->msg->str);
(gdb) bt
#0 0x0804ebcb in filter_match_eval (s=0x8073108, msg=0x806f8a0)
at filter.c:293
#1 0x0804ed5d in filter_expr_eval (self=0x8073108, msg=0x806f8a0)
at filter.h:57
#2 0x0804e724 in fop_and_eval (s=0x8073380, msg=0x806f8a0) at filter.c:113
#3 0x0804e575 in filter_expr_eval (self=0x8073380, msg=0x806f8a0)
at filter.h:57
#4 0x0804e3c4 in log_center_queue (s=0x8072668, msg=0x806f8a0,
path_flags=0)
at center.c:346
#5 0x080545db in log_pipe_queue (s=0x8072668, msg=0x806f8a0, path_flags=0)
at logpipe.h:72
#6 0x08054507 in log_source_group_queue (s=0x8072b40, msg=0x806f8a0,
path_flags=0) at sgroup.c:133
#7 0x0804daae in log_pipe_queue (s=0x8072b40, msg=0x806f8a0, path_flags=0)
at logpipe.h:72
#8 0x0804da70 in log_pipe_forward_msg (self=0x80727d8, msg=0x806f8a0,
path_flags=0) at logpipe.c:66
#9 0x08058d54 in log_pipe_queue (s=0x80727d8, msg=0x806f8a0, path_flags=0)
at logpipe.h:72
#10 0x08058cab in log_source_queue (s=0x8072748, msg=0x806f8a0,
path_flags=0)
at logsource.c:49
#11 0x080588cb in log_pipe_queue (s=0x8072748, msg=0x806f8a0, path_flags=0)
at logpipe.h:72
#12 0x08058640 in afinter_source_dispatch_msg (pipe=0x8072748,
msg=0x806f8a0)
at afinter.c:79
#13 0x080585c3 in afinter_source_dispatch (source=0x8062778,
callback=0x80585d2 <afinter_source_dispatch_msg>, user_data=0x8072748)
at afinter.c:55
#14 0x4006e44e in IA__g_main_context_dispatch (context=0x80627c8)
at gmain.c:1934
#15 0x4007073b in g_main_context_iterate (context=Variable "context" is
not available.
) at gmain.c:2565
#16 0x40070825 in IA__g_main_context_iteration (context=Variable
"context" is not available.
) at gmain.c:2624
#17 0x0804b00e in main_loop_run (cfg=0x80725b8) at main.c:142
#18 0x0804b5de in main (argc=5, argv=0xbffff344) at main.c:387
(gdb) list *0x0804ebcb
0x804ebcb is in filter_match_eval (filter.c:293).
288 }
289
290 static gboolean
291 filter_match_eval(FilterExprNode *s, LogMessage *msg)
292 {
293 return filter_re_eval((FilterRE *) s, msg->msg->str);
294 }
295
296 FilterExprNode *
297 filter_match_new(gchar *re)
(gdb) q
Thanks and best regards,
Roberto Nibali, ratz
--
echo
'[q]sa[ln0=aln256%Pln256/snlbx]sb3135071790101768542287578439snlbxq' | dc
More information about the syslog-ng
mailing list