Syslog logging

[Massimo-B]

Hi,

for projects like https://rseichter.github.io/fangfrisch/ I can configure logging to syslog:

https://rseichter.github.io/fangfrisch/#_configuration

I have set there

log_level = DEBUG
log_method = syslog                                                                                                                                                                                                                                                                                                        
log_target = /dev/log

but nothing is arriving on metalog. Before filing a bug report in the other project, is that the right configuration for metalog? I also tried

log_target = localhost

[m-kress]

Your issue triggered a mail to me, where your text appeared like this:

log_level = DEBUG
log_method =
syslog
log_target = /dev/log

There seems to be a weird character at the end of the line log_method, that cases a line feed. Could you please type the line again and try again?

On Linux it should be sufficient to have:
log_level = DEBUG
log_method = syslog

If that doesn't help, please send your metalog.conf file.

[auouymous]

I don't see any weird characters, but there are about 300 spaces after log_method = syslog which might cause wrapping.

[Massimo-B]

Ok, for the weird characters that might be happened when pasting, my file doesn't have that. Here a clean paste again:

# grep log /etc/fangfrisch.conf 
log_level = DEBUG
log_method = syslog

Removing log_method makes log it to STDOUT as expected, but method syslog doesn't push anything to metalog. I'm going to forward that to the other project...

[rseichter]

@m-kress As explained in the Fangfrisch documentation, the value or absence of log_target has functional implications. The default behaviour of logging via UDP may not be what is needed here. However, I am admittedly unfamiliar with Metalog.

[m-kress]

So the needed settings should be:

log_level = DEBUG
log_method = syslog
log_target = /dev/log

Maybe the logging works just fine but metalog is not porperly configured? This is why I asked for the metalog.conf.
This is just an example of how the end of your metalog.conf should look like:

...
FangFrisch:
    program_regex = "^fangfrisch"
    logdir = "/var/log/fangfrisch"
    break = 1

MISC:
    logdir = "/var/log/misc"

In case the log entry isn't catched by one of the sections like "FangFrisch", the "MISC:" section will be applied. If you misconfigured your filter for FangFrisch, then have a look into /var/log/misc/current, it might have been caught there. If that is true, you might find out, what is wrong to your config in section "FangFrisch:".

Please do not forget to restart metalog after you modified the metalog.conf file!

[m-kress]

In case that also doesn't help, you might want to test your python program with setting the format to something like:
handler.formatter = logging.Formatter(": %(name)s: %(message)s")

Metalog cares a big deal about the ":" and space characters in the log entry.

[rseichter]

Here is what I use in syslog-ng.conf to bundle all log messages related to ClamAV:

destination d_clamd { file("/var/log/clamd"); };
filter f_clamd { program("clamd") or program("freshclam") or program("fangfrisch"); };
log { source(src); filter(f_clamd); destination(d_clamd); flags(final); };

I also used other loggers during development without issues, so I am currently not planning any tests with metalog until a misconfiguration on @Massimo-B 's system can be ruled out.

[Massimo-B]

As I expect the issue to be in my metalog.conf, this is what I currently have:

# grep -i log /etc/fangfrisch.conf 
log_level = DEBUG
log_method = syslog
log_target = /dev/log

$ cat /etc/metalog.conf
# Sample Metalog configuration file

# Comments are introduced with "#", which is ONLY allowed at the beginning of a line.

# Rotate log after file size (1048576 = 1 megabyte)
maxsize  = 524288

# Rotate log at least after 30 days (in seconds)
maxtime  = 604800   # time in seconds (86400 = 1 day)

# Number of archive files per directory
maxfiles = 8

# directory with more config files to load; files names must end with ".conf"
#configdir = /etc/metalog.d

# Permissions for log directories. 0750 allows group to read logs. 0700 is default.
#perms    = 0750

# Format of the timestamp: YYYY-MM-DD HH:MM:SS.NNN
#stamp_fmt = "%F %T.%3N"

# Configures a remote log server
#remote_host = 192.168.1.2
#remote_port = 514

# Send all logs via UDP to a remote log server
#remote_log = 1

# This will capture all of the internal log messages that metalog itself
# generates.  If you use any "command" options below, you will want this
# as metalog generates a lot of status messages whenever it executes a
# command and children processes exit.
#
#Metalog:
#    program   = "metalog"
#    logdir    = "/var/log/metalog"
#    break     = 1

# Uncomment and adjust the following lines according to your console logging
# needs.  If you want to only output things that were not caught by other log
# sections, move this to the end of the file.  Make sure this command is on
# your root partition if you have /usr mounted separately.  This script should
# merely write $@ to some device (your console for messages):
# echo "$@" > /dev/tty10
#
# Hint: you can control the consolelog.sh behavior in /etc/conf.d/metalog
#
#console logging:
#  facility  = "*"
#  command   = "/sbin/consolelog.sh"

# Custom global settings ##########################################

postrotate_cmd = "/etc/metalog.d/metalog_rotate"

