Retries do not work properly #141

New Issue

Closed

opened 2022-10-16 13:45:53 +00:00 by sam · 0 comments

sam commented

2022-10-16 13:45:53 +00:00

Owner

Describe the bug
Retries do not work properly

Reproduction steps
Steps to reproduce the behavior:

Make a request that will fail the first time (eg. gets truncated)
Notice the request fails for a different reason

Expected behaviour
If the request fails again, it should fail for the same reason.

Screenshots / Logs

INFO [2022/10/16 15:45:25]: POSIX flags parsed
DEBUG [2022/10/16 15:45:25]: {Logger:0xc0000b82d0 TLSHost: EDNS:{Subnet:{Code:0 Family:0 SourceNetmask:0 SourceScope:0 Address:<nil>} ZFlag:0 BufSize:1232 EnableEDNS:true Cookie:true DNSSEC:false Expire:false KeepOpen:false Nsid:false Padding:false Version:0} Request:{Server: Name: Timeout:1s Port:0 Retries:2 Type:0 Class:1} Verbosity:0 Display:{Comments:true Question:true Opt:true Answer:true Authority:true Additional:true Statistics:true TTL:true ShowClass:false ShowQuery:false HumanTTL:false UcodeTranslate:false} Truncate:false BadCookie:false Short:false Identify:false Reverse:false HeaderFlags:{AA:false AD:false CD:false QR:false RD:true RA:false TC:false Z:false} JSON:false XML:false YAML:false TCP:false TLS:false TLSNoVerify:false HTTPS:false QUIC:false DNSCrypt:false IPv4:false IPv6:false}
INFO [2022/10/16 15:45:25]: 127.0.0.2 detected as a server
INFO [2022/10/16 15:45:25]: Domain not specified, making a default
INFO [2022/10/16 15:45:25]: Query not specified, making an "NS" query
INFO [2022/10/16 15:45:25]: DNS server set to 127.0.0.2
INFO [2022/10/16 15:45:25]: Dig/Drill flags parsed
DEBUG [2022/10/16 15:45:25]: {Logger:0xc0000b82d0 TLSHost: EDNS:{Subnet:{Code:0 Family:0 SourceNetmask:0 SourceScope:0 Address:<nil>} ZFlag:0 BufSize:1232 EnableEDNS:true Cookie:true DNSSEC:false Expire:false KeepOpen:false Nsid:false Padding:false Version:0} Request:{Server:127.0.0.2 Name:. Timeout:1s Port:0 Retries:2 Type:2 Class:1} Verbosity:0 Display:{Comments:true Question:true Opt:true Answer:true Authority:true Additional:true Statistics:true TTL:true ShowClass:false ShowQuery:false HumanTTL:false UcodeTranslate:false} Truncate:false BadCookie:false Short:false Identify:false Reverse:false HeaderFlags:{AA:false AD:false CD:false QR:false RD:true RA:false TC:false Z:false} JSON:false XML:false YAML:false TCP:false TLS:false TLSNoVerify:false HTTPS:false QUIC:false DNSCrypt:false IPv4:false IPv6:false}
INFO [2022/10/16 15:45:25]: Port set to 53
INFO [2022/10/16 15:45:25]: Options fully populated
DEBUG [2022/10/16 15:45:25]: {Logger:0xc0000b82d0 TLSHost: EDNS:{Subnet:{Code:0 Family:0 SourceNetmask:0 SourceScope:0 Address:<nil>} ZFlag:0 BufSize:1232 EnableEDNS:true Cookie:true DNSSEC:false Expire:false KeepOpen:false Nsid:false Padding:false Version:0} Request:{Server:127.0.0.2 Name:. Timeout:1s Port:53 Retries:2 Type:2 Class:1} Verbosity:0 Display:{Comments:true Question:true Opt:true Answer:true Authority:true Additional:true Statistics:true TTL:true ShowClass:false ShowQuery:false HumanTTL:false UcodeTranslate:false} Truncate:false BadCookie:false Short:false Identify:false Reverse:false HeaderFlags:{AA:false AD:false CD:false QR:false RD:true RA:false TC:false Z:false} JSON:false XML:false YAML:false TCP:false TLS:false TLSNoVerify:false HTTPS:false QUIC:false DNSCrypt:false IPv4:false IPv6:false}
INFO [2022/10/16 15:45:25]: Setting EDNS cookie to 7d0c6e824624ab87
INFO [2022/10/16 15:45:25]: EDNS UDP buffer set to 1232
INFO [2022/10/16 15:45:25]: EDNS Z flag set to 0
DEBUG [2022/10/16 15:45:25]: ;; opcode: QUERY, status: NOERROR, id: 38965
;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 7d0c6e824624ab87

;; QUESTION SECTION:
;.      IN       NS

INFO [2022/10/16 15:45:25]: loading standard/DNS-over-TLS resolver
INFO [2022/10/16 15:45:25]: Query successfully loaded
INFO [2022/10/16 15:45:25]: Using udp for making the request
WARN [2022/10/16 15:45:25]: Retrying request, error: standard: DNS exchange: read udp 127.0.0.1:37383->127.0.0.2:53: read: connection refused
INFO [2022/10/16 15:45:25]: Setting EDNS cookie to b27a2a12681d669b
INFO [2022/10/16 15:45:25]: EDNS UDP buffer set to 1232
INFO [2022/10/16 15:45:25]: EDNS Z flag set to 0
DEBUG [2022/10/16 15:45:25]: ;; opcode: QUERY, status: NOERROR, id: 48256
;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: b27a2a12681d669b

;; QUESTION SECTION:
;.      IN       NS

INFO [2022/10/16 15:45:25]: loading standard/DNS-over-TLS resolver
INFO [2022/10/16 15:45:25]: Query successfully loaded
INFO [2022/10/16 15:45:25]: Using udp for making the request
WARN [2022/10/16 15:45:25]: Retrying request, error: standard: DNS exchange: dial udp: lookup 127.0.0.2:53: no such host
INFO [2022/10/16 15:45:25]: Setting EDNS cookie to a61c35be7faceed8
INFO [2022/10/16 15:45:25]: EDNS UDP buffer set to 1232
INFO [2022/10/16 15:45:25]: EDNS Z flag set to 0
DEBUG [2022/10/16 15:45:25]: ;; opcode: QUERY, status: NOERROR, id: 16643
;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: a61c35be7faceed8

;; QUESTION SECTION:
;.      IN       NS

INFO [2022/10/16 15:45:25]: loading standard/DNS-over-TLS resolver
INFO [2022/10/16 15:45:25]: Query successfully loaded
INFO [2022/10/16 15:45:25]: Using udp for making the request
ERROR [2022/10/16 15:45:25]: query: standard: DNS exchange: dial udp: address [[127.0.0.2:53]:53]:53: too many colons in address

System information (please complete the following information):

OS: Debian sid
Version: awl version 0.5.6.dirty, built with go1.19.2

Additional context
I suspect this to be caused by #132

