dns record keep getting from cache with ttl=10

[VDuyHoang]

Hi,
At the beginning, the service is fine, all working as expected. But within 2 or 3 days, some domain keep getting from cache data with ttl=10. If i restart the agh, it will work correctly again. And after some days, the issue happens again.
AGH docker run on rocky linux 9 with out any filter.
Upstream DNS:

• tls://8.8.4.4
• quic://94.140.14.141
  TTL min=3600
  Some verbose logs:

2024/12/03 12:49:01.368846 1#15320 [debug] dnsforward: started processing querylog and stats
2024/12/03 12:49:01.368928 1#15320 [debug] dnsforward: client ip for stats and querylog: 10.88.0.1
2024/12/03 12:49:01.369124 1#15320 [debug] dnsforward: finished processing querylog and stats
2024/12/03 12:49:01.369307 1#15320 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 8924"
2024/12/03 12:49:01.369429 1#15320 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:01.369542 1#15320 [debug] dnsproxy: out line_num=3 line=""
2024/12/03 12:49:01.369657 1#15320 [debug] dnsproxy: out line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:01.369756 1#15320 [debug] dnsproxy: out line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:01.369859 1#15320 [debug] dnsproxy: out line_num=6 line=""
2024/12/03 12:49:01.369979 1#15320 [debug] dnsproxy: out line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:01.370089 1#15320 [debug] dnsproxy: out line_num=8 line=";Inbox.gooGLE.coM.\tIN\t A"
2024/12/03 12:49:01.370182 1#15320 [debug] dnsproxy: out line_num=9 line=""
2024/12/03 12:49:01.370296 1#15320 [debug] dnsproxy: out line_num=10 line=";; ANSWER SECTION:"
2024/12/03 12:49:01.370395 1#15320 [debug] dnsproxy: out line_num=11 line="inbox.google.com.\t10\tIN\tA\t142.251.42.197"
2024/12/03 12:49:01.370487 1#15320 [debug] dnsproxy: out line_num=12 line=""
2024/12/03 12:49:01.389782 1#15321 [debug] dnsproxy: resolved src=upstream rtt=21.259704ms
2024/12/03 12:49:01.390015 1#15321 [debug] dnsproxy: ttl overwritten old=136 new=3600
2024/12/03 12:49:01.390158 1#15321 [debug] dnsproxy: ttl overwritten old=136 new=3600
2024/12/03 12:49:01.390279 1#15321 [debug] dnsproxy: ttl overwritten old=136 new=3600
2024/12/03 12:49:01.390388 1#15321 [debug] dnsproxy: ttl overwritten old=136 new=3600
2024/12/03 12:49:01.390519 1#15321 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:01.390637 1#15321 [debug] dnsproxy: ecs option in response ecs=171.253.128.0/20
2024/12/03 12:49:06.762626 1#15322 [debug] dnsproxy: handling new udp packet raddr=10.88.0.1:44573
2024/12/03 12:49:06.762930 1#15322 [debug] dnsproxy: in line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 5361"
2024/12/03 12:49:06.763097 1#15322 [debug] dnsproxy: in line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:06.763234 1#15322 [debug] dnsproxy: in line_num=3 line=""
2024/12/03 12:49:06.763357 1#15322 [debug] dnsproxy: in line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:06.763471 1#15322 [debug] dnsproxy: in line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:06.763587 1#15322 [debug] dnsproxy: in line_num=6 line=""
2024/12/03 12:49:06.763703 1#15322 [debug] dnsproxy: in line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:06.763816 1#15322 [debug] dnsproxy: in line_num=8 line=";iNBox.google.COM.\tIN\t A"
2024/12/03 12:49:06.763928 1#15322 [debug] dnsproxy: in line_num=9 line=""
2024/12/03 12:49:06.764065 1#15322 [debug] dnsforward: started processing initial
2024/12/03 12:49:06.764227 1#15322 [debug] applying filters: looking for client with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:06.764391 1#15322 [debug] applying filters: no clients with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:06.764472 1#5855 [debug] addrproc: processing rdns ip=10.88.0.1
2024/12/03 12:49:06.764489 1#15322 [debug] dnsforward: finished processing initial
2024/12/03 12:49:06.764634 1#5855 [debug] addrproc: finished processing rdns ip=10.88.0.1 host="" elapsed=250.136µs
2024/12/03 12:49:06.764704 1#15322 [debug] dnsforward: started processing ddr
2024/12/03 12:49:06.764789 1#5855 [debug] addrproc: processing whois ip=10.88.0.1
2024/12/03 12:49:06.764800 1#15322 [debug] dnsforward: finished processing ddr
2024/12/03 12:49:06.764877 1#15322 [debug] dnsforward: started processing dhcp hosts
2024/12/03 12:49:06.765002 1#15322 [debug] dnsforward: finished processing dhcp hosts
2024/12/03 12:49:06.765083 1#15322 [debug] dnsforward: started processing dhcp addrs
2024/12/03 12:49:06.765005 1#5855 [debug] addrproc: finished processing whois ip=10.88.0.1 whois= elapsed=152.94µs
2024/12/03 12:49:06.765167 1#15322 [debug] dnsforward: finished processing dhcp addrs
2024/12/03 12:49:06.765231 1#15322 [debug] dnsforward: started processing filtering before req
2024/12/03 12:49:06.765299 1#15322 [debug] dnsforward: finished processing filtering before req
2024/12/03 12:49:06.765355 1#15322 [debug] dnsforward: started processing upstream
2024/12/03 12:49:06.765563 1#15322 [debug] dnsproxy: setting ecs subnet=171.253.128.0/24
2024/12/03 12:49:06.765700 1#15322 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:06.765802 1#15322 [debug] dnsproxy: replying from cache ecs_enabled=true
2024/12/03 12:49:06.765883 1#15322 [debug] dnsforward: finished processing upstream
2024/12/03 12:49:06.766004 1#15322 [debug] dnsforward: started processing filtering after resp
2024/12/03 12:49:06.766135 1#15322 [debug] dnsforward: finished processing filtering after resp
2024/12/03 12:49:06.766316 1#15322 [debug] ipset: started processing
2024/12/03 12:49:06.766441 1#15322 [debug] ipset: finished processing
2024/12/03 12:49:06.766517 1#15322 [debug] dnsforward: started processing querylog and stats
2024/12/03 12:49:06.766604 1#15322 [debug] dnsforward: client ip for stats and querylog: 10.88.0.1
2024/12/03 12:49:06.766752 1#15322 [debug] dnsforward: finished processing querylog and stats
2024/12/03 12:49:06.766906 1#15322 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 5361"
2024/12/03 12:49:06.767064 1#15322 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:06.767200 1#15322 [debug] dnsproxy: out line_num=3 line=""
2024/12/03 12:49:06.767315 1#15322 [debug] dnsproxy: out line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:06.767429 1#15322 [debug] dnsproxy: out line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:06.767525 1#15322 [debug] dnsproxy: out line_num=6 line=""
2024/12/03 12:49:06.767621 1#15322 [debug] dnsproxy: out line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:06.767728 1#15322 [debug] dnsproxy: out line_num=8 line=";iNBox.google.COM.\tIN\t A"
2024/12/03 12:49:06.767823 1#15322 [debug] dnsproxy: out line_num=9 line=""
2024/12/03 12:49:06.767916 1#15322 [debug] dnsproxy: out line_num=10 line=";; ANSWER SECTION:"
2024/12/03 12:49:06.768052 1#15322 [debug] dnsproxy: out line_num=11 line="inbox.google.com.\t10\tIN\tA\t142.251.42.197"
2024/12/03 12:49:06.768165 1#15322 [debug] dnsproxy: out line_num=12 line=""
2024/12/03 12:49:06.788090 1#15323 [debug] dnsproxy: resolved src=upstream rtt=21.979698ms
2024/12/03 12:49:06.788250 1#15323 [debug] dnsproxy: ttl overwritten old=131 new=3600
2024/12/03 12:49:06.788348 1#15323 [debug] dnsproxy: ttl overwritten old=131 new=3600
2024/12/03 12:49:06.788440 1#15323 [debug] dnsproxy: ttl overwritten old=131 new=3600
2024/12/03 12:49:06.788531 1#15323 [debug] dnsproxy: ttl overwritten old=131 new=3600
2024/12/03 12:49:06.788656 1#15323 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:06.788754 1#15323 [debug] dnsproxy: ecs option in response ecs=171.253.128.0/20
2024/12/03 12:49:09.135440 1#15324 [debug] dnsproxy: handling new udp packet raddr=10.88.0.1:53489
2024/12/03 12:49:09.135795 1#15324 [debug] dnsproxy: in line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 63470"
2024/12/03 12:49:09.136044 1#15324 [debug] dnsproxy: in line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:09.136284 1#15324 [debug] dnsproxy: in line_num=3 line=""
2024/12/03 12:49:09.136496 1#15324 [debug] dnsproxy: in line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:09.136657 1#15324 [debug] dnsproxy: in line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:09.136765 1#15324 [debug] dnsproxy: in line_num=6 line=""
2024/12/03 12:49:09.136861 1#15324 [debug] dnsproxy: in line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:09.136992 1#15324 [debug] dnsproxy: in line_num=8 line=";iNBOx.googlE.cOm.\tIN\t A"
2024/12/03 12:49:09.137107 1#15324 [debug] dnsproxy: in line_num=9 line=""
2024/12/03 12:49:09.137197 1#15324 [debug] dnsforward: started processing initial
2024/12/03 12:49:09.137333 1#15324 [debug] applying filters: looking for client with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:09.137575 1#15324 [debug] applying filters: no clients with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:09.137666 1#15324 [debug] dnsforward: finished processing initial
2024/12/03 12:49:09.137582 1#5855 [debug] addrproc: processing rdns ip=10.88.0.1
2024/12/03 12:49:09.137816 1#15324 [debug] dnsforward: started processing ddr
2024/12/03 12:49:09.137892 1#5855 [debug] addrproc: finished processing rdns ip=10.88.0.1 host="" elapsed=366.384µs
2024/12/03 12:49:09.138016 1#15324 [debug] dnsforward: finished processing ddr
2024/12/03 12:49:09.138116 1#5855 [debug] addrproc: processing whois ip=10.88.0.1
2024/12/03 12:49:09.138185 1#15324 [debug] dnsforward: started processing dhcp hosts
2024/12/03 12:49:09.138350 1#5855 [debug] addrproc: finished processing whois ip=10.88.0.1 whois= elapsed=225.387µs
2024/12/03 12:49:09.138361 1#15324 [debug] dnsforward: finished processing dhcp hosts
2024/12/03 12:49:09.138444 1#15324 [debug] dnsforward: started processing dhcp addrs
2024/12/03 12:49:09.138506 1#15324 [debug] dnsforward: finished processing dhcp addrs
2024/12/03 12:49:09.138563 1#15324 [debug] dnsforward: started processing filtering before req
2024/12/03 12:49:09.138630 1#15324 [debug] dnsforward: finished processing filtering before req
2024/12/03 12:49:09.138685 1#15324 [debug] dnsforward: started processing upstream
2024/12/03 12:49:09.138890 1#15324 [debug] dnsproxy: setting ecs subnet=171.253.128.0/24
2024/12/03 12:49:09.139062 1#15324 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:09.139180 1#15324 [debug] dnsproxy: replying from cache ecs_enabled=true
2024/12/03 12:49:09.139285 1#15324 [debug] dnsforward: finished processing upstream
2024/12/03 12:49:09.139392 1#15324 [debug] dnsforward: started processing filtering after resp
2024/12/03 12:49:09.139504 1#15324 [debug] dnsforward: finished processing filtering after resp
2024/12/03 12:49:09.139681 1#15324 [debug] ipset: started processing
2024/12/03 12:49:09.139812 1#15324 [debug] ipset: finished processing
2024/12/03 12:49:09.139875 1#15324 [debug] dnsforward: started processing querylog and stats
2024/12/03 12:49:09.139967 1#15324 [debug] dnsforward: client ip for stats and querylog: 10.88.0.1
2024/12/03 12:49:09.140113 1#15324 [debug] dnsforward: finished processing querylog and stats
2024/12/03 12:49:09.140251 1#15324 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 63470"
2024/12/03 12:49:09.140352 1#15324 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:09.140446 1#15324 [debug] dnsproxy: out line_num=3 line=""
2024/12/03 12:49:09.140565 1#15324 [debug] dnsproxy: out line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:09.140661 1#15324 [debug] dnsproxy: out line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:09.140756 1#15324 [debug] dnsproxy: out line_num=6 line=""
2024/12/03 12:49:09.140849 1#15324 [debug] dnsproxy: out line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:09.140942 1#15324 [debug] dnsproxy: out line_num=8 line=";iNBOx.googlE.cOm.\tIN\t A"
2024/12/03 12:49:09.141079 1#15324 [debug] dnsproxy: out line_num=9 line=""
2024/12/03 12:49:09.141173 1#15324 [debug] dnsproxy: out line_num=10 line=";; ANSWER SECTION:"
2024/12/03 12:49:09.141266 1#15324 [debug] dnsproxy: out line_num=11 line="inbox.google.com.\t10\tIN\tA\t142.251.42.197"
2024/12/03 12:49:09.141358 1#15324 [debug] dnsproxy: out line_num=12 line=""
2024/12/03 12:49:09.161229 1#15325 [debug] dnsproxy: resolved src=upstream rtt=21.749725ms
2024/12/03 12:49:09.161389 1#15325 [debug] dnsproxy: ttl overwritten old=128 new=3600
2024/12/03 12:49:09.161489 1#15325 [debug] dnsproxy: ttl overwritten old=128 new=3600
2024/12/03 12:49:09.161583 1#15325 [debug] dnsproxy: ttl overwritten old=128 new=3600
2024/12/03 12:49:09.161674 1#15325 [debug] dnsproxy: ttl overwritten old=128 new=3600
2024/12/03 12:49:09.161779 1#15325 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:09.161879 1#15325 [debug] dnsproxy: ecs option in response ecs=171.253.128.0/20
2024/12/03 12:49:11.551227 1#15326 [debug] dnsproxy: handling new udp packet raddr=10.88.0.1:60393
2024/12/03 12:49:11.551448 1#15326 [debug] dnsproxy: in line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 60399"
2024/12/03 12:49:11.551556 1#15326 [debug] dnsproxy: in line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:11.551652 1#15326 [debug] dnsproxy: in line_num=3 line=""
2024/12/03 12:49:11.551744 1#15326 [debug] dnsproxy: in line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:11.551838 1#15326 [debug] dnsproxy: in line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:11.551930 1#15326 [debug] dnsproxy: in line_num=6 line=""
2024/12/03 12:49:11.552043 1#15326 [debug] dnsproxy: in line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:11.552149 1#15326 [debug] dnsproxy: in line_num=8 line=";inBoX.googLE.CoM.\tIN\t A"
2024/12/03 12:49:11.552246 1#15326 [debug] dnsproxy: in line_num=9 line=""
2024/12/03 12:49:11.552336 1#15326 [debug] dnsforward: started processing initial
2024/12/03 12:49:11.552472 1#15326 [debug] applying filters: looking for client with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:11.552692 1#15326 [debug] applying filters: no clients with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:11.552717 1#5855 [debug] addrproc: processing rdns ip=10.88.0.1
2024/12/03 12:49:11.552847 1#15326 [debug] dnsforward: finished processing initial
2024/12/03 12:49:11.552985 1#5855 [debug] addrproc: finished processing rdns ip=10.88.0.1 host="" elapsed=261.166µs
2024/12/03 12:49:11.553022 1#15326 [debug] dnsforward: started processing ddr
2024/12/03 12:49:11.553208 1#15326 [debug] dnsforward: finished processing ddr
2024/12/03 12:49:11.553234 1#5855 [debug] addrproc: processing whois ip=10.88.0.1
2024/12/03 12:49:11.553335 1#15326 [debug] dnsforward: started processing dhcp hosts
2024/12/03 12:49:11.553481 1#5855 [debug] addrproc: finished processing whois ip=10.88.0.1 whois= elapsed=231.437µs
2024/12/03 12:49:11.553507 1#15326 [debug] dnsforward: finished processing dhcp hosts
2024/12/03 12:49:11.553583 1#15326 [debug] dnsforward: started processing dhcp addrs
2024/12/03 12:49:11.553644 1#15326 [debug] dnsforward: finished processing dhcp addrs
2024/12/03 12:49:11.553700 1#15326 [debug] dnsforward: started processing filtering before req
2024/12/03 12:49:11.553766 1#15326 [debug] dnsforward: finished processing filtering before req
2024/12/03 12:49:11.553824 1#15326 [debug] dnsforward: started processing upstream
2024/12/03 12:49:11.554056 1#15326 [debug] dnsproxy: setting ecs subnet=171.253.128.0/24
2024/12/03 12:49:11.554233 1#15326 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:11.554338 1#15326 [debug] dnsproxy: replying from cache ecs_enabled=true
2024/12/03 12:49:11.554446 1#15326 [debug] dnsforward: finished processing upstream
2024/12/03 12:49:11.554553 1#15326 [debug] dnsforward: started processing filtering after resp
2024/12/03 12:49:11.554665 1#15326 [debug] dnsforward: finished processing filtering after resp
2024/12/03 12:49:11.554843 1#15326 [debug] ipset: started processing
2024/12/03 12:49:11.554993 1#15326 [debug] ipset: finished processing
2024/12/03 12:49:11.555071 1#15326 [debug] dnsforward: started processing querylog and stats
2024/12/03 12:49:11.555140 1#15326 [debug] dnsforward: client ip for stats and querylog: 10.88.0.1
2024/12/03 12:49:11.555267 1#15326 [debug] dnsforward: finished processing querylog and stats
2024/12/03 12:49:11.555398 1#15326 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 60399"
2024/12/03 12:49:11.555497 1#15326 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:11.555592 1#15326 [debug] dnsproxy: out line_num=3 line=""
2024/12/03 12:49:11.555685 1#15326 [debug] dnsproxy: out line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:11.555779 1#15326 [debug] dnsproxy: out line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:11.555871 1#15326 [debug] dnsproxy: out line_num=6 line=""
2024/12/03 12:49:11.555983 1#15326 [debug] dnsproxy: out line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:11.556090 1#15326 [debug] dnsproxy: out line_num=8 line=";inBoX.googLE.CoM.\tIN\t A"
2024/12/03 12:49:11.556183 1#15326 [debug] dnsproxy: out line_num=9 line=""
2024/12/03 12:49:11.556276 1#15326 [debug] dnsproxy: out line_num=10 line=";; ANSWER SECTION:"
2024/12/03 12:49:11.556371 1#15326 [debug] dnsproxy: out line_num=11 line="inbox.google.com.\t10\tIN\tA\t142.251.42.197"
2024/12/03 12:49:11.556463 1#15326 [debug] dnsproxy: out line_num=12 line=""
2024/12/03 12:49:11.576703 1#15327 [debug] dnsproxy: resolved src=upstream rtt=22.027579ms
2024/12/03 12:49:11.576900 1#15327 [debug] dnsproxy: ttl overwritten old=126 new=3600
2024/12/03 12:49:11.577059 1#15327 [debug] dnsproxy: ttl overwritten old=126 new=3600
2024/12/03 12:49:11.577199 1#15327 [debug] dnsproxy: ttl overwritten old=126 new=3600
2024/12/03 12:49:11.577314 1#15327 [debug] dnsproxy: ttl overwritten old=126 new=3600
2024/12/03 12:49:11.577447 1#15327 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:11.577563 1#15327 [debug] dnsproxy: ecs option in response ecs=171.253.128.0/20
2024/12/03 12:49:15.768425 1#15328 [debug] dnsproxy: handling new udp packet raddr=10.88.0.1:49007
2024/12/03 12:49:15.768717 1#15328 [debug] dnsproxy: in line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 20297"
2024/12/03 12:49:15.768865 1#15328 [debug] dnsproxy: in line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:15.769020 1#15328 [debug] dnsproxy: in line_num=3 line=""
2024/12/03 12:49:15.769165 1#15328 [debug] dnsproxy: in line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:15.769281 1#15328 [debug] dnsproxy: in line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:15.769393 1#15328 [debug] dnsproxy: in line_num=6 line=""
2024/12/03 12:49:15.769513 1#15328 [debug] dnsproxy: in line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:15.769626 1#15328 [debug] dnsproxy: in line_num=8 line=";INbOx.GOOGle.Com.\tIN\t A"
2024/12/03 12:49:15.769735 1#15328 [debug] dnsproxy: in line_num=9 line=""
2024/12/03 12:49:15.769840 1#15328 [debug] dnsforward: started processing initial
2024/12/03 12:49:15.769984 1#15328 [debug] applying filters: looking for client with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:15.770188 1#5855 [debug] addrproc: processing rdns ip=10.88.0.1
2024/12/03 12:49:15.770198 1#15328 [debug] applying filters: no clients with ip 10.88.0.1 and clientid ""
2024/12/03 12:49:15.770431 1#15328 [debug] dnsforward: finished processing initial
2024/12/03 12:49:15.770330 1#5855 [debug] addrproc: finished processing rdns ip=10.88.0.1 host="" elapsed=230.71µs
2024/12/03 12:49:15.770512 1#15328 [debug] dnsforward: started processing ddr
2024/12/03 12:49:15.770604 1#5855 [debug] addrproc: processing whois ip=10.88.0.1
2024/12/03 12:49:15.770647 1#15328 [debug] dnsforward: finished processing ddr
2024/12/03 12:49:15.770734 1#5855 [debug] addrproc: finished processing whois ip=10.88.0.1 whois= elapsed=146.124µs
2024/12/03 12:49:15.770768 1#15328 [debug] dnsforward: started processing dhcp hosts
2024/12/03 12:49:15.770854 1#15328 [debug] dnsforward: finished processing dhcp hosts
2024/12/03 12:49:15.770929 1#15328 [debug] dnsforward: started processing dhcp addrs
2024/12/03 12:49:15.771024 1#15328 [debug] dnsforward: finished processing dhcp addrs
2024/12/03 12:49:15.771108 1#15328 [debug] dnsforward: started processing filtering before req
2024/12/03 12:49:15.771192 1#15328 [debug] dnsforward: finished processing filtering before req
2024/12/03 12:49:15.771265 1#15328 [debug] dnsforward: started processing upstream
2024/12/03 12:49:15.771516 1#15328 [debug] dnsproxy: setting ecs subnet=171.253.128.0/24
2024/12/03 12:49:15.771684 1#15328 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:15.771809 1#15328 [debug] dnsproxy: replying from cache ecs_enabled=true
2024/12/03 12:49:15.771904 1#15328 [debug] dnsforward: finished processing upstream
2024/12/03 12:49:15.771999 1#15328 [debug] dnsforward: started processing filtering after resp
2024/12/03 12:49:15.772115 1#15328 [debug] dnsforward: finished processing filtering after resp
2024/12/03 12:49:15.772281 1#15328 [debug] ipset: started processing
2024/12/03 12:49:15.772418 1#15328 [debug] ipset: finished processing
2024/12/03 12:49:15.772494 1#15328 [debug] dnsforward: started processing querylog and stats
2024/12/03 12:49:15.772581 1#15328 [debug] dnsforward: client ip for stats and querylog: 10.88.0.1
2024/12/03 12:49:15.772718 1#15328 [debug] dnsforward: finished processing querylog and stats
2024/12/03 12:49:15.772884 1#15328 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 20297"
2024/12/03 12:49:15.773041 1#15328 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
2024/12/03 12:49:15.773158 1#15328 [debug] dnsproxy: out line_num=3 line=""
2024/12/03 12:49:15.773270 1#15328 [debug] dnsproxy: out line_num=4 line=";; OPT PSEUDOSECTION:"
2024/12/03 12:49:15.773367 1#15328 [debug] dnsproxy: out line_num=5 line="; EDNS: version 0; flags:; udp: 1232"
2024/12/03 12:49:15.773475 1#15328 [debug] dnsproxy: out line_num=6 line=""
2024/12/03 12:49:15.773572 1#15328 [debug] dnsproxy: out line_num=7 line=";; QUESTION SECTION:"
2024/12/03 12:49:15.773666 1#15328 [debug] dnsproxy: out line_num=8 line=";INbOx.GOOGle.Com.\tIN\t A"
2024/12/03 12:49:15.773758 1#15328 [debug] dnsproxy: out line_num=9 line=""
2024/12/03 12:49:15.773869 1#15328 [debug] dnsproxy: out line_num=10 line=";; ANSWER SECTION:"
2024/12/03 12:49:15.773989 1#15328 [debug] dnsproxy: out line_num=11 line="inbox.google.com.\t10\tIN\tA\t142.251.42.197"
2024/12/03 12:49:15.774096 1#15328 [debug] dnsproxy: out line_num=12 line=""
2024/12/03 12:49:15.793771 1#15345 [debug] dnsproxy: resolved src=upstream rtt=21.608949ms
2024/12/03 12:49:15.793931 1#15345 [debug] dnsproxy: ttl overwritten old=122 new=3600
2024/12/03 12:49:15.794083 1#15345 [debug] dnsproxy: ttl overwritten old=122 new=3600
2024/12/03 12:49:15.794190 1#15345 [debug] dnsproxy: ttl overwritten old=122 new=3600
2024/12/03 12:49:15.794283 1#15345 [debug] dnsproxy: ttl overwritten old=122 new=3600
2024/12/03 12:49:15.794389 1#15345 [debug] legacy logger: got prefix "cache" in record for logger with prefix "dnsproxy"
2024/12/03 12:49:15.794485 1#15345 [debug] dnsproxy: ecs option in response ecs=171.253.128.0/20

[schzhn]

Disable the "Optimistic caching" setting.

Related #7428

[VDuyHoang]

yes, i see but

ttl overwritten old=126 new=3600

so after that it should be response with new data, shouldn't it ?

[schzhn]

Depending on ECS and other DNS options, DNS responses may be cached separately.
https://github.com/AdguardTeam/dnsproxy/blob/f901a5f4b9e8d5f143dce459067bc6614c6d927d/proxy/cache.go#L530

[VDuyHoang]

Thank you, got it