# Custom early, and break: Skipping ... ###########################
#
#
FS-Cache :

    facility = "kern"
    regex    = "FS-Cache:"
    logdir   = "NONE"
    break    = 1
    
pkexec :

    regex    = ".*/usr/sbin/xfpm-power-backlight-helper.*"
    logdir   = "NONE"
    break    = 1
    
pkexec :

    regex    = ".*pam_unix.*polkit-1.* session opened for user.*"
    logdir   = "NONE"
    break    = 1
    
acpi :

    regex    = ".*ACPI event unhandled: button/.*"
    logdir   = "NONE"
    break    = 1
    
acpi :

    regex    = ".*ACPI event unhandled: video/.*"
    logdir   = "NONE"
    break    = 1
    
acpi :

    regex    = ".*ACPI event unhandled: battery.*"
    logdir   = "NONE"
    break    = 1

# Custom early, and break: logging to dedicated file only #########

Shorewall :

    facility = "kern"
    regex    = "Shorewall:"
    logdir   = "/var/log/shorewall"
    break    = 1

fcron :

    program  = "fcron"
    regex    = "session (opened|closed) for user root"
    logdir   = "/var/log/cron"
    break    = 1

smartd :

    program  = "smartd"
    regex    = "Temperature_Cel.*changed"
    logdir   = "/var/log/smartd"
    break    = 1

# Everything, and continue ########################################

Everything important:
    facility = "*"
    minimum  = 6
    logdir   = "/var/log/everything"
#if break keyword does not appear, rules after here will be run.

Everything very important:
    facility = "*"
    minimum  = 1
    logdir   = "/var/log/critical"

Password failures:
    regex    = "(password|login|authentication)\s+(fail|invalid)"
    regex    = "(failed|invalid)\s+(password|login|authentication|user)"
    regex    = "ILLEGAL ROOT LOGIN"
    logdir   = "/var/log/pwdfail"
#    command  = "/usr/local/sbin/mail_pwd_failures.sh"

# If you changed default permissions it may be a good idea to set more
# restrictive permissions on sensitive logs.
#    perms    = 0700

# Specific, and break #############################################

Kernel messages:
    facility = "kern"
    logdir   = "/var/log/kernel"
    break    = 1
# Additionally send this log entries via UDP to a remote log server
#    remote_log = 1

Crond:
    facility = "cron"
    logdir   = "/var/log/cron"
    break    = 1

Dudes firewalled by IPTrap:
    program  = "iptrap"
    logdir   = "/var/log/iptrap"
    break    = 1

FTP Server:
    facility = "ftp"
    logdir   = "/var/log/ftpd"
    break    = 1

News Server:
    facility = "news"
    logdir   = "/var/log/news"
    break    = 1

SSH Server:
    program  = "sshd"
    logdir   = "/var/log/sshd"
    break    = 1

# why the hell do you still run that thing !?
Telnet:
    program  = "login"
    logdir   = "/var/log/telnet"
    break    = 1

Imap:
     program  = "/usr/sbin/imapd"
     logdir   = "/var/log/imap"
     break    = 1

POP Toaster:
    program  = "/usr/sbin/ipop3d"
    logdir   = "/var/log/pop"
    break    = 1

Mail:
    facility = "mail"
    neg_regex= "starting daemon"
    logdir   = "/var/log/mail"
    break    = 1

# exim stuff - log output from every program whose name begins with "exim".
Exim:
    program_regex = "^exim"
    logdir        = "/var/log/exim"
    break         = 1

Imap:
    program  = "/usr/sbin/imapd"
    logdir   = "/var/log/imap"
    break    = 1

# log output from every program whose name begins with "ppp"
Ppp:
    program_regex = "^ppp"
    logdir    = "/var/log/ppp"
    break     = 1

Postgresql:
    program_regex = "^postmaster"
    program_regex = "^postgres"
    logdir    = "/var/log/postgres"
    break     = 1

Apache:
    program_regex = "^httpd"
    logdir    = "/var/log/http"
    break     = 1

HAL:
    program_regex = "^hal"
    logdir    = "/var/log/hal"
    break     = 1

# Custom late: Logging to special files additionally ##############

fcron :

    program  = "fcron"
    logdir   = "/var/log/cron"
    break    = 1

smartd :
    program  = "smartd"
    logdir   = "/var/log/smartd"
    break    = 1

rsyncd :
    program  = "rsyncd"
    logdir   = "/var/log/rsyncd"
    break    = 1

distccd :
    program  = "distccd"
    logdir   = "/var/log/distccd"
    break    = 1

dnsmasq :
    program_regex  = "^dnsmasq"
    logdir   = "/var/log/dnsmasq"
    break    = 1

VMware :
#    program_regex = "^postmaster"
    program_regex = "^vmnet"
    logdir    = "/var/log/vmware"
    break     = 1

polipo :

    program  = "polipo"
    logdir   = "/var/log/polipo"
    break    = 1

#Shorewall :
#    facility = "kern"
#    regex    = "^Shorewall:"
#    logdir   = "/var/log/shorewall"
#    break    = 1

###################################################################

