Mailing List Archive

Duplicate entries
omething weird is happening with rsyslog.

The good news is I dont seem to lose anything even when the sub-morons
in charge of the network load a six month old firewall config when
they click the wrong button in the GUI.

The bad news is that, lately, I have been seeing duplicate entries in
the messages table but not in the other tables. At first I thought it
was beacause there might be a few machines still running both syslog
and rsyslog. However, I tracked doen and zapped the rogue syslog
processes and the problem still persists.

I know I'm a little down rev but I'd like to out off an upgrade unitl
after the next audit. However, if this is a "known issue" I'll
certainly upgrade and take whatever licks it costs.

Current config:

$ rsyslogd -v
rsyslogd 2.0.1, compiled with:
FEATURE_PTHREADS (dual-threading): Yes
FEATURE_REGEXP: Yes
FEATURE_LARGEFILE: Yes
FEATURE_NETZIP (message compression): Yes
SYSLOG_INET (Internet/remote support): Yes
FEATURE_GSSAPI (GSSAPI Kerberos 5 support): No
FEATURE_DEBUG (debug build, slow code): No

############### Server rsyslog.conf file #######################

$ModLoad MySQL

*.info;mail.none;authpriv.none;cron.none
>127.0.0.1,messages,syslogger,<password>

authpriv.* >127.0.0.1,secure,syslogger.<password>

mail.* -/var/log/maillog

cron.* /var/log/cron

*.emerg *

uucp,news.crit /var/log/spooler

local7.* /var/log/boot.log

###################### Host rsyslog.conf file #######################

*.info;mail.none;authpriv.none;cron.none /var/log/messages
*.info;mail.none;authpriv.none;cron.none @@scacisys01

auth,authpriv.* /var/log/secure
auth,authpriv.* @@scacisys01

# Log all the mail messages in one place.
mail.* -/var/log/maillog

cron.* /var/log/cron

*.emerg *

uucp,news.crit /var/log/spooler

local7.* /var/log/boot.log


--
Stephen Carville
Duplicate entries [ In reply to ]
Mhhh... I don't see anything bad nor have found any past reference to
duplicated messages. In later versions, this may (very unlinkely) happen
by intension to prevent message loss when a TCP connection breaks. This
was introduced to cope with the unreliability of TCP syslog:

http://blog.gerhards.net/2008/04/on-unreliability-of-plain-tcp-syslog.ht
ml

However, this is not in the version you have. Can you report anything
specific on the message duplication? Also, would it be an option to
upgrade to the latest v2-stable version (which is 2.0.5). Note that the
difference is only bug fixes, no new functionality is being added to v2.

Rainer

> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> bounces at lists.adiscon.com] On Behalf Of Stephen Carville
> Sent: Sunday, May 25, 2008 6:23 AM
> To: rsyslog-users
> Subject: [rsyslog] Duplicate entries
>
> omething weird is happening with rsyslog.
>
> The good news is I dont seem to lose anything even when the sub-morons
> in charge of the network load a six month old firewall config when
> they click the wrong button in the GUI.
>
> The bad news is that, lately, I have been seeing duplicate entries in
> the messages table but not in the other tables. At first I thought it
> was beacause there might be a few machines still running both syslog
> and rsyslog. However, I tracked doen and zapped the rogue syslog
> processes and the problem still persists.
>
> I know I'm a little down rev but I'd like to out off an upgrade unitl
> after the next audit. However, if this is a "known issue" I'll
> certainly upgrade and take whatever licks it costs.
>
> Current config:
>
> $ rsyslogd -v
> rsyslogd 2.0.1, compiled with:
> FEATURE_PTHREADS (dual-threading): Yes
> FEATURE_REGEXP: Yes
> FEATURE_LARGEFILE: Yes
> FEATURE_NETZIP (message compression): Yes
> SYSLOG_INET (Internet/remote support): Yes
> FEATURE_GSSAPI (GSSAPI Kerberos 5 support): No
> FEATURE_DEBUG (debug build, slow code): No
>
> ############### Server rsyslog.conf file #######################
>
> $ModLoad MySQL
>
> *.info;mail.none;authpriv.none;cron.none
> >127.0.0.1,messages,syslogger,<password>
>
> authpriv.*
> >127.0.0.1,secure,syslogger.<password>
>
> mail.* -
> /var/log/maillog
>
> cron.* /var/log/cron
>
> *.emerg *
>
> uucp,news.crit
> /var/log/spooler
>
> local7.*
> /var/log/boot.log
>
> ###################### Host rsyslog.conf file #######################
>
> *.info;mail.none;authpriv.none;cron.none /var/log/messages
> *.info;mail.none;authpriv.none;cron.none @@scacisys01
>
> auth,authpriv.* /var/log/secure
> auth,authpriv.* @@scacisys01
>
> # Log all the mail messages in one place.
> mail.* -/var/log/maillog
>
> cron.* /var/log/cron
>
> *.emerg *
>
> uucp,news.crit /var/log/spooler
>
> local7.* /var/log/boot.log
>
>
> --
> Stephen Carville
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
Duplicate entries [ In reply to ]
On Sun, May 25, 2008 at 1:57 AM, Rainer Gerhards
<rgerhards at hq.adiscon.com> wrote:

