Re: logging via udp

2023-12-13 Thread Ondrej Zajicek
On Wed, Dec 13, 2023 at 02:59:47PM +0100, Alexander Zubkov wrote:
> > > And could you, please, also explain another moment:
> > > https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38#bc490dc797778621d2345fabe1fb0b59fce18264_141_179
> > > Here your free the sk resource. Maybe this is done exactly because of
> > > the io loop list, but I cannot find how sk_free() would remove the
> > > socket from sock_list. It seems to me it would still refer the socket
> > > after it is freed.
> >
> > sk_free() calls rem_node(>n) for non-SKF_THREAD sockets, so it would
> > remove it from sock_list anyway.
> 
> As it is SKF_THREAD, it is not relevant yet. But I see here fd is set
> to -1 before rfree():
> https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38#bc490dc797778621d2345fabe1fb0b59fce18264_141_179
> And sk_free() will not call rem_node() in this case:
> https://gitlab.nic.cz/labs/bird/-/blob/2c7555cf2ac8439713dd9148b348128c57222a38/sysdep/unix/io.c#L834
> I worry it can lead to a hidden error in the future.

You are right, it would be better to have some sk invalidationg function
that would set fd to -1 and unlink it, instead of doing that manually.

-- 
Elen sila lumenn' omentielvo

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


Re: logging via udp

2023-12-13 Thread Alexander Zubkov via Bird-users
Hi,

Thank you!

On Wed, Dec 13, 2023 at 2:35 PM Ondrej Zajicek  wrote:
>
> On Wed, Dec 13, 2023 at 11:50:42AM +0100, Alexander Zubkov wrote:
> > Hi,
> >
> > Thanks! I looked throught your version and it is unclear to me if the
> > sk is still added to the io loop list (sock_list) or not. It seems
> > that sk_insert() still should be called on log udp socket, because I
> > see no exception for it.
>
> Hi
>
> I use SKF_THREAD (like in your patch), so it is not inserted intoo sock_list.

Huh, now I see it clearly. :) Oversaw it, sorry.

>
> > And could you, please, also explain another moment:
> > https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38#bc490dc797778621d2345fabe1fb0b59fce18264_141_179
> > Here your free the sk resource. Maybe this is done exactly because of
> > the io loop list, but I cannot find how sk_free() would remove the
> > socket from sock_list. It seems to me it would still refer the socket
> > after it is freed.
>
> sk_free() calls rem_node(>n) for non-SKF_THREAD sockets, so it would
> remove it from sock_list anyway.

As it is SKF_THREAD, it is not relevant yet. But I see here fd is set
to -1 before rfree():
https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38#bc490dc797778621d2345fabe1fb0b59fce18264_141_179
And sk_free() will not call rem_node() in this case:
https://gitlab.nic.cz/labs/bird/-/blob/2c7555cf2ac8439713dd9148b348128c57222a38/sysdep/unix/io.c#L834
I worry it can lead to a hidden error in the future.

>
> The socket structure is freed because it is no longer needed,
> as the fd is tracked by the rfile structure anyway.

Yes, it seems OK. I just wasn't sure it is cleared properly.

>
> --
> Elen sila lumenn' omentielvo
>
> Ondrej 'Santiago' Zajicek (email: santi...@crfreenet.org)
> "To err is human -- to blame it on a computer is even more so."



Re: logging via udp

2023-12-13 Thread Ondrej Zajicek
On Wed, Dec 13, 2023 at 11:50:42AM +0100, Alexander Zubkov wrote:
> Hi,
> 
> Thanks! I looked throught your version and it is unclear to me if the
> sk is still added to the io loop list (sock_list) or not. It seems
> that sk_insert() still should be called on log udp socket, because I
> see no exception for it.

Hi

I use SKF_THREAD (like in your patch), so it is not inserted intoo sock_list.

> And could you, please, also explain another moment:
> https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38#bc490dc797778621d2345fabe1fb0b59fce18264_141_179
> Here your free the sk resource. Maybe this is done exactly because of
> the io loop list, but I cannot find how sk_free() would remove the
> socket from sock_list. It seems to me it would still refer the socket
> after it is freed.

sk_free() calls rem_node(>n) for non-SKF_THREAD sockets, so it would
remove it from sock_list anyway.

The socket structure is freed because it is no longer needed,
as the fd is tracked by the rfile structure anyway.

-- 
Elen sila lumenn' omentielvo

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


Re: logging via udp

2023-12-13 Thread Alexander Zubkov via Bird-users
Hi,

Thanks! I looked throught your version and it is unclear to me if the
sk is still added to the io loop list (sock_list) or not. It seems
that sk_insert() still should be called on log udp socket, because I
see no exception for it. Didn't you have the same problem with reloads
as I had? I unfortunately do not remember exactly how it looked like,
but I'll try to retest it.
And could you, please, also explain another moment:
https://gitlab.nic.cz/labs/bird/-/commit/2c7555cf2ac8439713dd9148b348128c57222a38#bc490dc797778621d2345fabe1fb0b59fce18264_141_179
Here your free the sk resource. Maybe this is done exactly because of
the io loop list, but I cannot find how sk_free() would remove the
socket from sock_list. It seems to me it would still refer the socket
after it is freed.
I would appreciate if you could explain thar to me for better
understanding the code.

Regards,
Alexander

On Wed, Dec 13, 2023 at 4:11 AM Ondrej Zajicek  wrote:
>
> 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  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  wrote:
> > > >
> > > > Hi,
> > > >
> > > > On Wed, Dec 18, 2019 at 1:01 PM Ondrej Zajicek  
> > > > 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  Reconfigured
> > > > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  Reconfiguring
> > > > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  Reconfigured
> > > >
> > > > * rsyslog 

Re: logging via udp

2023-12-12 Thread 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  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  wrote:
> > >
> > > Hi,
> > >
> > > On Wed, Dec 18, 2019 at 1:01 PM Ondrej Zajicek  
> > > 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  Reconfigured
> > > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  Reconfiguring
> > > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  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  Started
> > > Dec 18 21:51:41 2019-12-18 21: 51:41.273  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: santi...@crfreenet.org)
"To err is human -- to blame it on a computer is even more so."


Re: logging via udp

2022-01-02 Thread Alexander Zubkov
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.

On Sun, Jan 2, 2022 at 2:35 PM Alexander Zubkov  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  wrote:
> >
> > Hi,
> >
> > On Wed, Dec 18, 2019 at 1:01 PM Ondrej Zajicek  
> > 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  Reconfigured
> > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  Reconfiguring
> > Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  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  Started
> > Dec 18 21:51:41 2019-12-18 21: 51:41.273  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
> > logs.
> >
> > >
> > > One issue in the patch is that getaddrinfo() is blocking and could block
> > > for several seconds if you have unreachable DNS servers. The same issue
> > > is also in RPKI code, and we plan to add some asynchronous resolver, so
> > > no need to handle it in this patch.
> >
> > Yes, you are right. It can block in that place. But on the other hand
> > it is at reload only, i.e. at controllable points in time. And I also
> > hope that if I use plain IP address there, it will not use DNS for it.
> >
> > >
> > > We already experienced issues related to excsessive logging, another
> > > neat solution is to log to (length-limited) file on ramfs.
> > >
> > > --
> > > Elen sila lumenn' omentielvo
> > >
> > > Ondrej 'Santiago' Zajicek (email: santi...@crfreenet.org)
> > > OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net)
> > > "To err is human -- to blame it on a computer is even more so."


bird-log-udp.patch-v2
Description: Binary data


Re: logging via udp

2022-01-02 Thread Alexander Zubkov
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  wrote:
>
> Hi,
>
> On Wed, Dec 18, 2019 at 1:01 PM Ondrej Zajicek  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  Reconfigured
> Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  Reconfiguring
> Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  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  Started
> Dec 18 21:51:41 2019-12-18 21: 51:41.273  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
> logs.
>
> >
> > One issue in the patch is that getaddrinfo() is blocking and could block
> > for several seconds if you have unreachable DNS servers. The same issue
> > is also in RPKI code, and we plan to add some asynchronous resolver, so
> > no need to handle it in this patch.
>
> Yes, you are right. It can block in that place. But on the other hand
> it is at reload only, i.e. at controllable points in time. And I also
> hope that if I use plain IP address there, it will not use DNS for it.
>
> >
> > We already experienced issues related to excsessive logging, another
> > neat solution is to log to (length-limited) file on ramfs.
> >
> > --
> > Elen sila lumenn' omentielvo
> >
> > Ondrej 'Santiago' Zajicek (email: santi...@crfreenet.org)
> > OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net)
> > "To err is human -- to blame it on a computer is even more so."
commit cbc332b64149ed67af5e2d0d2f9f3ab2f78f708b
Author: Alexander Zubkov 
Date:   Sun Jan 2 14:14:49 2022 +0100

Log: add udp log destination

Add UDP log destination, which can be configured with:

log udp ["hostname"|] [] ;

diff --git a/lib/socket.h b/lib/socket.h
index 96fedeeb..642a56ce 100644
--- a/lib/socket.h
+++ b/lib/socket.h
@@ -84,6 +84,7 @@ typedef struct birdsock {
 sock *sock_new(pool *);			/* Allocate new socket */
 #define sk_new(X) sock_new(X)		/* Wrapper to avoid name collision with OpenSSL */
 
+int sk_hostname_autoresolv(sock *);	/* Auto-resolve an IP address from a hostname */
 int sk_open(sock *);			/* Open socket */
 int sk_rx_ready(sock *s);
 int sk_send(sock *, uint len);		/* Send 

Re: logging via udp

2019-12-18 Thread Alexander Zubkov
Hi,

On Wed, Dec 18, 2019 at 1:01 PM Ondrej Zajicek  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  Reconfigured
Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  Reconfiguring
Dec 18 21:17:09 127.0.0.1 2019-12-18 21:17:09.090  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  Started
Dec 18 21:51:41 2019-12-18 21: 51:41.273  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
logs.

>
> One issue in the patch is that getaddrinfo() is blocking and could block
> for several seconds if you have unreachable DNS servers. The same issue
> is also in RPKI code, and we plan to add some asynchronous resolver, so
> no need to handle it in this patch.

Yes, you are right. It can block in that place. But on the other hand
it is at reload only, i.e. at controllable points in time. And I also
hope that if I use plain IP address there, it will not use DNS for it.

>
> We already experienced issues related to excsessive logging, another
> neat solution is to log to (length-limited) file on ramfs.
>
> --
> Elen sila lumenn' omentielvo
>
> Ondrej 'Santiago' Zajicek (email: santi...@crfreenet.org)
> OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net)
> "To err is human -- to blame it on a computer is even more so."


Re: logging via udp

2019-12-18 Thread Ondrej Zajicek
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?

One issue in the patch is that getaddrinfo() is blocking and could block
for several seconds if you have unreachable DNS servers. The same issue
is also in RPKI code, and we plan to add some asynchronous resolver, so
no need to handle it in this patch.

We already experienced issues related to excsessive logging, another
neat solution is to log to (length-limited) file on ramfs.

-- 
Elen sila lumenn' omentielvo

Ondrej 'Santiago' Zajicek (email: santi...@crfreenet.org)
OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net)
"To err is human -- to blame it on a computer is even more so."


signature.asc
Description: PGP signature