[m-kress]

The log message created from fangfrisch doesn't get captured by metalog because of not being conform to the old and deprecated BSD logging style. Metalog doesn't know the new standard RFC 5424.

Make a test for yourself:

Collect all messages not fetched by other sections in /var/log/misc/current by appending that to the end of your metalog.conf:

Misc:
logdir = "/var/log/misc"

Restart metalog then

Try this little testing program, comment the 5th, or the 6th line, then run it:

import logging.handlers
logger = logging.getLogger()
logger.setLevel(logging.INFO)
handler = logging.handlers.SysLogHandler(address='/dev/log')
f = r'fangfrisch[%(process)d]: %(message)s' # does not work
f = r': fangfrisch[%(process)d]: %(message)s' # works
handler.formatter = logging.Formatter(f)
logger.addHandler(handler)
logger.info("Started")

Unless fangfrisch doesn't start its syslog message with ": " metalog will not capture anything.

[rseichter]

Here is a fresh log snippet as captured by syslog-ng, combining Fangfrisch and clamd in a single log file:

Jul  1 18:12:13 myhost fangfrisch[14115]: /var/lib/clamav/urlhaus.ndb updated (826824 bytes)
Jul  1 18:12:13 myhost fangfrisch[14115]: [urlhaus] caused updates
Jul  1 18:12:13 myhost fangfrisch[14115]: Task(command={clamdscan --reload}, timeout=30) added
Jul  1 18:12:13 myhost fangfrisch[14115]: Ignoring duplicate: clamdscan --reload
Jul  1 18:12:13 myhost clamd[2522]: Reading databases from /var/lib/clamav
Jul  1 18:12:14 myhost fangfrisch[14115]: Task(command={clamdscan --reload}, timeout=30) returned code 0
Jul  1 18:12:27 myhost clamd[2522]: Database correctly reloaded (9088565 signatures)
Jul  1 18:12:27 myhost clamd[2522]: Activating the newly loaded database...

[rseichter]

@m-kress You made me smile by using the expression "new standard RFC 5424". The document was released in early 2009. 🙂

[Massimo-B]

Ok, thanks for clarification. This is the first situation where metalog isn't compatible to a project logging to syslog.
Time to switch the logger for something modern?

[m-kress]

@Massimo-B: maybe. For the time being you could please add ": " to line 57
in fangfrisch/log.py so it looks like:

default_format = r': fangfrisch[%(process)d]: %(message)s'

You also have to add the section to metaconf.log, so the fangfrisch logs get stored in a file. To log all unknown (misc) to a common directory append this to metalog.conf

misc:
logdir = "/var/log/misc"

[Massimo-B]

Next project I don't get any logs: https://github.com/linrunner/TLP

In https://github.com/linrunner/TLP/blob/main/tlp-func-base.in#L80 I see some logger -p debug, doing that manually I don't see any output:

logger test   # works
logger -p debug test   # works NOT

[m-kress]

That I can't reproduce on my machine. Both commands work (with or without "-p debug").
My version of logger:

$ logger --version
logger from util-linux 2.39.3

When I append "--rfc3164" it still works. When I append "--rfc5424" it does not which is not surprising at all.

Have your tried adding ": " to the fangfrisch file?

[Massimo-B]

Have your tried adding ": " to the fangfrisch file?

Yes, seems to work now:

# grep log /etc/fangfrisch.conf 
log_level = DEBUG
log_method = syslog
log_target = /dev/log

# grep -n "default_format =" /usr/lib/python3.12/site-packages/fangfrisch/log.py
57:        default_format = r': fangfrisch[%(process)d]: %(message)s'
60:        default_format = r'%(levelname)s: %(message)s'

# sudo -u clamav -- fangfrisch -c /etc/fangfrisch.conf refresh && echo OK
OK

# grep -e '\[fangfrisch\]' /var/log/everything/current 
Jul 12 09:37:11 [fangfrisch] /var/lib/clamav/urlhaus.ndb updated (1254939 bytes)

[Massimo-B]

That I can't reproduce on my machine. Both commands work (with or without "-p debug"). My version of logger:

# logger --version 
logger from util-linux 2.39.3

# date && logger LOGTEST
Fr 12. Jul 09:41:26 CEST 2024

# date && logger -p debug LOGTESTDEBUG
Fr 12. Jul 09:41:33 CEST 2024

# grep LOGTEST /var/log/everything/current 
Jul 12 09:41:26 [root] LOGTEST

I already found the reason:

Everything important:
    facility = "*"
    minimum  = 6
    logdir   = "/var/log/everything"

minimum = 6 is blocking debug level. Setting 7 here makes it work, also with TLP.

[m-kress]

Nice! Thanks for testing the modification of fangfrisch.

Conclusion: metalog works like defined in RFC3164 and not like defined in RFC5424. Maybe the newer RFC could be added to the code in the future, but there is nothing right now that solves the problem in metalog.

RFC5424 is also wished for here: #31

Please close this issue. RFC5424 is a feature put down onto the wishlist. Thank you!