Merge branch 'master' into 6321-boot-ttl-vol.1

upstream/doh.go

@@ -220,10 +220,9 @@ func (p *dnsOverHTTPS) exchangeHTTPS(client *http.Client, req *dns.Msg) (resp *d
 	}
 
 	logBegin(p.addrRedacted, n, req)
-	resp, err = p.exchangeHTTPSClient(client, req)
-	logFinish(p.addrRedacted, n, err)
+	defer func() { logFinish(p.addrRedacted, n, err) }()
 
-	return resp, err
+	return p.exchangeHTTPSClient(client, req)
 }
 
 // exchangeHTTPSClient sends the DNS query to a DoH resolver using the specified
@@ -277,13 +276,12 @@ func (p *dnsOverHTTPS) exchangeHTTPSClient(
 	}
 
 	if httpResp.StatusCode != http.StatusOK {
-		return nil,
-			fmt.Errorf(
-				"expected status %d, got %d from %s",
-				http.StatusOK,
-				httpResp.StatusCode,
-				p.addrRedacted,
-			)
+		return nil, fmt.Errorf(
+			"expected status %d, got %d from %s",
+			http.StatusOK,
+			httpResp.StatusCode,
+			p.addrRedacted,
+		)
 	}
 
 	resp = &dns.Msg{}

upstream/quic.go

@@ -193,15 +193,20 @@ func (p *dnsOverQUIC) Close() (err error) {
 
 // exchangeQUIC attempts to open a QUIC connection, send the DNS message
 // through it and return the response it got from the server.
-func (p *dnsOverQUIC) exchangeQUIC(m *dns.Msg) (resp *dns.Msg, err error) {
+func (p *dnsOverQUIC) exchangeQUIC(req *dns.Msg) (resp *dns.Msg, err error) {
+	addr := p.Address()
+
+	logBegin(addr, networkUDP, req)
+	defer func() { logFinish(addr, networkUDP, err) }()
+
 	var conn quic.Connection
 	conn, err = p.getConnection(true)
 	if err != nil {
 		return nil, err
 	}
 
 	var buf []byte
-	buf, err = m.Pack()
+	buf, err = req.Pack()
 	if err != nil {
 		return nil, fmt.Errorf("failed to pack DNS message for DoQ: %w", err)
 	}

upstream/upstream.go

@@ -11,11 +11,13 @@ import (
 	"net"
 	"net/netip"
 	"net/url"
+	"os"
 	"strconv"
 	"strings"
 	"time"
 
 	"github.com/AdguardTeam/dnsproxy/internal/bootstrap"
+	"github.com/AdguardTeam/golibs/errors"
 	"github.com/AdguardTeam/golibs/log"
 	"github.com/AdguardTeam/golibs/netutil"
 	"github.com/ameshkov/dnscrypt/v2"
@@ -273,25 +275,51 @@ func addPort(u *url.URL, port uint16) {
 // logBegin logs the start of DNS request resolution.  It should be called right
 // before dialing the connection to the upstream.  n is the [network] that will
 // be used to send the request.
-func logBegin(upsAddr string, n network, req *dns.Msg) {
-	qtype := ""
-	target := ""
+func logBegin(addr string, n network, req *dns.Msg) {
+	var qtype dns.Type
+	var qname string
 	if len(req.Question) != 0 {
-		qtype = dns.Type(req.Question[0].Qtype).String()
-		target = req.Question[0].Name
+		qtype = dns.Type(req.Question[0].Qtype)
+		qname = req.Question[0].Name
 	}
 
-	log.Debug("dnsproxy: %s: sending request over %s: %s %s", upsAddr, n, qtype, target)
+	log.Debug("dnsproxy: sending request to %s over %s: %s %q", addr, n, qtype, qname)
 }
 
-// Write to log about the result of DNS request
-func logFinish(upsAddr string, n network, err error) {
+// logFinish logs the end of DNS request resolution.  It should be called right
+// after receiving the response from the upstream or the failing action.  n is
+// the [network] that was used to send the request.
+func logFinish(addr string, n network, err error) {
+	logRoutine := log.Debug
+
 	status := "ok"
 	if err != nil {
 		status = err.Error()
+		if isTimeout(err) {
+			// Notify user about the timeout.
+			logRoutine = log.Error
+		}
 	}
 
-	log.Debug("dnsproxy: %s: response received over %s: %q", upsAddr, n, status)
+	logRoutine("dnsproxy: %s: response received over %s: %q", addr, n, status)
+}
+
+// isTimeout returns true if err is a timeout error.
+//
+// TODO(e.burkov):  Move to golibs.
+func isTimeout(err error) (ok bool) {
+	var netErr net.Error
+	switch {
+	case
+		errors.Is(err, context.Canceled),
+		errors.Is(err, context.DeadlineExceeded),
+		errors.Is(err, os.ErrDeadlineExceeded):
+		return true
+	case errors.As(err, &netErr):
+		return netErr.Timeout()
+	default:
+		return false
+	}
 }
 
 // DialerInitializer returns the handler that it creates.