logging via udp

[Ondrej Zajicek]

On Sun, Jan 02, 2022 at 04:58:33PM +0100, Alexander Zubkov wrote:
> Updated my last patch. I found a problem with that version, it hang on
> reconfigure sometimes. It turned out that birdsocks are added to the
> loop poll and it caused problems. Fixed that with SKF_THREAD flag, but
> that may be a bit tricky. Also found myself that there is already a
> structure for log config. And I also now do not abuse sk_write()
> function for this patch, because it may be not suitable for that.

Hi

Finally got to merge that patch. :-)

Replaced the unformatted output with RFC 3164 syslog format, so it is
properly parsed by rsyslog (and hopefully others), also made some
cleanups, restructuring and bugfixes.

https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38


> On Sun, Jan 2, 2022 at 2:35 PM Alexander Zubkov <green at qrator.net> wrote:
> >
> > Hi,
> >
> > Is there reason agains adding udp log destination in bird? I have in
> > attachmealsont a reworked version of the patch.
> > This version does not use direct socket interface, but extends
> > birdsock API for its needs. It also should not call (and possibly
> > block) getaddrinfo() in case when plain IP is specified.
> > It is a bit hacky - it uses birdsock to bind and connect the socket,
> > then "steals" its file descriptor for rfile. But it shoud close
> > correctly as I understand.
> > And I'm not sure about my implementation using "log_udp_cfg" variable
> > in the parser to gather configuration. Maybe it is not "safe" and it
> > should not be global, but some space in pool should be allocated for
> > it each time.
> > There are other decisions, I'm not sure about. So if anything is bad -
> > I can try to update it.
> >
> > On Wed, Dec 18, 2019 at 8:15 PM Alexander Zubkov <green at qrator.net> wrote:
> > >
> > > Hi,
> > >
> > > On Wed, Dec 18, 2019 at 1:01 PM Ondrej Zajicek <santiago at crfreenet.org> wrote:
> > > >
> > > > On Wed, Dec 18, 2019 at 09:14:43AM +0100, Alexander Zubkov wrote:
> > > > > Hello,
> > > > >
> > > > > Made some dirty patch for myself to allow bird to send logs via udp.
> > > > > But it may be useful not only for me, so posting it here. It could be
> > > > > useful when server experiencing high IO-load. As syslog and file
> > > > > operations in bird are blocking, it can be blocked on writing to it
> > > > > for indefinite time, which could lead to various problems like
> > > > > protocol timeouts. So udp logging comes in handy here. The tradeoff is
> > > > > that we can miss some logs if they are not processed in time.
> > > > > You can specify udp log destination like that:
> > > > > log udp [host IP|"hostname"] [port NUMBER|"portname"] ...
> > > >
> > > > Hello
> > > >
> > > > Is this compatible with some standard for UDP logging or with other
> > > > infrastructure (log deamons), or you just collect it using netcat?
> > >
> > > Not sure if it is standard now. And message format could be relatively
> > > easily converted into one. That is one of the reasons the patch is
> > > dirty. :)
> > > From my experience syslog servers are mostly ok with non formatted
> > > plain text udp messages with some issues, which are more or less
> > > severe depending on what you do with these logs later. For example
> > > just tested couple of them:
> > >
> > > * syslog-ng with simple source config:
> > >
> > > source s_net { network(ip(127.0.0.1) transport(udp) port(514)); };
> > >
> > > It most cases it takes the message from packet, prepends it with
> > > timestamp and hostname (ip) from which the packet was received. There
> > > are several options of how to parse messages, though. I get logs like
> > > those with syslog-ng:
> > >
> > > Dec 18 21:16:51 127.0.0.1 2019-12-18 21:16:51.773 <INFO> Reconfigured
> > > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090 <INFO> Reconfiguring
> > > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090 <INFO> Reconfigured
> > >
> > > * rsyslog with simple udp config:
> > >
> > > module(load="imudp")
> > > input(type="imudp" address="127.0.0.1" port="514")
> > >
> > > It is also mostly ok with plaintext messages, it prepends them with
> > > timestamp, but it tries to parse first field of the message as a
> > > hostname. I get logs like those with rsyslog:
> > >
> > > Dec 18 21:51:27 2019-12-18 21: 51:27.917 <INFO> Started
> > > Dec 18 21:51:41 2019-12-18 21: 51:41.273 <INFO> Reconfiguring
> > >
> > > There can also be issues with message splitting. If message is cut
> > > into two packets or several messages are there in one packet. This
> > > should be also taken into consideration when we look at the resulting

-- 
Elen sila lumenn' omentielvo

Ondrej 'Santiago' Zajicek (email: santiago at crfreenet.org)
"To err is human -- to blame it on a computer is even more so."