> However, this is not in the version you have. Can you report anything
> specific on the message duplication?

I used some network tools to watch the behavior between scacitf01-d
(clent) and scacisys01 (server).

$ netstat -atp (domain name removed for readability);

on scacisys01

tcp 0 0 scacisys01:shell scacitf01-d:57878 ESTABLISHED
26777/rsyslogd
tcp 0 0 scacisys01:shell scacitf01-d:57876 ESTABLISHED
26777/rsyslogd

on scacitf01-d

tcp 0 0 scacitf01-d:57878 scacisys01:shell ESTABLISHED
10387/rsyslogd
tcp 0 0 scacitf01-d:57876 scacisys01:shell ESTABLISHED
10387/rsyslogd

Should there be two connections?

For an ssh login, wireshark reports that the syslog server received
the following

from scacitf01-d:57876 :

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Connection from
10.212.166.26 port 46039

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Found matching RSA key:
a0:f6:2d:e7:4d:b8:c0:53:01:c6:b3:ce:63:16:05:4f

<38>May 25 07:35:26 scacitf01-d sshd[16156]: Postponed publickey for
stephen from 10.212.166.26 port 46039 ssh2

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Found matching RSA key:
a0:f6:2d:e7:4d:b8:c0:53:01:c6:b3:ce:63:16:05:4f

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Accepted publickey for
stephen from 10.212.166.26 port 46039 ssh2

and from scacitf01-d:57878:

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Connection from
10.212.166.26 port 46039

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Found matching RSA key:
a0:f6:2d:e7:4d:b8:c0:53:01:c6:b3:ce:63:16:05:4f

<38>May 25 07:35:26 scacitf01-d sshd[16156]: Postponed publickey for
stephen from 10.212.166.26 port 46039 ssh2

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Found matching RSA key:
a0:f6:2d:e7:4d:b8:c0:53:01:c6:b3:ce:63:16:05:4f

<38>May 25 07:35:26 scacitf01-d sshd[16155]: Accepted publickey for
stephen from 10.212.166.26 port 46039 ssh2

<86>May 25 07:35:26 scacitf01-d sshd[16155]: pam_unix(sshd:session):
session opened for user stephen by (uid=0)

So some message are being sent twice.

>Also, would it be an option to
> upgrade to the latest v2-stable version (which is 2.0.5). Note that the
> difference is only bug fixes, no new functionality is being added to v2.

Probably if it's only bug fixes.

--
Stephen Carville
Duplicate entries [ In reply to ]
It definitely seems to the mulitple connections. I change the client
configuration to funnel all the messages thru a single connection and
teh duplication stopped.

Before

*.info;mail.none;authpriv.none;cron.none /var/log/messages
*.info;mail.none;authpriv.none;cron.none @@scacisys01

authpriv.* /var/log/secure
authpriv.* @@scacisys01

After

*.info;mail.none;authpriv.none;cron.none /var/log/messages

authpriv.* /var/log/secure

*.info;auth,authpriv.*;mail.none;cron.none @@scacisys01

--
Stephen Carville
Duplicate entries [ In reply to ]
Hi Stephen,

If I understand you right, there was nothing wrong with rsyslog. You
instructed it to forward authpriv.none message to the remote host:

> *.info;mail.none;authpriv.none;cron.none @@scacisys01

And you also instructed it to also forward all authpriv messages to the
same host:

> authpriv.* @@scacisys01

That, of course, leads to authpriv.none message to be forwarded twice -
once by the first rule and another time by the second.

Please note that rule execution is serially. There is no interdependency
between rules. If a rule matches, the action is carried out. This is
context-free. Rsyslog doesn't care if another rule has the same action.
In this sample, it may be useful you did not intend what you configured,
but in most cases it would be hard to tell what your real intension
would be. So rather than trying the figure out the users intension,
rsyslog simply carries out what is configured ;)

