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.

Sign up for GitHub

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

Jump to bottom

Caching appears to not be working #417

Open
ryancastro opened this issue Sep 6, 2024 · 1 comment
Open

Caching appears to not be working #417

ryancastro opened this issue Sep 6, 2024 · 1 comment

Comments

@ryancastro
Copy link

Pulled master as of today, and built with sudo go run main.go --config-path=config.yaml --verbose.

I run with the included configuration file, and then I simply hit the server with two dns questions over TLS. Both for google.com. Both requests make a dial out to an upstream provider, rather than using the cache, despite the cache being clearly enabled. Am I simply misunderstanding how caching works? That'd be embarrassing.

Here's some simple reproduction:

# TLS Configuration
tls-crt: fullchain.pem
tls-key: privkey.pem
tls-port: 
  - 853
https-port:
  - 443

# DNS Servers
# timeout: 2s # timeout for upstream dns request
upstream:
  - "1.1.1.1:53"
  - "8.8.8.8:53"
bootstrap:
  - "1.1.1.1:53"
  - "8.8.8.8:53"

# Cache
cache: true
cache-min-ttl: 60
cache-size: 64
ratelimit: 20

Run with Doggo:
doggo google.com @tls://mydomain.example.com --time

Here is my verbose output:

Server start:

2024/09/06 11:45:52.910249 INFO dnsproxy starting version="" revision="" branch="" commit_time=""
2024/09/06 11:45:52.910496 DEBUG hosts files are enabled
2024/09/06 11:45:52.910508 DEBUG hosts files are not specified, using default paths=[private/etc/hosts]
2024/09/06 11:45:52.910830 DEBUG set upstream idx=0 addr=1.1.1.1:53
2024/09/06 11:45:52.910839 DEBUG set upstream idx=1 addr=8.8.8.8:53
2024/09/06 11:45:52.911905 INFO cache ttl override is enabled prefix=dnsproxy min=60 max=0
2024/09/06 11:45:52.911917 INFO ratelimit is enabled prefix=dnsproxy rps=20 ipv4_subnet_mask_len=24 ipv6_subnet_mask_len=56
2024/09/06 11:45:52.911941 INFO upstream mode is set prefix=dnsproxy mode=load_balance
2024/09/06 11:45:52.911946 INFO cache enabled prefix=dnsproxy size=64
2024/09/06 11:45:52.911951 INFO starting dns proxy server prefix=dnsproxy
2024/09/06 11:45:52.911989 INFO creating udp server socket prefix=dnsproxy addr=0.0.0.0:53
2024/09/06 11:45:52.912322 INFO listening to udp prefix=dnsproxy addr=[::]:53

Requests (two requests):

