Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve insertion of clients, domains and DNS cache records #2095

Merged
merged 4 commits into from
Oct 26, 2024

Conversation

DL6ER
Copy link
Member

@DL6ER DL6ER commented Oct 23, 2024

What does this implement/fix?

Following up on #2084, this PR seeks to improve creation speed of new records (domains, clients, and DNS cache records). Previously, we used linear scanning whenever a new entry is to be added. Usually, there are some "holes" poked in the tables by preceding recycling activity but nothing guarantees us that (a) something has been recycled at all or (b) that such records are "early" in the table. Hence, linear searching through the tables usually scans the entire table just to find that there are no gaps and we have to create a new record at the very end of the table.

This PR improves this by adding a new shared memory object which memorizes if there are any recycled entries in these tables. If so, we use them right away without having to search for this. If there are none, we know that can immediately create a new entry at the end of the table.

In any case, we can avoid the (possibly lengthy) linear searching at all. Thanks for a list-with-known-length implementation, no memory copying/moving is ever required making this extremely fast.

Furthermore, this PR avoid creating DNS cache records when we don't actually need them during database importing.

Both changes improve the overall speed of FTL during DNS operation but are actually most notable during startup on low-end hardware as history importing gets roughly 5-20% faster depending on whats the limiting factor there on your device. If it is your CPU that is being slow, you may see a very notable impact. If, however, your disk/SDcard, etc., is slow, then this change may have much less of an impact for you.


Related issue or feature (if applicable): N/A

Pull request in docs with documentation (if applicable): N/A


By submitting this pull request, I confirm the following:

  1. I have read and understood the contributors guide, as well as this entire template. I understand which branch to base my commits and Pull Requests against.
  2. I have commented my proposed changes within the code.
  3. I am willing to help maintain this change if there are issues with it later.
  4. It is compatible with the EUPL 1.2 license
  5. I have squashed any insignificant commits. (git rebase)

Checklist:

  • The code change is tested and works locally.
  • I based my code and PRs against the repositories developmental branch.
  • I signed off all commits. Pi-hole enforces the DCO for all contributions
  • I signed all my commits. Pi-hole requires signatures to verify authorship
  • I have read the above and my PR is ready for review.

@DL6ER DL6ER requested a review from a team October 23, 2024 20:25
@yubiuser
Copy link
Member

Both changes improve the overall speed of FTL during DNS operation but are actually most notable during startup on low-end hardware as history importing gets roughly 5-20% faster depending on whats the limiting factor there on your device.

On which step would one see an improvement here? Looking between

Database successfully initialized and Imported XXX queries from the on-disk database I don't see mich improvement on my rather slow NanoPi Neo2 Plus

development

2024-10-24 11:30:21.783 CEST [423074M] INFO: Database version is 19
2024-10-24 11:30:21.784 CEST [423074M] INFO: Database successfully initialized
2024-10-24 11:30:22.529 CEST [423074M] INFO: Imported 9130 queries from the on-disk database (it has 1391891 rows)
2024-10-24 11:30:22.529 CEST [423074M] INFO: Parsing queries in database
2024-10-24 11:30:22.848 CEST [423074M] INFO: Imported 9130 queries from the long-term database
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Total DNS queries: 9130
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Cached DNS queries: 3879
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Forwarded DNS queries: 2601
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Blocked DNS queries: 2191
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Unknown DNS queries: 4
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Unique domains: 1054
2024-10-24 11:30:22.848 CEST [423074M] INFO:  -> Unique clients: 10
2024-10-24 11:30:22.849 CEST [423074M] INFO:  -> DNS cache records: 2773
2024-10-24 11:30:22.849 CEST [423074M] INFO:  -> Known forward destinations: 2

this branch, first start

2024-10-24 11:31:40.843 CEST [423157M] INFO: Database version is 19
2024-10-24 11:31:40.849 CEST [423157M] INFO: Database successfully initialized
2024-10-24 11:31:42.305 CEST [423157M] INFO: Imported 9144 queries from the on-disk database (it has 1391905 rows)
2024-10-24 11:31:42.307 CEST [423157M] INFO: Parsing queries in database
2024-10-24 11:31:42.599 CEST [423157M] INFO: Imported 9144 queries from the long-term database
2024-10-24 11:31:42.600 CEST [423157M] INFO:  -> Total DNS queries: 9144
2024-10-24 11:31:42.600 CEST [423157M] INFO:  -> Cached DNS queries: 3880
2024-10-24 11:31:42.600 CEST [423157M] INFO:  -> Forwarded DNS queries: 2614
2024-10-24 11:31:42.600 CEST [423157M] INFO:  -> Blocked DNS queries: 2191
2024-10-24 11:31:42.600 CEST [423157M] INFO:  -> Unknown DNS queries: 4
2024-10-24 11:31:42.600 CEST [423157M] INFO:  -> Unique domains: 1054
2024-10-24 11:31:42.601 CEST [423157M] INFO:  -> Unique clients: 10
2024-10-24 11:31:42.601 CEST [423157M] INFO:  -> DNS cache records: 516
2024-10-24 11:31:42.601 CEST [423157M] INFO:  -> Known forward destinations: 2

consecutive restart

2024-10-24 11:34:47.369 CEST [423320M] INFO: Database version is 19
2024-10-24 11:34:47.370 CEST [423320M] INFO: Database successfully initialized
2024-10-24 11:34:48.096 CEST [423320M] INFO: Imported 9166 queries from the on-disk database (it has 1391927 rows)
2024-10-24 11:34:48.097 CEST [423320M] INFO: Parsing queries in database
2024-10-24 11:34:48.269 CEST [423320M] INFO: Imported 9166 queries from the long-term database
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Total DNS queries: 9166
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Cached DNS queries: 3882
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Forwarded DNS queries: 2634
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Blocked DNS queries: 2191
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Unknown DNS queries: 4
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Unique domains: 1055
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Unique clients: 10
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> DNS cache records: 516
2024-10-24 11:34:48.270 CEST [423320M] INFO:  -> Known forward destinations: 2

@yubiuser
Copy link
Member

How do you interpret those results? What does it mean no Clients recycled? What happens when the list is full?

2024-10-24 19:14:05.860 CEST [423320/T423324] INFO: Recycle list fullness:
2024-10-24 19:14:05.860 CEST [423320/T423324] INFO:   Clients: 0/1024 (0.00%)
2024-10-24 19:14:05.860 CEST [423320/T423324] INFO:   Domains: 113/1024 (11.04%)
2024-10-24 19:14:05.860 CEST [423320/T423324] INFO:   DNS Cache: 0/1024 (0.00%)

@DL6ER
Copy link
Member Author

DL6ER commented Oct 25, 2024

I don't see mich improvement on my rather slow NanoPi Neo2 Plus

Hmm, yes, this is interesting, I would have expected much more than:

development: 848 - 529 = 319
this branch, first start: 599 - 307 = 292
consecutive restart: 269 - 097 = 172

I am unable to test on "real" slow hardware so I configured a Pi-hole v6.0 container to be "low-end" on x86_64 using something like:

services:
  pi-hole-slow:
    image: pihole/pihole:local-v6
    [...]
    deploy:
      resources:
        limits:
          # maximum the container can get
          cpus: '0.001'
          memory: 100M
        reservations:
          # minimum that needs to be guaranteed for the container
          cpus: '0.0001'
          memory: 50M

and saw improvements by a factor 3-4x. Your numbers above show something close to a 2x, at least when comparing the last with the development times.


How do you interpret those results?

Clients: 0/1024 (0.00%)

There are two possible causes here:

  • No clients have been recycled and the table is still empty.
  • Clients have been recycled but the empty slots have already been reused to create new clients.

In both cases, the code to create new clients will immediately append the new clients at the end of the list without wasting time to search possible gaps. The situation is the same for the DNS Cache: 0/1024 (0.00%) report.

Domains: 113/1024 (11.04%)

There are 113 domains that have been recycled. Whenever the next new domain is created, FTL takes the last ID from this list and can create the domain at this location. No need to search for an empty spot. As the binary search algorithm ensures monotonicity (strict ordering) in the lookup table, domains can equally fast be found regardless if they are created at the beginning, somewhere in the middle or towards the end of the list.

What does it mean no Clients recycled?

It means that there are no clients that have not been seen for consecutive 24 hours and, hence, have been recycled. This is rather unlikely to happen in small home networks with always the same clients. You will much more likely to see this with domains of pages you have visited yesterday but not ever since again.

What happens when the list is full?

In this case, the list stops to be filled with new IDs. Yes, it means we "forget" where some empty slots are and, if many new domains/clients/DNS cache records are created, this can eventually lead to "wasting" some memory. There are, in general, two obvious mitigations possible:

  1. Increase the default ID table size: 1024 on all three tables means 12 KB, we could easily go to some larger number like 2^16 = 65535 = ~ 786 KB. This shouldn't be a problem
  2. We could periodically "scan" for empty slots, e.g. during GC runs. It could also be conditional on whether an overflow has occurred (then can) or not (then the ID table is already 100% accurate)

Both can also be combined.

@yubiuser
Copy link
Member

How can the stats be empty, but it says it recycled some domains and cache entries just a few lines above?


2024-10-25 20:39:00.846 CEST [423320/T423324] DEBUG_GC: GC starting, mintime: 2024-10-24 20:40:00 CEST (1729795200), counters->queries = 12370
2024-10-25 20:39:00.854 CEST [423320/T423324] DEBUG_GC: delete_old_queries_from_db(): Deleted 88 (88) queries, new number of queries in memory: 12282
2024-10-25 20:39:00.857 CEST [423320/T423324] DEBUG_GC: Recycling domain 4.courier-push-apple.com.akadns.net (ID 732, last query was 2024-10-24 20:38:14.857 CEST)
2024-10-25 20:39:00.857 CEST [423320/T423324] DEBUG_GC: RECYCLE[domains][0] = 732 SET
2024-10-25 20:39:00.857 CEST [423320/T423324] DEBUG_GC: Recycling domain 4-courier.push.apple.com (ID 733, last query was 2024-10-24 20:38:14.857 CEST)
2024-10-25 20:39:00.857 CEST [423320/T423324] DEBUG_GC: RECYCLE[domains][1] = 733 SET
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: Recycling cache entry with ID 1474
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][0] = 1474 SET
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: Recycling cache entry with ID 1475
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][1] = 1475 SET
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: Recycling cache entry with ID 1477
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][2] = 1477 SET
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: Recycling cache entry with ID 1481
2024-10-25 20:39:00.859 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][3] = 1481 SET
2024-10-25 20:39:00.859 CEST [423320/T423324] DEBUG_GC: Recycling cache entry with ID 1482
2024-10-25 20:39:00.860 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][4] = 1482 SET
2024-10-25 20:39:00.860 CEST [423320/T423324] DEBUG_GC: 501/512 clients, 791/2176 domains and 873/3584 cache records are free
2024-10-25 20:39:00.861 CEST [423320/T423324] DEBUG_GC: Recycled 0 clients, 2 domains, and 5 cache records (scanned 12282 queries)
2024-10-25 20:39:00.861 CEST [423320/T423324] DEBUG_GC: GC removed 88 queries (took 15.55 ms)
2024-10-25 20:39:48.852 CEST [423320/T423324] DEBUG_GC: Statvfs() results for /etc/pihole/pihole-FTL.db:
2024-10-25 20:39:48.854 CEST [423320/T423324] DEBUG_GC:   Block size: 4096
2024-10-25 20:39:48.856 CEST [423320/T423324] DEBUG_GC:   Fragment size: 4096
2024-10-25 20:39:48.857 CEST [423320/T423324] DEBUG_GC:   Total blocks: 1829907
2024-10-25 20:39:48.859 CEST [423320/T423324] DEBUG_GC:   Free blocks: 1241653
2024-10-25 20:39:48.860 CEST [423320/T423324] DEBUG_GC:   Available blocks: 1143349
2024-10-25 20:39:48.862 CEST [423320/T423324] DEBUG_GC:   Total inodes: 471424
2024-10-25 20:39:48.863 CEST [423320/T423324] DEBUG_GC:   Free inodes: 421294
2024-10-25 20:39:48.864 CEST [423320/T423324] DEBUG_GC:   Available inodes: 421294
2024-10-25 20:39:48.866 CEST [423320/T423324] DEBUG_GC:   Filesystem ID: 18446744073432919729
2024-10-25 20:39:48.867 CEST [423320/T423324] DEBUG_GC:   Mount flags: 1056
2024-10-25 20:39:48.869 CEST [423320/T423324] DEBUG_GC:   Maximum filename length: 255
2024-10-25 20:39:48.870 CEST [423320/T423324] DEBUG_GC: Checking free space at /etc/pihole/pihole-FTL.db: 37% <= 90%
2024-10-25 20:39:48.872 CEST [423320/T423324] DEBUG_GC: Statvfs() results for /var/log/pihole/FTL.log:
2024-10-25 20:39:48.873 CEST [423320/T423324] DEBUG_GC:   Block size: 4096
2024-10-25 20:39:48.875 CEST [423320/T423324] DEBUG_GC:   Fragment size: 4096
2024-10-25 20:39:48.876 CEST [423320/T423324] DEBUG_GC:   Total blocks: 11990
2024-10-25 20:39:48.878 CEST [423320/T423324] DEBUG_GC:   Free blocks: 5802
2024-10-25 20:39:48.879 CEST [423320/T423324] DEBUG_GC:   Available blocks: 4906
2024-10-25 20:39:48.880 CEST [423320/T423324] DEBUG_GC:   Total inodes: 12800
2024-10-25 20:39:48.882 CEST [423320/T423324] DEBUG_GC:   Free inodes: 12689
2024-10-25 20:39:48.883 CEST [423320/T423324] DEBUG_GC:   Available inodes: 12689
2024-10-25 20:39:48.885 CEST [423320/T423324] DEBUG_GC:   Filesystem ID: 18446744073144472568
2024-10-25 20:39:48.886 CEST [423320/T423324] DEBUG_GC:   Mount flags: 4142
2024-10-25 20:39:48.887 CEST [423320/T423324] DEBUG_GC:   Maximum filename length: 255
2024-10-25 20:39:48.889 CEST [423320/T423324] DEBUG_GC: Checking free space at /var/log/pihole/FTL.log: 59% <= 90%
2024-10-25 20:39:54.040 CEST [423320M] DEBUG_GC: RECYCLE[domains][1] = 733 TAKE
2024-10-25 20:39:54.042 CEST [423320M] DEBUG_GC: New domain: onedscolprdeus12.eastus.cloudapp.azure.com (ID 733)
2024-10-25 20:39:54.049 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][4] = 1482 TAKE
2024-10-25 20:39:54.050 CEST [423320M] DEBUG_GC: New cache entry: domainID 830, clientID 8, query_type 16 (ID 1482)
2024-10-25 20:39:54.072 CEST [423320M] DEBUG_GC: RECYCLE[domains][0] = 732 TAKE
2024-10-25 20:39:54.074 CEST [423320M] DEBUG_GC: New domain: onedscolprdcus11.centralus.cloudapp.azure.com (ID 732)
2024-10-25 20:39:54.083 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][3] = 1481 TAKE
2024-10-25 20:39:54.084 CEST [423320M] DEBUG_GC: New cache entry: domainID 830, clientID 9, query_type 16 (ID 1481)
2024-10-25 20:40:00.556 CEST [423320M] DEBUG_ANY: dnsmasq received signal 17
2024-10-25 20:40:00.571 CEST [423320M] DEBUG_ANY: dnsmasq received signal 17
2024-10-25 20:40:56.014 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][2] = 1477 TAKE
2024-10-25 20:40:56.016 CEST [423320M] DEBUG_GC: New cache entry: domainID 798, clientID 8, query_type 2 (ID 1477)
2024-10-25 20:40:56.036 CEST [423320M] DEBUG_GC: RECYCLE[domains] is empty
2024-10-25 20:40:56.038 CEST [423320M] DEBUG_GC: New domain: onedscolprdwus21.westus.cloudapp.azure.com (ID 2132)
2024-10-25 20:40:56.065 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][1] = 1475 TAKE
2024-10-25 20:40:56.067 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 8, query_type 2 (ID 1475)
2024-10-25 20:40:56.072 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][0] = 1474 TAKE
2024-10-25 20:40:56.073 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 9, query_type 2 (ID 1474)
2024-10-25 20:40:59.753 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.755 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 8, query_type 1 (ID 3419)
2024-10-25 20:40:59.767 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.769 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 8, query_type 16 (ID 3420)
2024-10-25 20:40:59.778 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.780 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 9, query_type 1 (ID 3421)
2024-10-25 20:40:59.797 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.799 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 9, query_type 16 (ID 3422)
2024-10-25 20:41:00.442 CEST [423320M] DEBUG_ANY: dnsmasq received signal 17
2024-10-25 20:41:00.479 CEST [423320M] DEBUG_ANY: dnsmasq received signal 17
2024-10-25 20:41:12.660 CEST [423320M] DEBUG_GC: RECYCLE[domains] is empty
2024-10-25 20:41:12.662 CEST [423320M] DEBUG_GC: New domain: raw.githubusercontent.com (ID 2133)
2024-10-25 20:41:12.664 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:41:12.666 CEST [423320M] DEBUG_GC: New cache entry: domainID 2133, clientID 8, query_type 1 (ID 3423)
2024-10-25 20:41:12.675 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:41:12.677 CEST [423320M] DEBUG_GC: New cache entry: domainID 2133, clientID 8, query_type 16 (ID 3424)
2024-10-25 20:41:12.684 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:41:12.686 CEST [423320M] DEBUG_GC: New cache entry: domainID 2133, clientID 9, query_type 1 (ID 3425)
2024-10-25 20:41:12.697 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:41:12.699 CEST [423320M] DEBUG_GC: New cache entry: domainID 2133, clientID 9, query_type 16 (ID 3426)
2024-10-25 20:41:58.232 CEST [423320M] INFO: Received: RT42 (42 -> 7)
2024-10-25 20:41:58.870 CEST [423320/T423324] INFO: Searching for hash collisions in clients lookup table
2024-10-25 20:41:58.871 CEST [423320/T423324] INFO: Found 0 hash collisions in clients lookup table (scanned 11 elements)
2024-10-25 20:41:58.871 CEST [423320/T423324] INFO: Searching for hash collisions in domains lookup table
2024-10-25 20:41:58.872 CEST [423320/T423324] INFO: Found 0 hash collisions in domains lookup table (scanned 1389 elements)
2024-10-25 20:41:58.872 CEST [423320/T423324] INFO: Searching for hash collisions in DNS cache lookup table
2024-10-25 20:41:58.873 CEST [423320/T423324] INFO: Found 0 hash collisions in DNS cache lookup table (scanned 2724 elements)
2024-10-25 20:41:58.873 CEST [423320/T423324] INFO: Recycle list fullness:
2024-10-25 20:41:58.874 CEST [423320/T423324] INFO:   Clients: 0/1024 (0.00%)
2024-10-25 20:41:58.874 CEST [423320/T423324] INFO:   Domains: 0/1024 (0.00%)
2024-10-25 20:41:58.875 CEST [423320/T423324] INFO:   DNS Cache: 0/1024 (0.00%)
2024-10-25 20:42:00.277 CEST [423320M] DEBUG_ANY: dnsmasq received signal 17
2024-10-25 20:42:00.311 CEST [423320M] DEBUG_ANY: dnsmasq received signal 17

@DL6ER
Copy link
Member Author

DL6ER commented Oct 25, 2024

There were two domains and five DNS cache records recycled:

2024-10-25 20:39:00.857 CEST [423320/T423324] DEBUG_GC: RECYCLE[domains][0] = 732 SET
2024-10-25 20:39:00.857 CEST [423320/T423324] DEBUG_GC: RECYCLE[domains][1] = 733 SET

2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][0] = 1474 SET
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][1] = 1475 SET
2024-10-25 20:39:00.858 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][2] = 1477 SET
2024-10-25 20:39:00.859 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][3] = 1481 SET
2024-10-25 20:39:00.860 CEST [423320/T423324] DEBUG_GC: RECYCLE[dns_cache][4] = 1482 SET

as also seen in the summary:

2024-10-25 20:39:00.861 CEST [423320/T423324] DEBUG_GC: Recycled 0 clients, 2 domains, and 5 cache records (scanned 12282 queries)

Then, new queries arrived and created four new domains:

2024-10-25 20:39:54.040 CEST [423320M] DEBUG_GC: RECYCLE[domains][1] = 733 TAKE
2024-10-25 20:39:54.042 CEST [423320M] DEBUG_GC: New domain: onedscolprdeus12.eastus.cloudapp.azure.com (ID 733)
2024-10-25 20:39:54.072 CEST [423320M] DEBUG_GC: RECYCLE[domains][0] = 732 TAKE
2024-10-25 20:39:54.074 CEST [423320M] DEBUG_GC: New domain: onedscolprdcus11.centralus.cloudapp.azure.com (ID 732)
2024-10-25 20:40:56.036 CEST [423320M] DEBUG_GC: RECYCLE[domains] is empty
2024-10-25 20:40:56.038 CEST [423320M] DEBUG_GC: New domain: onedscolprdwus21.westus.cloudapp.azure.com (ID 2132)
2024-10-25 20:41:12.660 CEST [423320M] DEBUG_GC: RECYCLE[domains] is empty
2024-10-25 20:41:12.662 CEST [423320M] DEBUG_GC: New domain: raw.githubusercontent.com (ID 2133)