The bottom line to keep in mind is that each rule is a separate unit of
execution.

HTH,
Rainer

> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> bounces at lists.adiscon.com] On Behalf Of Stephen Carville
> Sent: Sunday, May 25, 2008 9:10 PM
> To: rsyslog-users
> Subject: Re: [rsyslog] Duplicate entries
>
> It definitely seems to the mulitple connections. I change the client
> configuration to funnel all the messages thru a single connection and
> teh duplication stopped.
>
> Before
>
> *.info;mail.none;authpriv.none;cron.none /var/log/messages
> *.info;mail.none;authpriv.none;cron.none @@scacisys01
>
> authpriv.* /var/log/secure
> authpriv.* @@scacisys01
>
> After
>
> *.info;mail.none;authpriv.none;cron.none /var/log/messages
>
> authpriv.* /var/log/secure
>
> *.info;auth,authpriv.*;mail.none;cron.none @@scacisys01
>
> --
> Stephen Carville
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
Duplicate entries [ In reply to ]
On Sun, May 25, 2008 at 11:18 PM, Rainer Gerhards
<rgerhards at hq.adiscon.com> wrote:
> Hi Stephen,
>
> If I understand you right, there was nothing wrong with rsyslog. You
> instructed it to forward authpriv.none message to the remote host:
>
>> *.info;mail.none;authpriv.none;cron.none @@scacisys01
>
> And you also instructed it to also forward all authpriv messages to the
> same host:
>
>> authpriv.* @@scacisys01
>
> That, of course, leads to authpriv.none message to be forwarded twice -
> once by the first rule and another time by the second.

Doesn't authpriv.none mean send no authpriv messages? Since it is is
after the *.info it should take precedence. At least thats how I
understand the syslog rules to work.

In any case, I understand what I did wrong. I had *.info in one rule
and auth.* in another creating an overlap.

> Please note that rule execution is serially. There is no interdependency
> between rules. If a rule matches, the action is carried out. This is
> context-free. Rsyslog doesn't care if another rule has the same action.
> In this sample, it may be useful you did not intend what you configured,
> but in most cases it would be hard to tell what your real intension
> would be. So rather than trying the figure out the users intension,
> rsyslog simply carries out what is configured ;)
>
> The bottom line to keep in mind is that each rule is a separate unit of
> execution.

I cannot see any downside to putting them all on the same connection
so I'll leave it that way FTTB.

Thank your for you help

--
Stephen Carville
Duplicate entries [ In reply to ]
> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com [mailto:rsyslog-
> bounces at lists.adiscon.com] On Behalf Of Stephen Carville
> Sent: Tuesday, May 27, 2008 1:03 AM
> To: rsyslog-users
> Subject: Re: [rsyslog] Duplicate entries
>
> On Sun, May 25, 2008 at 11:18 PM, Rainer Gerhards
> <rgerhards at hq.adiscon.com> wrote:
> > Hi Stephen,
> >
> > If I understand you right, there was nothing wrong with rsyslog. You
> > instructed it to forward authpriv.none message to the remote host:
> >
> >> *.info;mail.none;authpriv.none;cron.none @@scacisys01
> >
> > And you also instructed it to also forward all authpriv messages to
> the
> > same host:
> >
> >> authpriv.* @@scacisys01
> >
> > That, of course, leads to authpriv.none message to be forwarded
twice
> -
> > once by the first rule and another time by the second.
>
> Doesn't authpriv.none mean send no authpriv messages? Since it is is
> after the *.info it should take precedence. At least thats how I
> understand the syslog rules to work.

I have to admit that this is probably the last bit of sysklogd code I
did never even look at ;) But you are right, this sounds like a bug.
I'll review the code once I am through with TLS.

> In any case, I understand what I did wrong. I had *.info in one rule
> and auth.* in another creating an overlap.
>
> > Please note that rule execution is serially. There is no
> interdependency
> > between rules. If a rule matches, the action is carried out. This is
> > context-free. Rsyslog doesn't care if another rule has the same
> action.
> > In this sample, it may be useful you did not intend what you
> configured,
> > but in most cases it would be hard to tell what your real intension
> > would be. So rather than trying the figure out the users intension,
> > rsyslog simply carries out what is configured ;)
> >
> > The bottom line to keep in mind is that each rule is a separate unit
> of
> > execution.
>
> I cannot see any downside to putting them all on the same connection
> so I'll leave it that way FTTB.

One connection is fine. The fewer rules you need, the better the
performance is :)

Rainer
>
> Thank your for you help
>
> --
> Stephen Carville
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog