Mailing List Archive

per programname logs
I'm trying to get rsyslog to log each programname to separate logfiles,
so I have:

$template PerAppLogs,"/var/log/rsyslog/apps/%programname%.log"
*.* -?PerAppLogs

This seems to show a couple of problems with %programname%. It will be set
to a bit strange strings for some of the messages:

1.4.1.log:
Aug 27 21:58:01 syslogd 1.4.1: restart.
Aug 27 21:58:01 syslogd 1.4.1: restart.
Aug 27 21:58:01 syslogd 1.4.1: restart.

message.log:
Aug 27 22:02:48 last message repeated 12 times
Aug 27 22:02:49 last message repeated 6 times
Aug 27 22:02:49 last message repeated 92 times


Not sure who's to blame..


-jf
per programname logs [ In reply to ]
Can you let us know which strings it is set to? That would definitely
help troubleshooting (one lab less to do ;)).

Thanks,
Rainer

> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com
> [mailto:rsyslog-bounces at lists.adiscon.com] On Behalf Of
> Jan-Frode Myklebust
> Sent: Monday, August 27, 2007 10:08 PM
> To: rsyslog at lists.adiscon.com
> Subject: [rsyslog] per programname logs
>
> I'm trying to get rsyslog to log each programname to separate
> logfiles,
> so I have:
>
> $template PerAppLogs,"/var/log/rsyslog/apps/%programname%.log"
> *.* -?PerAppLogs
>
> This seems to show a couple of problems with %programname%.
> It will be set
> to a bit strange strings for some of the messages:
>
> 1.4.1.log:
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
>
> message.log:
> Aug 27 22:02:48 last message repeated 12 times
> Aug 27 22:02:49 last message repeated 6 times
> Aug 27 22:02:49 last message repeated 92 times
>
>
> Not sure who's to blame..
>
>
> -jf
>
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
>
per programname logs [ In reply to ]
On 2007-08-27, Jan-Frode Myklebust <janfrode at tanso.net> wrote:
>
> 1.4.1.log:
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
>
> message.log:
> Aug 27 22:02:48 last message repeated 12 times
> Aug 27 22:02:49 last message repeated 6 times
> Aug 27 22:02:49 last message repeated 92 times

BTW, the same happens for per-host template:

$template DailyPerHostLogs,"/var/log/syslog/%$YEAR%/%$MONTH%/%$DAY%/%HOSTNAME%.log"
*.* -?DailyPerHostLogs

which interprets the above as coming from %HOSTNAME% "syslogd" and "last",
and therefore gives me the logfiles last.log and syslogd.log.


-jf
per programname logs [ In reply to ]
On 2007-08-27, Rainer Gerhards <rgerhards at hq.adiscon.com> wrote:
> Can you let us know which strings it is set to? That would definitely
> help troubleshooting (one lab less to do ;)).

Not sure what you're asking.. I have this rsyslog.conf entry:

$template PerAppLogs,"/var/log/rsyslog/apps/%programname%.log"
*.* -?PerAppLogs

which produce two log files "1.4.1.log" and "message.log" containing

Aug 27 21:58:01 syslogd 1.4.1: restart.
Aug 27 21:58:01 syslogd 1.4.1: restart.
Aug 27 21:58:01 syslogd 1.4.1: restart.

Aug 27 22:02:48 last message repeated 12 times
Aug 27 22:02:49 last message repeated 6 times
Aug 27 22:02:49 last message repeated 92 times

respectively. I think that's all information I have.. plus maybe also
say that the remote host logging this is likely RHEL3, RHEL4 or RHEL5
with sysklogd sending the logs over standard udp (*.* @loghost).

Another thing that scared me a bit is that from the same template I
got a logfile named ".log" containing:

Aug 27 22:00:01 censored1.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
Aug 27 22:00:01 censored2.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
Aug 27 22:00:02 censored3.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
Aug 27 22:00:17 censored4.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
Aug 27 22:00:17 censored5.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save

which makes me think it tried to create the file /usr/bin/sudo.log..
Wonder if it might be possible to make rsyslogd overwrite /etc/passwd
with a sufficientlty crafted %programname% string...


-jf
per programname logs [ In reply to ]
Good points and I probably see the reason for the internal messages. I
just happen to be on the road this week without access to the code. Will
fix next week.

Also, you are right that using the properties in file name generation
without further sanitizing is not a good thing. There needs to be
created a solution.

Rainer

> -----Original Message-----
> From: rsyslog-bounces at lists.adiscon.com
> [mailto:rsyslog-bounces at lists.adiscon.com] On Behalf Of
> Jan-Frode Myklebust
> Sent: Monday, August 27, 2007 11:07 PM
> To: rsyslog at lists.adiscon.com
> Subject: Re: [rsyslog] per programname logs
>
> On 2007-08-27, Rainer Gerhards <rgerhards at hq.adiscon.com> wrote:
> > Can you let us know which strings it is set to? That would
> definitely
> > help troubleshooting (one lab less to do ;)).
>
> Not sure what you're asking.. I have this rsyslog.conf entry:
>
> $template PerAppLogs,"/var/log/rsyslog/apps/%programname%.log"
> *.* -?PerAppLogs
>
> which produce two log files "1.4.1.log" and "message.log" containing
>
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
>
> Aug 27 22:02:48 last message repeated 12 times
> Aug 27 22:02:49 last message repeated 6 times
> Aug 27 22:02:49 last message repeated 92 times
>
> respectively. I think that's all information I have.. plus maybe also
> say that the remote host logging this is likely RHEL3, RHEL4 or RHEL5
> with sysklogd sending the logs over standard udp (*.* @loghost).
>
> Another thing that scared me a bit is that from the same template I
> got a logfile named ".log" containing:
>
> Aug 27 22:00:01 censored1.domain.mgmt /usr/bin/sudo djksjdks
> : TTY=unknown ; PWD=/home/djksjdks ; USER=root ;
> COMMAND=/sbin/iptables-save
> Aug 27 22:00:01 censored2.domain.mgmt /usr/bin/sudo djksjdks
> : TTY=unknown ; PWD=/home/djksjdks ; USER=root ;
> COMMAND=/sbin/iptables-save
> Aug 27 22:00:02 censored3.domain.mgmt /usr/bin/sudo djksjdks
> : TTY=unknown ; PWD=/home/djksjdks ; USER=root ;
> COMMAND=/sbin/iptables-save
> Aug 27 22:00:17 censored4.domain.mgmt /usr/bin/sudo djksjdks
> : TTY=unknown ; PWD=/home/djksjdks ; USER=root ;
> COMMAND=/sbin/iptables-save
> Aug 27 22:00:17 censored5.domain.mgmt /usr/bin/sudo djksjdks
> : TTY=unknown ; PWD=/home/djksjdks ; USER=root ;
> COMMAND=/sbin/iptables-save
>
> which makes me think it tried to create the file /usr/bin/sudo.log..
> Wonder if it might be possible to make rsyslogd overwrite /etc/passwd
> with a sufficientlty crafted %programname% string...
>
>
> -jf
>
> _______________________________________________
> rsyslog mailing list
> http://lists.adiscon.net/mailman/listinfo/rsyslog
>
per programname logs [ In reply to ]
Jan-Frode Myklebust wrote:
> On 2007-08-27, Rainer Gerhards <rgerhards at hq.adiscon.com> wrote:
>> Can you let us know which strings it is set to? That would definitely
>> help troubleshooting (one lab less to do ;)).
>
> Not sure what you're asking.. I have this rsyslog.conf entry:
>
> $template PerAppLogs,"/var/log/rsyslog/apps/%programname%.log"
> *.* -?PerAppLogs
>
> which produce two log files "1.4.1.log" and "message.log" containing
>
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
> Aug 27 21:58:01 syslogd 1.4.1: restart.
>
> Aug 27 22:02:48 last message repeated 12 times
> Aug 27 22:02:49 last message repeated 6 times
> Aug 27 22:02:49 last message repeated 92 times
>
> respectively. I think that's all information I have.. plus maybe also
> say that the remote host logging this is likely RHEL3, RHEL4 or RHEL5
> with sysklogd sending the logs over standard udp (*.* @loghost).
>
> Another thing that scared me a bit is that from the same template I
> got a logfile named ".log" containing:
>
> Aug 27 22:00:01 censored1.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
> Aug 27 22:00:01 censored2.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
> Aug 27 22:00:02 censored3.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
> Aug 27 22:00:17 censored4.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
> Aug 27 22:00:17 censored5.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save
>
> which makes me think it tried to create the file /usr/bin/sudo.log..
> Wonder if it might be possible to make rsyslogd overwrite /etc/passwd
> with a sufficientlty crafted %programname% string...
>

Hi,

in your example above, %programname% was an empty string, so you've
ended up with the logfile /var/log/rsyslog/apps/.log.
Additionally, programname can't contain '/', so you example should be
fairly safe.

The reason of files like 1.4.1.log being produced is in the way hostname
and tag are parsed.
For example, message "s y s l o g: asdf" would have its hostname set to
"s" and programname to "y".
per programname logs [ In reply to ]
On 2007-08-29, theinric at redhat.com <theinric at redhat.com> wrote:
>>
>> Aug 27 21:58:01 syslogd 1.4.1: restart.
>> Aug 27 21:58:01 syslogd 1.4.1: restart.
>> Aug 27 21:58:01 syslogd 1.4.1: restart.
>>
>> Aug 27 22:02:48 last message repeated 12 times
>> Aug 27 22:02:49 last message repeated 6 times
>> Aug 27 22:02:49 last message repeated 92 times
>>
>
> in your example above, %programname% was an empty string, so you've
> ended up with the logfile /var/log/rsyslog/apps/.log.

In the entry:

Aug 27 22:00:17 censored5.domain.mgmt /usr/bin/sudo djksjdks : TTY=unknown ; PWD=/home/djksjdks ; USER=root ; COMMAND=/sbin/iptables-save

I'd expect it to be "/usr/bin/sudo djksjdks ", and that's what I think sudo
intended it to be. Testing using "logger" I see that %programname% gets a bit
strange interpretations:

# logger -t xyz test
# cat xyz.log
Aug 29 13:18:27 loghost1 xyz: test


# logger -t "x y z" test
# cat x.log
Aug 29 13:19:30 loghost1 x y z: test


# logger -t "y z " test
# cat y.log
Aug 29 13:21:17 loghost1 y z : test


And strangely, this one sets the %programname% to the hostname:

# logger -t " w" test
# cat loghost1.log
Aug 29 13:26:08 loghost1 loghost1 w: test



-jf