2024/09/06 11:46:18.240713 DEBUG handling request prefix=default_handler req=";google.com.\tIN\t A"
2024/09/06 11:46:18.240725 DEBUG no hosts records found prefix=default_handler name=google.com qtype=1
2024/09/06 11:46:18.240799 DEBUG sending request addr=8.8.8.8:53 proto=udp qtype=A qname=google.com.
2024/09/06 11:46:18.240815 DEBUG dialing prefix=bootstrap addr=8.8.8.8:53 idx=1 total=1
2024/09/06 11:46:18.241052 DEBUG connection succeeded prefix=bootstrap addr=8.8.8.8:53 elapsed=224.834µs
2024/09/06 11:46:18.268331 DEBUG response received addr=8.8.8.8:53 proto=udp status=ok
2024/09/06 11:46:18.268399 DEBUG exchange successfully finished prefix=dnsproxy upstream=8.8.8.8:53 question=";google.com.\tIN\t A" duration=27.627042ms
2024/09/06 11:46:18.268417 DEBUG resolved prefix=dnsproxy src=upstream rtt=27.678042ms
2024/09/06 11:46:18.268427 DEBUG ttl overwritten prefix=dnsproxy old=45 new=60
2024/09/06 11:46:18.268474 DEBUG out prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 47072"
2024/09/06 11:46:18.268483 DEBUG out prefix=dnsproxy line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0"
2024/09/06 11:46:18.268487 DEBUG out prefix=dnsproxy line_num=3 line=""
2024/09/06 11:46:18.268490 DEBUG out prefix=dnsproxy line_num=4 line=";; QUESTION SECTION:"
2024/09/06 11:46:18.268493 DEBUG out prefix=dnsproxy line_num=5 line=";google.com.\tIN\t A"
2024/09/06 11:46:18.268554 DEBUG out prefix=dnsproxy line_num=6 line=""
2024/09/06 11:46:18.268571 DEBUG out prefix=dnsproxy line_num=7 line=";; ANSWER SECTION:"
2024/09/06 11:46:18.268576 DEBUG out prefix=dnsproxy line_num=8 line="google.com.\t60\tIN\tA\t142.250.188.14"
2024/09/06 11:46:18.268580 DEBUG out prefix=dnsproxy line_num=9 line=""
2024/09/06 11:46:18.269464 DEBUG connection is closed prefix=dnsproxy proto=tcp details="reading msg" err="reading len: EOF"
2024/09/06 11:47:35.106258 DEBUG handling new request prefix=dnsproxy proto=tls raddr=127.0.0.1:64826
2024/09/06 11:47:35.117224 DEBUG in prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 55618"
2024/09/06 11:47:35.117263 DEBUG in prefix=dnsproxy line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0"
2024/09/06 11:47:35.117268 DEBUG in prefix=dnsproxy line_num=3 line=""
2024/09/06 11:47:35.117273 DEBUG in prefix=dnsproxy line_num=4 line=";; QUESTION SECTION:"
2024/09/06 11:47:35.117277 DEBUG in prefix=dnsproxy line_num=5 line=";google.com.\tIN\t A"
2024/09/06 11:47:35.117281 DEBUG in prefix=dnsproxy line_num=6 line=""
2024/09/06 11:47:35.117552 DEBUG handling request prefix=default_handler req=";google.com.\tIN\t A"
2024/09/06 11:47:35.117571 DEBUG no hosts records found prefix=default_handler name=google.com qtype=1
2024/09/06 11:47:35.117649 DEBUG sending request addr=8.8.8.8:53 proto=udp qtype=A qname=google.com.
2024/09/06 11:47:35.117696 DEBUG dialing prefix=bootstrap addr=8.8.8.8:53 idx=1 total=1
2024/09/06 11:47:35.118238 DEBUG connection succeeded prefix=bootstrap addr=8.8.8.8:53 elapsed=515.209µs
2024/09/06 11:47:35.143151 DEBUG response received addr=8.8.8.8:53 proto=udp status=ok
2024/09/06 11:47:35.143215 DEBUG exchange successfully finished prefix=dnsproxy upstream=8.8.8.8:53 question=";google.com.\tIN\t A" duration=25.595083ms
2024/09/06 11:47:35.143230 DEBUG resolved prefix=dnsproxy src=upstream rtt=25.644625ms
2024/09/06 11:47:35.143339 DEBUG out prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 55618"
2024/09/06 11:47:35.143366 DEBUG out prefix=dnsproxy line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0"
2024/09/06 11:47:35.143372 DEBUG out prefix=dnsproxy line_num=3 line=""
2024/09/06 11:47:35.143375 DEBUG out prefix=dnsproxy line_num=4 line=";; QUESTION SECTION:"
2024/09/06 11:47:35.143379 DEBUG out prefix=dnsproxy line_num=5 line=";google.com.\tIN\t A"
2024/09/06 11:47:35.143383 DEBUG out prefix=dnsproxy line_num=6 line=""
2024/09/06 11:47:35.143386 DEBUG out prefix=dnsproxy line_num=7 line=";; ANSWER SECTION:"
2024/09/06 11:47:35.143390 DEBUG out prefix=dnsproxy line_num=8 line="google.com.\t269\tIN\tA\t142.251.46.238"
2024/09/06 11:47:35.143393 DEBUG out prefix=dnsproxy line_num=9 line=""
2024/09/06 11:47:35.143777 DEBUG connection is closed prefix=dnsproxy proto=tcp details="reading msg" err="reading len: EOF"
@timkgh
Copy link

timkgh commented Sep 16, 2024 •
edited
Loading

My guess is that cache-size: 64 is not enough. That's 64 bytes, not entries. Try something bigger, e.g. 64000 or don't specify it, 64K is default.
--cache-size= Cache size (in bytes). Default: 64k

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ryancastro @timkgh