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

Difficulty level: Unknown (require assessment)
Version: -
Why the issue appeared?: Will be filled on close
Is it a breaking change?: Unspecified (possibly destroys the router)
Issue type: Unspecified (please specify)

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

[email protected]:~$ 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
[email protected]:~$

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:

[email protected]:~$ 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:

[email protected]:~$ 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?