DNS and Dialer Update

app/dns/dohdns.go

@@ -13,6 +13,7 @@ import (
 	"time"
 
 	"github.com/xtls/xray-core/common"
+	"github.com/xtls/xray-core/common/log"
 	"github.com/xtls/xray-core/common/net"
 	"github.com/xtls/xray-core/common/net/cnc"
 	"github.com/xtls/xray-core/common/protocol/dns"
@@ -47,6 +48,56 @@ func NewDoHNameServer(url *url.URL, dispatcher routing.Dispatcher, clientIP net.
 	s := baseDOHNameServer(url, "DOH", clientIP)
 
 	s.dispatcher = dispatcher
+	tr := &http.Transport{
+		MaxIdleConns:        30,
+		IdleConnTimeout:     90 * time.Second,
+		TLSHandshakeTimeout: 30 * time.Second,
+		ForceAttemptHTTP2:   true,
+		DialContext: func(ctx context.Context, network, addr string) (net.Conn, error) {
+			dispatcherCtx := context.Background()
+			if inbound := session.InboundFromContext(ctx); inbound != nil {
+				dispatcherCtx = session.ContextWithInbound(dispatcherCtx, inbound)
+			}
+			if content := session.ContentFromContext(ctx); content != nil {
+				dispatcherCtx = session.ContextWithContent(dispatcherCtx, content)
+			}
+			dispatcherCtx = internet.ContextWithLookupDomain(dispatcherCtx, internet.LookupDomainFromContext(ctx))
+
+			dest, err := net.ParseDestination(network + ":" + addr)
+			if err != nil {
+				return nil, err
+			}
+
+			dispatcherCtx = log.ContextWithAccessMessage(dispatcherCtx, &log.AccessMessage{
+				From:   "DoH",
+				To:     s.dohURL,
+				Status: log.AccessAccepted,
+				Reason: "",
+			})
+
+			link, err := s.dispatcher.Dispatch(dispatcherCtx, dest)
+			if err != nil {
+				return nil, err
+			}
+
+			cc := common.ChainedClosable{}
+			if cw, ok := link.Writer.(common.Closable); ok {
+				cc = append(cc, cw)
+			}
+			if cr, ok := link.Reader.(common.Closable); ok {
+				cc = append(cc, cr)
+			}
+			return cnc.NewConnection(
+				cnc.ConnectionInputMulti(link.Writer),
+				cnc.ConnectionOutputMulti(link.Reader),
+				cnc.ConnectionOnClose(cc),
+			), nil
+		},
+	}
+	s.httpClient = &http.Client{
+		Timeout:   time.Second * 180,
+		Transport: tr,
+	}
 
 	return s, nil
 }
@@ -64,6 +115,12 @@ func NewDoHLocalNameServer(url *url.URL, clientIP net.IP) *DoHNameServer {
 				return nil, err
 			}
 			conn, err := internet.DialSystem(ctx, dest, nil)
+			log.Record(&log.AccessMessage{
+				From:   "DoH",
+				To:     s.dohURL,
+				Status: log.AccessAccepted,
+				Detour: "local",
+			})
 			if err != nil {
 				return nil, err
 			}
@@ -249,41 +306,6 @@ func (s *DoHNameServer) dohHTTPSContext(ctx context.Context, b []byte) ([]byte,
 
 	hc := s.httpClient
 
-	// Dispatched connection will be closed (interrupted) after each request
-	// This makes DOH inefficient without a keep-alived connection
-	// See: core/app/proxyman/outbound/handler.go:113
-	// Using mux (https request wrapped in a stream layer) improves the situation.
-	// Recommend to use NewDoHLocalNameServer (DOHL:) if xray instance is running on
-	//  a normal network eg. the server side of xray
-
-	if s.dispatcher != nil {
-		tr := &http.Transport{
-			MaxIdleConns:        30,
-			IdleConnTimeout:     90 * time.Second,
-			TLSHandshakeTimeout: 30 * time.Second,
-			ForceAttemptHTTP2:   true,
-			DialContext: func(ctx context.Context, network, addr string) (net.Conn, error) {
-				dest, err := net.ParseDestination(network + ":" + addr)
-				if err != nil {
-					return nil, err
-				}
-
-				link, err := s.dispatcher.Dispatch(ctx, dest)
-				if err != nil {
-					return nil, err
-				}
-				return cnc.NewConnection(
-					cnc.ConnectionInputMulti(link.Writer),
-					cnc.ConnectionOutputMulti(link.Reader),
-				), nil
-			},
-		}
-		hc = &http.Client{
-			Timeout:   time.Second * 180,
-			Transport: tr,
-		}
-	}
-
 	resp, err := hc.Do(req.WithContext(ctx))
 	if err != nil {
 		return nil, err
@@ -347,6 +369,7 @@ func (s *DoHNameServer) QueryIP(ctx context.Context, domain string, option IPOpt
 	ips, err := s.findIPsForDomain(fqdn, option)
 	if err != errRecordNotFound {
 		newError(s.name, " cache HIT ", domain, " -> ", ips).Base(err).AtDebug().WriteToLog()
+		log.Record(&log.DNSLog{s.name, domain, ips, log.DNSCacheHit, 0, err})
 		return ips, err
 	}
 
@@ -377,10 +400,12 @@ func (s *DoHNameServer) QueryIP(ctx context.Context, domain string, option IPOpt
 		close(done)
 	}()
 	s.sendQuery(ctx, fqdn, option)
+	start := time.Now()
 
 	for {
 		ips, err := s.findIPsForDomain(fqdn, option)
 		if err != errRecordNotFound {
+			log.Record(&log.DNSLog{s.name, domain, ips, log.DNSQueried, time.Since(start), err})
 			return ips, err
 		}
 

app/dns/server.go

@@ -22,6 +22,7 @@ import (
 	"github.com/xtls/xray-core/features"
 	"github.com/xtls/xray-core/features/dns"
 	"github.com/xtls/xray-core/features/routing"
+	"github.com/xtls/xray-core/transport/internet"
 )
 
 // Server is a DNS rely server.
@@ -301,6 +302,7 @@ func (s *Server) queryIPTimeout(idx int, client Client, domain string, option IP
 			Tag: s.tag,
 		})
 	}
+	ctx = internet.ContextWithLookupDomain(ctx, Fqdn(domain))
 	ips, err := client.QueryIP(ctx, domain, option)
 	cancel()
 

app/dns/udpns.go

@@ -2,12 +2,14 @@ package dns
 
 import (
 	"context"
+	"github.com/xtls/xray-core/transport/internet"
 	"strings"
 	"sync"
 	"sync/atomic"
 	"time"
 
 	"github.com/xtls/xray-core/common"
+	"github.com/xtls/xray-core/common/log"
 	"github.com/xtls/xray-core/common/net"
 	"github.com/xtls/xray-core/common/protocol/dns"
 	udp_proto "github.com/xtls/xray-core/common/protocol/udp"
@@ -190,9 +192,16 @@ func (s *ClassicNameServer) sendQuery(ctx context.Context, domain string, option
 		if inbound := session.InboundFromContext(ctx); inbound != nil {
 			udpCtx = session.ContextWithInbound(udpCtx, inbound)
 		}
+		udpCtx = internet.ContextWithLookupDomain(udpCtx, internet.LookupDomainFromContext(ctx))
 		udpCtx = session.ContextWithContent(udpCtx, &session.Content{
 			Protocol: "dns",
 		})
+		udpCtx = log.ContextWithAccessMessage(udpCtx, &log.AccessMessage{
+			From:   "DNS",
+			To:     s.address,
+			Status: log.AccessAccepted,
+			Reason: "",
+		})
 		s.udpServer.Dispatch(udpCtx, s.address, b)
 	}
 }
@@ -241,6 +250,7 @@ func (s *ClassicNameServer) QueryIP(ctx context.Context, domain string, option I
 	ips, err := s.findIPsForDomain(fqdn, option)
 	if err != errRecordNotFound {
 		newError(s.name, " cache HIT ", domain, " -> ", ips).Base(err).AtDebug().WriteToLog()
+		log.Record(&log.DNSLog{s.name, domain, ips, log.DNSCacheHit, 0, err})
 		return ips, err
 	}
 
@@ -271,10 +281,12 @@ func (s *ClassicNameServer) QueryIP(ctx context.Context, domain string, option I
 		close(done)
 	}()
 	s.sendQuery(ctx, fqdn, option)
+	start := time.Now()
 
 	for {
 		ips, err := s.findIPsForDomain(fqdn, option)
 		if err != errRecordNotFound {
+			log.Record(&log.DNSLog{s.name, domain, ips, log.DNSQueried, time.Since(start), err})
 			return ips, err
 		}
 

app/log/config.proto

@@ -22,4 +22,5 @@ message Config {
 
   LogType access_log_type = 4;
   string access_log_path = 5;
+  bool enable_dns_log = 6;
 }

app/log/log.go

@@ -17,13 +17,15 @@ type Instance struct {
 	accessLogger log.Handler
 	errorLogger  log.Handler
 	active       bool
+	dns          bool
 }
 
 // New creates a new log.Instance based on the given config.
 func New(ctx context.Context, config *Config) (*Instance, error) {
 	g := &Instance{
 		config: config,
 		active: false,
+		dns:    config.EnableDnsLog,
 	}
 	log.RegisterHandler(g)
 
@@ -103,6 +105,10 @@ func (g *Instance) Handle(msg log.Message) {
 		if g.accessLogger != nil {
 			g.accessLogger.Handle(msg)
 		}
+	case *log.DNSLog:
+		if g.dns && g.accessLogger != nil {
+			g.accessLogger.Handle(msg)
+		}
 	case *log.GeneralMessage:
 		if g.errorLogger != nil && msg.Severity <= g.config.ErrorLogLevel {
 			g.errorLogger.Handle(msg)

common/log/dns.go

@@ -0,0 +1,59 @@
+package log
+
+import (
+	"net"
+	"strings"
+	"time"
+)
+
+type DNSLog struct {
+	Server  string
+	Domain  string
+	Result  []net.IP
+	Status  dnsStatus
+	Elapsed time.Duration
+	Error   error
+}
+
+func (l *DNSLog) String() string {
+	builder := &strings.Builder{}
+
+	// Server got answer: domain -> [ip1, ip2] 23ms
+	builder.WriteString(l.Server)
+	builder.WriteString(" ")
+	builder.WriteString(string(l.Status))
+	builder.WriteString(" ")
+	builder.WriteString(l.Domain)
+	builder.WriteString(" -> [")
+	builder.WriteString(joinNetIP(l.Result))
+	builder.WriteString("]")
+
+	if l.Elapsed > 0 {
+		builder.WriteString(" ")
+		builder.WriteString(l.Elapsed.String())
+	}
+	if l.Error != nil {
+		builder.WriteString(" <")
+		builder.WriteString(l.Error.Error())
+		builder.WriteString(">")
+	}
+	return builder.String()
+}
+
+type dnsStatus string
+
+var (
+	DNSQueried  = dnsStatus("got answer:")
+	DNSCacheHit = dnsStatus("cache HIT:")
+)
+
+func joinNetIP(ips []net.IP) string {
+	if len(ips) == 0 {
+		return ""
+	}
+	sips := make([]string, 0, len(ips))
+	for _, ip := range ips {
+		sips = append(sips, ip.String())
+	}
+	return strings.Join(sips, ", ")
+}