In order to write log messages of "myapp" into /var/log/local5.log
, I use SysLogHandler.
"myapp" runs well, no error, but nothing gets logged, /var/log/local5.log
remains empty.
Relevant parts of the logging configuration file:
handlers:
mainHandler:
class: logging.handlers.SysLogHandler
level: INFO
formatter: defaultFormatter
address: '/dev/log'
facility: 'local5'
loggers:
__main__:
level: INFO
handlers: [mainHandler]
Here is how I try to write a log in the main script of "myapp":
with open('myconfig.yml') as f:
logging.config.dictConfig(yaml.load(f))
log = logging.getLogger(__name__)
log.info("Starting")
I have added some sys.stderr.write()
to /usr/lib/python3.4/logging/handlers.py
to see what's happening and I get:
$ myapp
[SysLogHandler._connect_unixsocket()] Sucessfully connected to socket: /dev/log
[SysLogHandler.emit()] called
[SysLogHandler.emit()] msg=b'<174>2016/04/23 07:17:00.453 myapp: main: Starting\x00'
[SysLogHandler.emit()] msg sent to unix socket (no OSError)
/etc/rsyslog.conf
(relevant parts; TCP and UDP syslog receptions are disabled):
$ModLoad imuxsock # provides support for local system logging
$ModLoad imklog # provides kernel logging support
[...]
$IncludeConfig /etc/rsyslog.d/*.conf
/etc/rsyslog.d/40-local.conf
:
local5.* /var/log/local5.log
According to lsof
output, it looks like rsyslogd
is listening to /dev/log
(or am I wrong?):
# lsof | grep "/dev/log"
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
Output information may be incomplete.
rsyslogd 28044 syslog 0u unix 0xffff8800b4b9b100 0t0 3088160 /dev/log
in:imuxso 28044 28045 syslog 0u unix 0xffff8800b4b9b100 0t0 3088160 /dev/log
in:imklog 28044 28046 syslog 0u unix 0xffff8800b4b9b100 0t0 3088160 /dev/log
rs:main 28044 28047 syslog 0u unix 0xffff8800b4b9b100 0t0 3088160 /dev/log
I don't put the whole rsyslogd -N1
output since it's a bit long, but the mentionning"local" lines:
# rsyslogd -N1 | grep local
rsyslogd: version 7.4.4, config validation run (level 1), master config /etc/rsyslog.conf
3119.943361369:7f39080fc780: cnf:global:cfsysline: $ModLoad imuxsock # provides support for local system logging
3119.944034769:7f39080fc780: rsyslog/glbl: using '127.0.0.1' as localhost IP
3119.946084095:7f39080fc780: requested to include config file '/etc/rsyslog.d/40-local.conf'
3119.946135638:7f39080fc780: config parser: pushed file /etc/rsyslog.d/40-local.conf on top of stack
3119.946432390:7f39080fc780: config parser: resume parsing of file /etc/rsyslog.d/40-local.conf at line 1
3119.946678298:7f39080fc780: config parser: reached end of file /etc/rsyslog.d/40-local.conf
3119.946697644:7f39080fc780: Decoding traditional PRI filter 'local5.*'
3119.946723904:7f39080fc780: symbolic name: local5 ==> 168
3119.949560475:7f39080fc780: PRIFILT 'local5.*'
3119.949675782:7f39080fc780: ACTION 0x224cda0 [builtin:omfile:/var/log/local5.log]
3119.953397587:7f39080fc780: PRIFILT 'local5.*'
3119.953806713:7f39080fc780: ACTION 0x224cda0 [builtin:omfile:/var/log/local5.log]
rsyslogd: End of config validation run. Bye.
I don't understand what I am missing. rsyslog's documentation matching the version I use (7.4.4) seems outdated and I can't find my way in it. Not sure that's the place to find how to fix my problem.
EDITS:
rsyslog.conf
, so I changed to use the 'local5' one.I finally found out that I previously created /var/log/local5.log
with inappropriate owner and group (root:root
). They were inappropriate because /etc/rsyslog.conf
tells explicitely owner and group should be syslog:syslog
:
#
# Set the default permissions for all log files.
#
$FileOwner syslog
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$PrivDropToUser syslog
$PrivDropToGroup syslog
Unfortunately, the other log files rsyslog
should take care of (like auth.log
) were also root:root
, so, seen from ls -lah
, mine was not different from others... (what are also empty, I wonder why such a non-functional configuration is installed by default).
Unfortunately, rsyslog
does not log any error (or at least I haven't found where).
As a side note, rsyslog
expects a special format for the messages it gets, and if it doesn't, it adds some informations, by default (timestamp hostname). It's possible to modify them. Anyway, from my python script, I decided to only send the message to log and let rsyslog
format the output. So finally, the relevant parts of my logging configuration file are:
formatters:
rsyslogdFormatter:
format: '%(filename)s: %(funcName)s: %(message)s'
handlers:
mainHandler:
class: logging.handlers.SysLogHandler
level: INFO
formatter: rsyslogdFormatter
address: '/dev/log'
facility: 'local5'
loggers:
__main__:
level: INFO
handlers: [mainHandler]
And I added a customized template in /etc/rsyslog.conf
:
$template MyappTpl,"%$now% %timegenerated:12:23:date-rfc3339% %syslogtag%%msg%\n"
and accordingly modified /etc/rsyslog.d/40-local.conf
:
local5.* /var/log/local5.log;MyappTpl
I also want to mention that the documentation provided by the matching package (rsyslog-doc
for ubuntu) matches the installed version, of course, and provides hints I hadn't found in the online documentation.