Hi,
I found a performance issue in Knot Resolver 6.5.0 when reloading an RPZ
file.
Every time the RPZ file changes, the watchdog starts the policy-loader
after about 5 seconds. During this reload, some workers stop answering
queries for up to 0.9 seconds.
The problem seems to be related to cache.open(), which calls
posix_fallocate() on the whole cache file. With our 32 GB cache on tmpfs,
this takes about 0.85 seconds, even on an existing cache file.
We use Knot Resolver 6 at a local ISP with around 30k users. Our RPZ
blocklist is updated about once per hour, usually with only 100-200 names
changed.
* Environment *
- Knot Resolver 6.5.0-cznic.1~bookworm
- libknot16 3.5.8 (lab) / 3.5.9 (production)
- liblmdb0 0.9.24-1
- python3-watchdog 2.2.1-1
- Debian 12, kernel 6.1
- 30 workers, 64 CPU cores
- Cache on tmpfs, size-max 32G
- RPZ file: ~825k records, ~326k names, watchdog enabled
* What happens *
The generated policy-loader script includes:
cache.open(34359738368, 'lmdb:///var/cache/knot-resolver')
I checked the policy-loader with perf record -g. For about 0.85 seconds,
almost all CPU time is spent in:
shmem_fallocate vfs_fallocate __x64_sys_fallocate posix_fallocate64
(libc.so.6) [unknown] (libkres.so.9) kr_cache_open+0x8f (libkres.so.9)
I also sampled /proc/<pid>/{stat,wchan,syscall} for all workers every 10 ms.
During this operation, workers trying to write to the cache appear to be
blocked in futex(). Their DNS responses are delayed until posix_fallocate()
finishes.
On our lab host, 2 out of 30 workers were affected. On production, with
higher traffic, almost all workers were affected.
We measured the following maximum response times during normal RPZ updates:
Host Before update After update
Production 1 39 ms 874 ms
Production 2 53 ms 887 ms
There were no timeouts or SERVFAIL responses. All delayed answers were sent
almost at the same moment.
I also tested repeated fallocate() on an existing 8 GB file:
Filesystem Time
tmpfs 488 ms
tmpfs (huge=always) 348 ms
ext4 7 ms
On tmpfs, the time increases almost linearly with file size (around 60
ms/GB).
* How to reproduce *
Example configuration (cache on tmpfs):
cache: storage: /var/cache/knot-resolver size-max: 32G local-data: rpz: -
file: /etc/knot-resolver/hazard.rpz watchdog: true
Send a constant stream of DNS queries and append one record to the RPZ file:
echo "test.example IN A 192.0.2.1" >> /etc/knot-resolver/hazard.rpz
About 5-6 seconds later, query latency increases.
On our lab host, I reproduced this twice, with maximum response times of
781 ms and 615 ms. In both tests, delayed responses were sent at +5.96
seconds after the RPZ change.
* Workaround *
I used lua.policy-script-only with a script generated by kresctl convert
--type policy-loader, but removed the cache.open() line.
The RPZ file remains configured in local-data.rpz, so the watchdog
continues to reload the rules.
Results on the same lab host:
Default Without cache.open()
Max response time 615-781 ms 5 ms
Queries over 50 ms 8-17 0
Policy-loader runtime ~1.4-1.5 s 0.45 s
Workers blocked in futex 2 0
New RPZ rules applied yes yes
I also tested existing and new RPZ records, local addresses, PTR records,
NXDOMAIN responses, DNSSEC validation and normal resolution. Everything
worked as expected.
However, this workaround has two drawbacks:
1. With lua.policy-script-only, the policy-loader ignores local-data,
views and forward from the config. We have to generate these rules
ourselves using Ansible templates.
2. Changes in the lua section cause a rolling restart of all workers,
even when only lua.policy-script changes. I suspect this is because
config.lua is included in the worker-related config nodes in manager.py.
* Question *
Does the policy-loader actually need to open the cache? Could some features
depend on it, for example the cache “top” file or other rule types ?
In our setup, removing cache.open() fixes the latency spikes, and
everything we tested still works.
Would it make sense to skip cache.open() when it is not needed ?
Thanks!
Best regards,
Mateusz Masłowski
Show replies by date