out of which the first two have reused exactly the two IDs recycled above (732 and 733), and also nine new DNS cache records:

2024-10-25 20:39:54.049 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][4] = 1482 TAKE
2024-10-25 20:39:54.050 CEST [423320M] DEBUG_GC: New cache entry: domainID 830, clientID 8, query_type 16 (ID 1482)
2024-10-25 20:39:54.083 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][3] = 1481 TAKE
2024-10-25 20:39:54.084 CEST [423320M] DEBUG_GC: New cache entry: domainID 830, clientID 9, query_type 16 (ID 1481)
2024-10-25 20:40:56.014 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][2] = 1477 TAKE
2024-10-25 20:40:56.016 CEST [423320M] DEBUG_GC: New cache entry: domainID 798, clientID 8, query_type 2 (ID 1477)
2024-10-25 20:40:56.065 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][1] = 1475 TAKE
2024-10-25 20:40:56.067 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 8, query_type 2 (ID 1475)
2024-10-25 20:40:56.072 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache][0] = 1474 TAKE
2024-10-25 20:40:56.073 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 9, query_type 2 (ID 1474)
2024-10-25 20:40:59.753 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.755 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 8, query_type 1 (ID 3419)
2024-10-25 20:40:59.767 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.769 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 8, query_type 16 (ID 3420)
2024-10-25 20:40:59.778 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.780 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 9, query_type 1 (ID 3421)
2024-10-25 20:40:59.797 CEST [423320M] DEBUG_GC: RECYCLE[dns_cache] is empty
2024-10-25 20:40:59.799 CEST [423320M] DEBUG_GC: New cache entry: domainID 2132, clientID 9, query_type 16 (ID 3422)

out of which the first five have reused the recycled records from above and then four new ones are created.

2024-10-25 20:41:58.873 CEST [423320/T423324] INFO: Recycle list fullness:
2024-10-25 20:41:58.874 CEST [423320/T423324] INFO: Clients: 0/1024 (0.00%)
2024-10-25 20:41:58.874 CEST [423320/T423324] INFO: Domains: 0/1024 (0.00%)
2024-10-25 20:41:58.875 CEST [423320/T423324] INFO: DNS Cache: 0/1024 (0.00%)

You are seeing zero available recycled IDs here as all of them have already been used before you've sent SIGRT7.

@yubiuser
Copy link
Member

Ok. I think I misunderstood how to interpret the logs

@DL6ER DL6ER merged commit f916fc6 into development Oct 26, 2024
19 checks passed
@DL6ER DL6ER deleted the tweak/table_IDs branch October 26, 2024 18:17
@PromoFaux PromoFaux mentioned this pull request Feb 18, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants