problem receiving non-NULL terminated UDP messages
Hi, I have the same problem as someone 2 years ago (https://lists.balabit.hu/pipermail/syslog-ng/2003-September/005414.html) with UDP messages. Problem: My OpenWRT based wifi router messages are not recognized and written to file via syslog-ng-1.9.5. The configuration file constsits of single udp() source and destination to single file. Symptoms: I am running `./syslog-ng -F -v -d -e` and after receiving an UDP log message I get a log_reader_fd_prepare(); messages in console window, so that means that the packet has arrived. (also checked with tcpdump for that). Despite packet arrival nothing is written to log file. The udp message does not end with NULL character as expected in logreader.c/log_reader_iterate_buf() function. I scanned the RFC for that but there is not defined that the message must terminate with a NULL character. Workaround: (needs testing for side-efects) Replace in afsocket.c:425 line with self->reader = log_reader_new(... (self->flags & AFSOCKET_LOCAL) ? LR_LOCAL|LR_PKTTERM : LR_PKTTERM,...); (Insert fixed LR_PKTTERM flag) Debugging process and toughts: After a while debugging with gdb I noticed that logreader.c/log_reader_iterate_buf() does not recognise the incoming message because it is not terminated by a NULL or NL character. I noticed that there exists a flag LR_PKTTERM which is supposed to be used in UDP sources so I went after LR_PKTTERM flag. The only place that flag is set is in afsocket.c/afsocket_sc_init() function and only if socket is a DGRAM type. If you trace back you see that afsocket_sc_init() is used from afsocket_sc_new() which is used from afsocket_sd_process_connection() which is used from afsocket_sd_accept() which is used from afsocket_sd_init(). Let's stop now at afsocket_sd_init() function: If you look carefully you can notice that afsocket_sd_accept() function is used as callback _only_ if used in STREAM sockets and not DGRAM! For DGRAM sockets the reader is creaded by log_reader_new() and with flags set as `(self->flags & AFSOCKET_LOCAL) ? LR_LOCAL : 0`. That means that log_reader_iterate_buf() does not have LR_PKTTERM flag set and thus not extracting UDP message from my router. As I can see afsocket.c/afsocket_sc_init() function is not used by DGRAM connections at all thus LR_PKTTERM is never set. Thanks for patience :) Pinky
On Mon, 2005-07-25 at 22:05 +0200, e09f6a7593f8ae3994ea57e1117f67ec wrote:
Hi, I have the same problem as someone 2 years ago (https://lists.balabit.hu/pipermail/syslog-ng/2003-September/005414.html) with UDP messages.
Problem:
My OpenWRT based wifi router messages are not recognized and written to file via syslog-ng-1.9.5. The configuration file constsits of single udp() source and destination to single file.
Symptoms:
I am running `./syslog-ng -F -v -d -e` and after receiving an UDP log message I get a log_reader_fd_prepare(); messages in console window, so that means that the packet has arrived. (also checked with tcpdump for that). Despite packet arrival nothing is written to log file. The udp message does not end with NULL character as expected in logreader.c/log_reader_iterate_buf() function. I scanned the RFC for that but there is not defined that the message must terminate with a NULL character.
Workaround: (needs testing for side-efects)
Replace in afsocket.c:425 line with self->reader = log_reader_new(... (self->flags & AFSOCKET_LOCAL) ? LR_LOCAL|LR_PKTTERM : LR_PKTTERM,...); (Insert fixed LR_PKTTERM flag)
Thanks for the detailed problem report. I have added a different solution though, trying to merge the diverging code paths for SOCK_DGRAM and SOCK_STREAM. I've committed a fix to my tla archive, the snapshot for tomorrow should contain the fix, or you can apply the patch below to your tree directly. Can you please test if this one works (I've compile tested and slightly runtime tested and it seems to work fine). --- orig/src/afsocket.c +++ mod/src/afsocket.c @@ -191,7 +191,7 @@ afsocket_sc_init(LogPipe *s, GlobalConfi { AFSocketSourceConnection *self = (AFSocketSourceConnection *) s; - self->reader = log_reader_new(fd_read_new(self->sock, 0), + self->reader = log_reader_new(fd_read_new(self->sock, (self->owner->flags & AFSOCKET_DGRAM) ? FR_RECV : 0), (self->owner->flags & AFSOCKET_LOCAL) ? LR_LOCAL : 0 | (self->owner->flags & AFSOCKET_DGRAM) ? LR_PKTTERM : 0 | (self->owner->flags & AFSOCKET_PROTO_RFC3164) ? LR_STRICT : 0, @@ -218,7 +218,13 @@ afsocket_sc_queue(LogPipe *s, LogMessage AFSocketSourceConnection *self = (AFSocketSourceConnection *) s; if (!msg->saddr) - msg->saddr = g_sockaddr_ref(self->peer_addr); + { + if (self->peer_addr) + msg->saddr = g_sockaddr_ref(self->peer_addr); + else + msg_notice("Internal error, message without source address;", NULL); + } + log_pipe_queue(s->pipe_next, msg, path_flags); } @@ -302,6 +308,19 @@ afsocket_sd_set_max_connections(LogDrive self->max_connections = max_connections; } +static inline gchar * +afsocket_sd_format_persist_name(AFSocketSourceDriver *self, gboolean listener_name) +{ + static gchar persist_name[128]; + gchar buf[64]; + + g_snprintf(persist_name, sizeof(persist_name), + listener_name ? "afsocket_sd_listen_fd(%s,%s)" : "afsocket_sd_connections(%s,%s)", + !!(self->flags & AFSOCKET_STREAM) ? "stream" : "dgram", + g_sockaddr_format(self->bind_addr, buf, sizeof(buf))); + return persist_name; +} + gboolean afsocket_sd_process_connection(AFSocketSourceDriver *self, GSockAddr *peer_addr, gint fd) { @@ -371,32 +390,43 @@ gboolean afsocket_sd_init(LogPipe *s, GlobalConfig *cfg, PersistentConfig *persist) { AFSocketSourceDriver *self = (AFSocketSourceDriver *) s; - gchar persist_name[256], buf[128]; gint sock; + gboolean res = FALSE; log_reader_options_init(&self->reader_options, cfg); - g_snprintf(persist_name, sizeof(persist_name), - "afsocket_sd_listen_fd(%s,%s)", - !!(self->flags & AFSOCKET_STREAM) ? "stream" : "dgram", - g_sockaddr_format(self->bind_addr, buf, sizeof(buf))); - - /* NOTE: this assumes that fd 0 will never be used for listening fds, - * main.c opens fd 0 so this assumption can hold */ - - sock = GPOINTER_TO_UINT(persist_config_fetch(persist, persist_name)) - 1; - - if (sock == -1 && !afsocket_open_socket(self->bind_addr, !!(self->flags & AFSOCKET_STREAM), &sock)) + /* fetch persistent connections first */ + if ((self->flags & AFSOCKET_KEEP_ALIVE)) { - return FALSE; + GList *p; + + self->connections = persist_config_fetch(persist, afsocket_sd_format_persist_name(self, FALSE)); + for (p = self->connections; p; p = p->next) + { + log_pipe_append((LogPipe *) p->data, s); + } } + + /* ok, we have connection list, check if we need to open a listener */ + sock = -1; if (self->flags & AFSOCKET_STREAM) { GSource *source; - GList *p; + if (self->flags & AFSOCKET_KEEP_ALIVE) + { + /* NOTE: this assumes that fd 0 will never be used for listening fds, + * main.c opens fd 0 so this assumption can hold */ + sock = GPOINTER_TO_UINT(persist_config_fetch(persist, afsocket_sd_format_persist_name(self, TRUE))) - 1; + } + + if (sock == -1 && !afsocket_open_socket(self->bind_addr, !!(self->flags & AFSOCKET_STREAM), &sock)) + { + return FALSE; + } + - /* create listening source */ + /* set up listening source */ self->fd = sock; listen(sock, self->listen_backlog); @@ -407,26 +437,21 @@ afsocket_sd_init(LogPipe *s, GlobalConfi g_source_set_callback(source, afsocket_sd_accept, self, (GDestroyNotify) log_pipe_unref); self->source_id = g_source_attach(source, NULL); g_source_unref(source); - - /* fetch kept alive connections */ - - g_snprintf(persist_name, sizeof(persist_name), - "afsocket_sd_connections(%s)", - g_sockaddr_format(self->bind_addr, buf, sizeof(buf))); - self->connections = persist_config_fetch(persist, persist_name); - for (p = self->connections; p; p = p->next) - { - log_pipe_append((LogPipe *) p->data, s); - } } else { - self->fd = sock; - self->reader = log_reader_new(fd_read_new(sock, FR_RECV | FR_DONTCLOSE), (self->flags & AFSOCKET_LOCAL) ? LR_LOCAL : 0, &self->super.super, &self->reader_options); - log_pipe_append(self->reader, &self->super.super); - log_pipe_init(self->reader, NULL, NULL); + if (!(self->flags & AFSOCKET_KEEP_ALIVE) || !self->connections || !afsocket_open_socket(self->bind_addr, !!(self->flags & AFSOCKET_STREAM), &sock)) + { + /* we could not recover persistent listener and could not open one either */ + return FALSE; + } + self->fd = -1; + + /* we either have self->connections != NULL, or sock contains a new fd */ + if (self->connections || afsocket_sd_process_connection(self, NULL, sock)) + res = TRUE; } - return TRUE; + return res; } static void @@ -440,30 +465,32 @@ gboolean afsocket_sd_deinit(LogPipe *s, GlobalConfig *cfg, PersistentConfig *persist) { AFSocketSourceDriver *self = (AFSocketSourceDriver *) s; - gchar persist_name[256], buf[128]; - if (self->flags & AFSOCKET_STREAM) + if ((self->flags & AFSOCKET_KEEP_ALIVE) == 0 || !persist) { GList *p, *next; - - if ((self->flags & AFSOCKET_KEEP_ALIVE) == 0 || !persist) - { - for (p = self->connections; p; p = next) - { - next = p->next; - afsocket_sd_kill_connection((AFSocketSourceConnection *) p->data); - g_list_free_1(p); - } - } - else + + /* we don't store anything across HUPs */ + for (p = self->connections; p; p = next) { - - g_snprintf(persist_name, sizeof(persist_name), - "afsocket_sd_connections(%s)", - g_sockaddr_format(self->bind_addr, buf, sizeof(buf))); - persist_config_add(persist, persist_name, self->connections, (GDestroyNotify) afsocket_sd_kill_connection); + next = p->next; + afsocket_sd_kill_connection((AFSocketSourceConnection *) p->data); + g_list_free_1(p); } - self->connections = NULL; + } + else + { + /* for AFSOCKET_STREAM source drivers this is a list, for + * AFSOCKET_DGRAM this is a single connection */ + + persist_config_add(persist, afsocket_sd_format_persist_name(self, FALSE), self->connections, (GDestroyNotify) afsocket_sd_kill_connection); + } + self->connections = NULL; + + + if (self->flags & AFSOCKET_STREAM) + { + g_source_remove(self->source_id); self->source_id = 0; if ((self->flags & AFSOCKET_LISTENER_KEEP_ALIVE) == 0) @@ -473,27 +500,23 @@ afsocket_sd_deinit(LogPipe *s, GlobalCon NULL); close(self->fd); } + else + { + /* NOTE: the fd is incremented by one when added to persistent config + * as persist config cannot store NULL */ + + persist_config_add(persist, afsocket_sd_format_persist_name(self, TRUE), GUINT_TO_POINTER(self->fd + 1), afsocket_sd_close_fd); + } } else if (self->flags & AFSOCKET_DGRAM) { - log_pipe_deinit(self->reader, NULL, NULL); - log_pipe_unref(self->reader); - self->reader = NULL; - } - - if (self->flags & AFSOCKET_LISTENER_KEEP_ALIVE) - { - g_snprintf(persist_name, sizeof(persist_name), - "afsocket_sd_listen_fd(%s,%s)", - !!(self->flags & AFSOCKET_STREAM) ? "stream" : "dgram", - g_sockaddr_format(self->bind_addr, buf, sizeof(buf))); - - /* NOTE: the fd is incremented by one when added to persistent config - * as persist config cannot store NULL */ - - persist_config_add(persist, persist_name, GUINT_TO_POINTER(self->fd + 1), afsocket_sd_close_fd); + /* we don't need to close the listening fd here as we have a + * single connection which will close it */ + + ; } + return TRUE; } @@ -519,8 +542,6 @@ afsocket_sd_free_instance(AFSocketSource g_sockaddr_unref(self->bind_addr); self->bind_addr = NULL; - g_assert(!self->reader); - log_drv_free_instance(&self->super); } --- orig/src/afsocket.h +++ mod/src/afsocket.h @@ -45,7 +45,6 @@ struct _AFSocketSourceDriver guint32 flags; gint fd; guint source_id; - LogPipe *reader; LogReaderOptions reader_options; GSockAddr *bind_addr; -- Bazsi
Balazs Scheidler wrote:
Thanks for the detailed problem report. I have added a different solution though, trying to merge the diverging code paths for SOCK_DGRAM and SOCK_STREAM. I've committed a fix to my tla archive, the snapshot for tomorrow should contain the fix, or you can apply the patch below to your tree directly.
Can you please test if this one works (I've compile tested and slightly runtime tested and it seems to work fine).
I have compiled syslog-ng-1.9.5+20050730.tar.gz and it does not seems to work and it cannot open udp source. Debugging with a single udp() source: afsocket_sd_init (s=0x8067f38, cfg=0x8062a20, persist=0x0) at afsocket.c:403 self->connections = persist_config_fetch(persist, afsocket_sd_format_persist_name(self, FALSE)); self->connections is null due persist==0x0 afsocket.c:412 if (!(self->flags & AFSOCKET_KEEP_ALIVE) || !self->connections || !afsocket_open_s... bails out here self->flags = 0x701, self->connection=null self->flags & AFSOCKET_KEEP_ALIVE > 0, hmmm, udp keepalive? Note that persist if set to NULL at main.c:372 by calling cfg_init(cfg, NULL) If you need detailed program tracking I can make you one. Pinky
On Sat, 2005-07-30 at 14:22 +0200, e09f6a7593f8ae3994ea57e1117f67ec wrote:
Balazs Scheidler wrote:
Thanks for the detailed problem report. I have added a different solution though, trying to merge the diverging code paths for SOCK_DGRAM and SOCK_STREAM. I've committed a fix to my tla archive, the snapshot for tomorrow should contain the fix, or you can apply the patch below to your tree directly.
Can you please test if this one works (I've compile tested and slightly runtime tested and it seems to work fine).
I have compiled syslog-ng-1.9.5+20050730.tar.gz and it does not seems to work and it cannot open udp source.
Debugging with a single udp() source:
afsocket_sd_init (s=0x8067f38, cfg=0x8062a20, persist=0x0) at afsocket.c:403 self->connections = persist_config_fetch(persist, afsocket_sd_format_persist_name(self, FALSE)); self->connections is null due persist==0x0
afsocket.c:412 if (!(self->flags & AFSOCKET_KEEP_ALIVE) || !self->connections || !afsocket_open_s... bails out here self->flags = 0x701, self->connection=null self->flags & AFSOCKET_KEEP_ALIVE > 0, hmmm, udp keepalive?
Note that persist if set to NULL at main.c:372 by calling cfg_init(cfg, NULL)
Sorry, did a stupid mistake, I tested a previous copy of the syslog-ng binary and not the one which already contained the changes. However I've extended the preliminary functional test program to also cover tcp/udp message sending and added some more fixes. Tomorrow's snapshot should contain the changes. PS: let me know if a public Arch archive would be useful in addition to the daily snapshots. -- Bazsi
participants (2)
-
Balazs Scheidler
-
e09f6a7593f8ae3994ea57e1117f67ec