Database export taking upwards of 20 seconds

[swills]

Versions

• Pi-hole: v6.1.4
• Web: v6.2.1
• FTL: v6.2.3

Platform

• OS and version: Linux 6.12.43
• Platform: Talos

I noticed that Pihole had started to hang periodically and after some troubleshooting turned on debugging. Here are some relevant logs:

2025-11-06 03:54:25.414 UTC [54/T171] DEBUG_DATABASE: Exported 0 rows for disk.query_storage (took 25331.0 ms, last SQLite ID 15293262)
2025-11-06 03:55:22.111 UTC [54/T171] DEBUG_DATABASE: Exported 71 rows for disk.query_storage (took 22034.2 ms, last SQLite ID 15293404)
2025-11-06 03:56:23.988 UTC [54/T171] DEBUG_DATABASE: Exported 0 rows for disk.query_storage (took 23913.9 ms, last SQLite ID 15293333)
2025-11-06 03:57:24.162 UTC [54/T171] DEBUG_DATABASE: Exported 55 rows for disk.query_storage (took 24093.2 ms, last SQLite ID 15293443)
2025-11-06 03:58:23.516 UTC [54/T171] DEBUG_DATABASE: Exported 0 rows for disk.query_storage (took 23457.7 ms, last SQLite ID 15293388)
2025-11-06 03:59:22.760 UTC [54/T171] DEBUG_DATABASE: Exported 44 rows for disk.query_storage (took 22677.1 ms, last SQLite ID 15293476)
2025-11-06 04:00:21.945 UTC [54/T171] DEBUG_DATABASE: Exported 49 rows for disk.query_storage (took 21855.9 ms, last SQLite ID 15293574)
2025-11-06 04:01:21.107 UTC [54/T171] DEBUG_DATABASE: Exported 69 rows for disk.query_storage (took 21015.7 ms, last SQLite ID 15293713)

Looks like exporting the DB is taking ~20 seconds.

Note that this is running inside Kubernetes with /etc/pihole on Ceph storage, specifically CephFS (not rbd, nfs, etc.). Perhaps not a supported platform and that's fine, I'm happy to bump database.DBinterval up from the default 60 seconds and otherwise ignore infrequent issues.

That said, I think that the problem may be somewhat simple to fix, since I suspect it's an fsync() issue due to the fact that SQLite does fsync by default (without pragma synchronous = off) and CephFS is very conservative about ensuring all copies are written to disk.

[swills]

I realized I wasn't clear here about two things here. 1. The problem is that it stops responding to requests completely while the database export happens. 2. This config has been in use for a long while but it was only in recent upgrades that it started to be a problem.

[DL6ER]

only in recent upgrades

By any chance, can you be more specific? I think what you are seeing should be there since the v6.0 upgrade. On the sync issue: We are already lowering the default value pragma synchronous = full to pragma synchronous = normal through a compile-time flag. I am somewhat hesitant to lower it even more (that is, off).

FULL (2)

When synchronous is FULL (2), the SQLite database engine will use the xSync method of the VFS to ensure that all content is safely written to the disk surface prior to continuing. This ensures that an operating system crash or power failure will not corrupt the database.

FULL is the default synchronous mode for a rollback journal. FULL is atomic, consistent, isolated, and durable (ACID) in WAL mode and is atomic, consistent, and isolated with a rollback journal. FULL might also be durable using a rollback journal, depending on the underlying filesystem. FULL is not necessarily durable across a power loss in rollback mode, so if durability is desired, it is best to set the synchronous mode to EXTRA.

NORMAL (1)

When synchronous is NORMAL (1), the SQLite database engine will still sync at the most critical moments, but less often than in FULL mode. There is a very small (though non-zero) chance that a power failure at just the wrong time could corrupt the database in journal_mode=DELETE on an older filesystem. WAL mode is safe from corruption with synchronous=NORMAL, and probably DELETE mode is safe too on modern filesystems. WAL mode is always consistent with synchronous=NORMAL, but WAL mode does lose durability. A transaction committed in WAL mode with synchronous=NORMAL might roll back following a power loss or system crash. Transactions are durable across application crashes regardless of the synchronous setting or journal mode.

