DNS (pdns_recursor) stats logs not saved to disk
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	jjakob
	Jun 24 2019, 9:58 PM

Description

pdns_recursor stats logs are seen in journalctl but not in /var/log/*.

As journald doesn't save to disk this means all logs are lost on reboot.

pdns log facility is 3 (daemon) and priority (=syslog severity) is 6, this translates to daemon.info

Mon 2019-06-24 12:26:51.084882 CEST [...]
    _BOOT_ID=xxx
    _MACHINE_ID=xxx
    _HOSTNAME=vyos
    _TRANSPORT=stdout
    PRIORITY=6
    SYSLOG_FACILITY=3
    SYSLOG_IDENTIFIER=pdns_recursor
    MESSAGE=stats: 54106 questions, 4436 cache entries, 997 negative entries, 6% cache hits
    _PID=2868
    _UID=0
    _GID=0
    _COMM=pdns_recursor
    _EXE=/usr/sbin/pdns_recursor
    _CMDLINE=/usr/sbin/pdns_recursor --daemon=no --write-pid=no --disable-syslog --log-timestamp=no
    _CAP_EFFECTIVE=404c1
    _SYSTEMD_CGROUP=/system.slice/pdns-recursor.service
    _SYSTEMD_UNIT=pdns-recursor.service
    _SYSTEMD_SLICE=system.slice

vyos default for /var/log/messages is *.notice;local7.debug

By setting set system syslog global facility all level info; set system syslog global facility protocols level debug, from short testing on my machine, it adds dhcpd and sudo logs which you'd want saved anyway, so imo the default should be set to *.info. This does increase disk writes so it may not be suitable for flash drives.

Details

Version: -
Is it a breaking change?: Unspecified (possibly destroys the router)
Issue type: Unspecified (please specify)

Related Objects

Mentioned In: rVYOSONEX4523381d5985: Revert "syslog: T1487: store all journalctl log files also in syslog"
rVYOSONEXbc3cf0a0a18a: Revert "syslog: T1487: store all journalctl log files also in syslog"
rVYOSONEX3a0ca1836039: Merge pull request #2803 from vyos/mergify/bp/sagitta/pr-2797
rVYOSONEX61817dbb3f26: syslog: T1487: store all journalctl log files also in syslog
rVYOSONEX800c85a20a00: syslog: T1487: store all journalctl log files also in syslog
rVYOSONEXf5b19352a4bc: Merge pull request #2797 from c-po/syslog-t1487

Event Timeline

jjakob created this task.Jun 24 2019, 9:58 PM

jjakob created this object in space S1 VyOS Public.

dmbaturin added a project: test.Jul 29 2021, 12:29 PM

dmbaturin set Is it a breaking change? to Unspecified (possibly destroys the router).

Do we need to set this option configurable?
We have an option --disable-syslog so for enable logging it should be --enable-syslog

vyos@r4-1.3:~$ sudo cat /etc/systemd/system/pdns-recursor.service.d/override.conf 
[Service]
WorkingDirectory=
WorkingDirectory=/run/powerdns
RuntimeDirectory=
RuntimeDirectory=powerdns
RuntimeDirectoryPreserve=yes
ExecStart=
ExecStart=/usr/sbin/pdns_recursor --daemon=no --write-pid=no --disable-syslog --log-timestamp=no --config-dir=/run/powerdns --socket-dir=/run/powerdns
vyos@r4-1.3:~$

From the manual:

Do not log to syslog, only to stdout. Use this setting when running inside a supervisor that handles logging (like systemd). Note: do not use this setting in combination with daemon as all logging will disappear.

Log files can be read from journal by:

cpo@BR1.wue3:~$ journalctl -u pdns-recursor -n 10
-- Logs begin at Tue 2021-08-17 00:26:56 CEST, end at Tue 2021-08-17 14:07:37 CEST. --
Aug 17 13:08:54 BR1.wue3 pdns_recursor[9301]: stats: 6915 packet cache entries, 89% packet cache hits
Aug 17 13:08:54 BR1.wue3 pdns_recursor[9301]: stats: thread 0 has been distributed 33512710 queries
Aug 17 13:08:54 BR1.wue3 pdns_recursor[9301]: stats: 9 qps (average over 1800 seconds)
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: 33529990 questions, 102 cache entries, 12 negative entries, 12% cache hits
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: throttle map: 1, ns speeds: 815, failed ns: 5, ednsmap: 1491
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: outpacket/query ratio 28%, 0% throttled, 0 no-delegation drops
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: 552 outgoing tcp connections, 0 queries running, 53303 outgoing timeouts
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: 6873 packet cache entries, 89% packet cache hits
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: thread 0 has been distributed 33529822 queries
Aug 17 13:38:54 BR1.wue3 pdns_recursor[9301]: stats: 9 qps (average over 1800 seconds)

I also see the logfiles in my message file:

cpo@BR1.wue3:~$ show log all | match pdns_recursor
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: 33405762 questions, 99 cache entries, 3 negative entries, 12% cache hits
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: throttle map: 0, ns speeds: 733, failed ns: 1, ednsmap: 1356
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: outpacket/query ratio 28%, 0% throttled, 0 no-delegation drops
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: 551 outgoing tcp connections, 0 queries running, 53091 outgoing timeouts
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: 6120 packet cache entries, 89% packet cache hits
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: thread 0 has been distributed 33405594 queries
Aug 17 10:08:54 BR1 pdns_recursor[9301]: stats: 9 qps (average over 1800 seconds)

@c-po Can we close it?