**Describe the bug** Retries do not work properly **Reproduction steps** Steps to reproduce the behavior: 1. Make a request that will fail the first time (eg. gets truncated) 2. Notice the request fails for a different reason **Expected behaviour** If the request fails again, it should fail for the same reason. **Screenshots / Logs** ``` INFO [2022/10/16 15:45:25]: POSIX flags parsed DEBUG [2022/10/16 15:45:25]: {Logger:0xc0000b82d0 TLSHost: EDNS:{Subnet:{Code:0 Family:0 SourceNetmask:0 SourceScope:0 Address:<nil>} ZFlag:0 BufSize:1232 EnableEDNS:true Cookie:true DNSSEC:false Expire:false KeepOpen:false Nsid:false Padding:false Version:0} Request:{Server: Name: Timeout:1s Port:0 Retries:2 Type:0 Class:1} Verbosity:0 Display:{Comments:true Question:true Opt:true Answer:true Authority:true Additional:true Statistics:true TTL:true ShowClass:false ShowQuery:false HumanTTL:false UcodeTranslate:false} Truncate:false BadCookie:false Short:false Identify:false Reverse:false HeaderFlags:{AA:false AD:false CD:false QR:false RD:true RA:false TC:false Z:false} JSON:false XML:false YAML:false TCP:false TLS:false TLSNoVerify:false HTTPS:false QUIC:false DNSCrypt:false IPv4:false IPv6:false} INFO [2022/10/16 15:45:25]: 127.0.0.2 detected as a server INFO [2022/10/16 15:45:25]: Domain not specified, making a default INFO [2022/10/16 15:45:25]: Query not specified, making an "NS" query INFO [2022/10/16 15:45:25]: DNS server set to 127.0.0.2 INFO [2022/10/16 15:45:25]: Dig/Drill flags parsed DEBUG [2022/10/16 15:45:25]: {Logger:0xc0000b82d0 TLSHost: EDNS:{Subnet:{Code:0 Family:0 SourceNetmask:0 SourceScope:0 Address:<nil>} ZFlag:0 BufSize:1232 EnableEDNS:true Cookie:true DNSSEC:false Expire:false KeepOpen:false Nsid:false Padding:false Version:0} Request:{Server:127.0.0.2 Name:. Timeout:1s Port:0 Retries:2 Type:2 Class:1} Verbosity:0 Display:{Comments:true Question:true Opt:true Answer:true Authority:true Additional:true Statistics:true TTL:true ShowClass:false ShowQuery:false HumanTTL:false UcodeTranslate:false} Truncate:false BadCookie:false Short:false Identify:false Reverse:false HeaderFlags:{AA:false AD:false CD:false QR:false RD:true RA:false TC:false Z:false} JSON:false XML:false YAML:false TCP:false TLS:false TLSNoVerify:false HTTPS:false QUIC:false DNSCrypt:false IPv4:false IPv6:false} INFO [2022/10/16 15:45:25]: Port set to 53 INFO [2022/10/16 15:45:25]: Options fully populated DEBUG [2022/10/16 15:45:25]: {Logger:0xc0000b82d0 TLSHost: EDNS:{Subnet:{Code:0 Family:0 SourceNetmask:0 SourceScope:0 Address:<nil>} ZFlag:0 BufSize:1232 EnableEDNS:true Cookie:true DNSSEC:false Expire:false KeepOpen:false Nsid:false Padding:false Version:0} Request:{Server:127.0.0.2 Name:. Timeout:1s Port:53 Retries:2 Type:2 Class:1} Verbosity:0 Display:{Comments:true Question:true Opt:true Answer:true Authority:true Additional:true Statistics:true TTL:true ShowClass:false ShowQuery:false HumanTTL:false UcodeTranslate:false} Truncate:false BadCookie:false Short:false Identify:false Reverse:false HeaderFlags:{AA:false AD:false CD:false QR:false RD:true RA:false TC:false Z:false} JSON:false XML:false YAML:false TCP:false TLS:false TLSNoVerify:false HTTPS:false QUIC:false DNSCrypt:false IPv4:false IPv6:false} INFO [2022/10/16 15:45:25]: Setting EDNS cookie to 7d0c6e824624ab87 INFO [2022/10/16 15:45:25]: EDNS UDP buffer set to 1232 INFO [2022/10/16 15:45:25]: EDNS Z flag set to 0 DEBUG [2022/10/16 15:45:25]: ;; opcode: QUERY, status: NOERROR, id: 38965 ;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1 ;; OPT PSEUDOSECTION: ; EDNS: version 0; flags: ; udp: 1232 ; COOKIE: 7d0c6e824624ab87 ;; QUESTION SECTION: ;. IN NS INFO [2022/10/16 15:45:25]: loading standard/DNS-over-TLS resolver INFO [2022/10/16 15:45:25]: Query successfully loaded INFO [2022/10/16 15:45:25]: Using udp for making the request WARN [2022/10/16 15:45:25]: Retrying request, error: standard: DNS exchange: read udp 127.0.0.1:37383->127.0.0.2:53: read: connection refused INFO [2022/10/16 15:45:25]: Setting EDNS cookie to b27a2a12681d669b INFO [2022/10/16 15:45:25]: EDNS UDP buffer set to 1232 INFO [2022/10/16 15:45:25]: EDNS Z flag set to 0 DEBUG [2022/10/16 15:45:25]: ;; opcode: QUERY, status: NOERROR, id: 48256 ;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1 ;; OPT PSEUDOSECTION: ; EDNS: version 0; flags: ; udp: 1232 ; COOKIE: b27a2a12681d669b ;; QUESTION SECTION: ;. IN NS INFO [2022/10/16 15:45:25]: loading standard/DNS-over-TLS resolver INFO [2022/10/16 15:45:25]: Query successfully loaded INFO [2022/10/16 15:45:25]: Using udp for making the request WARN [2022/10/16 15:45:25]: Retrying request, error: standard: DNS exchange: dial udp: lookup 127.0.0.2:53: no such host INFO [2022/10/16 15:45:25]: Setting EDNS cookie to a61c35be7faceed8 INFO [2022/10/16 15:45:25]: EDNS UDP buffer set to 1232 INFO [2022/10/16 15:45:25]: EDNS Z flag set to 0 DEBUG [2022/10/16 15:45:25]: ;; opcode: QUERY, status: NOERROR, id: 16643 ;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1 ;; OPT PSEUDOSECTION: ; EDNS: version 0; flags: ; udp: 1232 ; COOKIE: a61c35be7faceed8 ;; QUESTION SECTION: ;. IN NS INFO [2022/10/16 15:45:25]: loading standard/DNS-over-TLS resolver INFO [2022/10/16 15:45:25]: Query successfully loaded INFO [2022/10/16 15:45:25]: Using udp for making the request ERROR [2022/10/16 15:45:25]: query: standard: DNS exchange: dial udp: address [[127.0.0.2:53]:53]:53: too many colons in address ``` **System information (please complete the following information):** - OS: Debian sid - Version: `awl version 0.5.6.dirty, built with go1.19.2` **Additional context** I suspect this to be caused by #132