The synchronous=NORMAL setting provides the best balance between performance and safety for most applications running in WAL mode. You lose durability across power lose with synchronous NORMAL in WAL mode, but that is not important for most applications. Transactions are still atomic, consistent, and isolated, which are the most important characteristics in most use cases.

OFF (0)

With synchronous OFF (0), SQLite continues without syncing as soon as it has handed data off to the operating system. If the application running SQLite crashes, the data will be safe, but the database might become corrupted if the operating system crashes or the computer loses power before that data has been written to non-volatile storage. On the other hand, commits can be much faster with synchronous OFF.

Setting synchronous to OFF is a good option when creating a new database from scratch, in a scenario where the process of creating the database can be repeated if a power loss occurs in the middle, and when performance is critical.

(source: https://sqlite.org/pragma.html#pragma_synchronous)

[DL6ER]

Well, there are two things here:

1. Why is it taking so long even when zero queries are exported? Seems worth running your Pi-hole with debug.database so we get additional information in the log file. Maybe we can use that to optimize stuff

2. I don't think it's actually needed to block the resolver while exporting ... could you try branch tweak/dont-lock-on-export?

   sudo pihole checkout ftl tweak/dont-lock-on-export

[swills]

By any chance, can you be more specific?

This was Pi-hole: v6.0.6, Web: v6.1, FTL v6.1, but I setup another kubernetes deployment using that version and copied my db to it and then tested and I saw the same thing for a while, then it actually cleared up in that deployment, which was surprising to me.

1. Seems worth running your Pi-hole with debug.database so we get additional information in the log file.

I can definitely do that, I did that to get the DEBUG_DATABASE lines above, but it is a lot of info, is there any particular info you are looking for?

2. sudo pihole checkout ftl tweak/dont-lock-on-export

This just says: [✗] Function not supported in Docker images. I looked at the docs on building the image locally, but docker buildx doesn't work in k8s, I'll have to invest some time in getting the image built, hopefully tomorrow afternoon.

[swills]

I was able to get an image built and tested and it definitely helps. I now see lines like this in logs:

2025-11-09 19:17:00.322 UTC [66/T110] DEBUG_DATABASE: Exported 70 rows for disk.query_storage (took 201.6 ms)
2025-11-09 19:18:00.314 UTC [66/T110] DEBUG_DATABASE: Exported 55 rows for disk.query_storage (took 206.3 ms)
2025-11-09 19:19:00.237 UTC [66/T110] DEBUG_DATABASE: Exported 51 rows for disk.query_storage (took 203.3 ms)
2025-11-09 19:20:00.285 UTC [66/T110] DEBUG_DATABASE: Exported 108 rows for disk.query_storage (took 233.0 ms)
2025-11-09 19:21:00.224 UTC [66/T110] DEBUG_DATABASE: Exported 112 rows for disk.query_storage (took 200.5 ms)
2025-11-09 19:22:00.275 UTC [66/T110] DEBUG_DATABASE: Exported 57 rows for disk.query_storage (took 201.0 ms)
2025-11-09 19:23:00.212 UTC [66/T110] DEBUG_DATABASE: Exported 52 rows for disk.query_storage (took 200.1 ms)
2025-11-09 19:24:00.479 UTC [66/T110] DEBUG_DATABASE: Exported 119 rows for disk.query_storage (took 242.9 ms)
2025-11-09 19:25:00.404 UTC [66/T110] DEBUG_DATABASE: Exported 100 rows for disk.query_storage (took 228.9 ms)

There is still the occasional delay in responding to requests when the export happens but it's only a second or two, so it's not bad.

Thanks for the quick fix!

[DL6ER]

Then this delay likely comes for elsewhere, could you try building from branch tweak/db_performance and enable FTLCONF_DEBUG_TIMING as well? The fix discussed here is already integrated into this branch.

[swills]

Done, here:

https://gist.github.com/swills/c3e377d45f1a031e5104e79296b4ec6f

is a sample of the logs. I can send complete logs if needed. I do still notice a brief delay in responding to queries when the stats export happens.

[DL6ER]

Thank you for the log. I have carefully checked it and found a few blockers around incoming new queries, all ranging in the regime of ~ 0.1 - 0.2 seconds, each. This is already unexpectedly slow but likely due to your gravity.db being stored on the network, too, so any lookups in the table for "is domain XYZ to be blocked?" are simply orders of magnitude slower than they'd be on a local filesystem (where we expect these functions to return in less than one millisecond).

By any chance, can you enable some form of local file caching on the clients? It'd probably help a lot.

Then I looked closer specifically on the export to disk as you mentioned this as being a spot where things are slowed down. Writing the queries to disk took 9 and 7 seconds in the two occurrences in this log snippet. However, we can also observe that many queries were processed within this time so it is not clear to me when exactly you could have seen this happening.
My best speculation right now is that maybe the disk operation is slowing your entire network down because of (a) many write operations requiring a substantial bandwidth (network saturation?) or (b) the operation consumes so much CPU power that things get slowed down globally.

Without me having used CephFS before, it is difficult to come up with any concrete pointers for optimization (else than trying to up with a better caching). However, the mere observation that the read-only (!) access to gravity.db is slowest while we are exporting queries makes it very very likely a CephFS saturation problem of any kind.

Maybe you can try using some Ceph monitoring tools to identify any bottlenecks within the Ceph cluster itself (e.g., OSD latency, network saturation). Maybe you can also optimize placement group settings.

I'm not seeing anything in this log that could reveal further optimization potential for Pi-hole right now. I will, nonetheless, add additional debug timing also to the relevant gravity.db read-only operations.

[swills]

Thanks for looking. I think you're right that CephFS is the source of the problem. I'm planning to switch the storage from ceph-filesystem (CephFS) to ceph-block (nbd) which I think will help a lot. My apologies for taking your time on a site specific issue (storage performance) which happened to look like a DNS issue.

Just in case it helps to confirm your thinking on the issue, I reproduced the problem again and share the logs here. I noticed delays resolving queries from 12:05:10 until 12:05:12 in this log:

https://gist.github.com/swills/4ad4a5984be8a69f7d3c1be290aa4e1c

[swills]

One thing I did notice in that log was this:

2025-11-10 12:05:13.567 UTC [65/T178] DEBUG_TIMING: Database operation parse_neighbor_cache(db) took 2922.5 ms

I'm not sure it makes any sense to look at the arp cache when running in Kubernetes so I turned that off to see if it would affect things and my delays seem completely gone now. Note this is still using the tweak/db_performance branch, and I still think CephFS is the source of the problem.

[swills]

Well, I spoke too soon on my problems being gone, I was testing and noticed this one:

2025-11-10 12:39:12.743 UTC [65/T178] DEBUG_TIMING: Database operation delete_old_queries_in_DB(db) took 5454.9 ms

So yeah, pretty convinced I need to migrate the storage.

[swills]

Also thought you might be interested in these logs I saw:

)
2025-11-10 12:39:41.729 UTC [65M] DEBUG_TIMING: SHM lock held for 0.014 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:41.730 UTC [65M] DEBUG_TIMING: SHM lock held for 0.050 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.730 UTC [65M] DEBUG_TIMING: SHM lock held for 0.018 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:41.730 UTC [65M] DEBUG_TIMING: SHM lock held for 0.038 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.731 UTC [65M] DEBUG_TIMING: SHM lock held for 0.032 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.731 UTC [65M] DEBUG_TIMING: SHM lock held for 0.030 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:41.731 UTC [65M] DEBUG_TIMING: SHM lock held for 0.015 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:41.731 UTC [65M] DEBUG_TIMING: SHM lock held for 0.034 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.731 UTC [65M] DEBUG_TIMING: SHM lock held for 0.026 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:41.732 UTC [65M] DEBUG_TIMING: SHM lock held for 0.411 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.816 UTC [65M] DEBUG_TIMING: SHM lock held for -916.710 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:41.816 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:41.816 UTC [65M] DEBUG_TIMING: SHM lock held for 0.052 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.902 UTC [65M] DEBUG_TIMING: SHM lock held for 85.034 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:41.902 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:41.902 UTC [65M] DEBUG_TIMING: SHM lock held for 0.041 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:41.987 UTC [65M] DEBUG_TIMING: SHM lock held for 84.601 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:41.987 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:41.987 UTC [65M] DEBUG_TIMING: SHM lock held for 0.040 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.054 UTC [65M] DEBUG_TIMING: SHM lock held for 66.779 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.054 UTC [65M] DEBUG_TIMING: SHM lock held for 0.041 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.055 UTC [65M] DEBUG_TIMING: SHM lock held for 0.043 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:42.055 UTC [65M] DEBUG_TIMING: SHM lock held for 0.015 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:42.055 UTC [65M] DEBUG_TIMING: SHM lock held for 0.036 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.055 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.011 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.032 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.011 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.056 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.057 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.057 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.057 UTC [65M] DEBUG_TIMING: SHM lock held for 0.060 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.057 UTC [65M] DEBUG_TIMING: SHM lock held for 0.032 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:42.057 UTC [65M] DEBUG_TIMING: SHM lock held for 0.017 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:42.058 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.058 UTC [65M] DEBUG_TIMING: SHM lock held for 0.037 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.058 UTC [65M] DEBUG_TIMING: SHM lock held for 0.028 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:42.058 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:42.058 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.058 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.011 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.032 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.059 UTC [65M] DEBUG_TIMING: SHM lock held for 0.011 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.060 UTC [65M] DEBUG_TIMING: SHM lock held for 0.044 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.060 UTC [65M] DEBUG_TIMING: SHM lock held for 0.014 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.060 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.060 UTC [65M] DEBUG_TIMING: SHM lock held for 0.032 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.011 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.014 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.064 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.029 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:42.061 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:42.062 UTC [65M] DEBUG_TIMING: SHM lock held for 0.030 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.062 UTC [65M] DEBUG_TIMING: SHM lock held for 0.011 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.062 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.062 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.062 UTC [65M] DEBUG_TIMING: SHM lock held for 0.026 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:42.062 UTC [65M] DEBUG_TIMING: SHM lock held for 0.012 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:42.063 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.063 UTC [65M] DEBUG_TIMING: SHM lock held for 0.013 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.063 UTC [65M] DEBUG_TIMING: SHM lock held for 0.031 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.205 UTC [65M] DEBUG_TIMING: SHM lock held for 142.027 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.215 UTC [65/T178] DEBUG_TIMING: SHM lock held for 9.448 ms in DB_thread() (/app/src/database/database-thread.c:115)
2025-11-10 12:39:42.215 UTC [65M] DEBUG_TIMING: SHM lock held for 0.069 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.215 UTC [65M] DEBUG_TIMING: SHM lock held for 0.053 ms in _FTL_new_query() (/app/src/dnsmasq_interface.c:987)
2025-11-10 12:39:42.216 UTC [65M] DEBUG_TIMING: SHM lock held for 0.018 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2441)
2025-11-10 12:39:42.216 UTC [65M] DEBUG_TIMING: SHM lock held for 0.062 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.216 UTC [65M] DEBUG_TIMING: SHM lock held for 0.016 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.216 UTC [65M] DEBUG_TIMING: SHM lock held for 0.017 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.217 UTC [65M] DEBUG_TIMING: SHM lock held for 0.042 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.217 UTC [65M] DEBUG_TIMING: SHM lock held for 0.017 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)
2025-11-10 12:39:42.217 UTC [65M] DEBUG_TIMING: SHM lock held for 0.016 ms in FTL_reply() (/app/src/dnsmasq_interface.c:2398)
2025-11-10 12:39:42.217 UTC [65M] DEBUG_TIMING: SHM lock held for 0.076 ms in FTL_dnsmasq_log() (/app/src/dnsmasq_interface.c:3887)
2025-11-10 12:39:42.217 UTC [65M] DEBUG_TIMING: SHM lock held for 0.016 ms in FTL_CNAME() (/app/src/dnsmasq_interface.c:1963)

Some of those timings are very weird, particularly the -916.710 ms.