add more detail info for routing

http.go

@@ -2,6 +2,7 @@ package gost
 
 import (
 	"bufio"
+	"bytes"
 	"encoding/base64"
 	"fmt"
 	"net"
@@ -108,18 +109,34 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 	if req == nil {
 		return
 	}
-	if Debug {
-		dump, _ := httputil.DumpRequest(req, false)
-		log.Logf("[http] %s -> %s\n%s", conn.RemoteAddr(), req.Host, string(dump))
-	}
 
+	host := req.Host
 	// try to get the actual host.
 	if v := req.Header.Get("Gost-Target"); v != "" {
-		if host, err := decodeServerName(v); err == nil {
-			req.Host = host
+		if h, err := decodeServerName(v); err == nil {
+			host = h
 		}
 	}
 
+	if _, port, _ := net.SplitHostPort(host); port == "" {
+		host = net.JoinHostPort(host, "80")
+	}
+
+	u, _, _ := basicProxyAuth(req.Header.Get("Proxy-Authorization"))
+	if u != "" {
+		u += "@"
+	}
+	log.Logf("[http] %s%s -> %s -> %s",
+		u, conn.RemoteAddr(), h.options.Node.String(), host)
+
+	if Debug {
+		dump, _ := httputil.DumpRequest(req, false)
+		log.Logf("[http] %s -> %s\n%s", conn.RemoteAddr(), conn.LocalAddr(), string(dump))
+	}
+
+	req.Host = host
+	req.Header.Del("Gost-Target")
+
 	resp := &http.Response{
 		ProtoMajor: 1,
 		ProtoMinor: 1,
@@ -127,96 +144,35 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 	}
 	resp.Header.Add("Proxy-Agent", "gost/"+Version)
 
-	if !Can("tcp", req.Host, h.options.Whitelist, h.options.Blacklist) {
+	if !Can("tcp", host, h.options.Whitelist, h.options.Blacklist) {
 		log.Logf("[http] %s - %s : Unauthorized to tcp connect to %s",
-			conn.RemoteAddr(), req.Host, req.Host)
+			conn.RemoteAddr(), conn.LocalAddr(), host)
 		resp.StatusCode = http.StatusForbidden
 
 		if Debug {
 			dump, _ := httputil.DumpResponse(resp, false)
-			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), req.Host, string(dump))
+			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), conn.LocalAddr(), string(dump))
 		}
 
 		resp.Write(conn)
 		return
 	}
 
-	if h.options.Bypass.Contains(req.Host) {
-		log.Logf("[http] [bypass] %s", req.Host)
+	if h.options.Bypass.Contains(host) {
 		resp.StatusCode = http.StatusForbidden
 
+		log.Logf("[http] %s - %s bypass %s",
+			conn.RemoteAddr(), conn.LocalAddr(), host)
 		if Debug {
 			dump, _ := httputil.DumpResponse(resp, false)
-			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), req.Host, string(dump))
+			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), conn.LocalAddr(), string(dump))
 		}
 
 		resp.Write(conn)
 		return
 	}
 
-	u, p, _ := basicProxyAuth(req.Header.Get("Proxy-Authorization"))
-	if Debug && (u != "" || p != "") {
-		log.Logf("[http] %s - %s : Authorization: '%s' '%s'", conn.RemoteAddr(), req.Host, u, p)
-	}
-	if !authenticate(u, p, h.options.Users...) {
-		// probing resistance is enabled
-		if ss := strings.SplitN(h.options.ProbeResist, ":", 2); len(ss) == 2 {
-			switch ss[0] {
-			case "code":
-				resp.StatusCode, _ = strconv.Atoi(ss[1])
-			case "web":
-				url := ss[1]
-				if !strings.HasPrefix(url, "http") {
-					url = "http://" + url
-				}
-				if r, err := http.Get(url); err == nil {
-					resp = r
-				}
-			case "host":
-				cc, err := net.Dial("tcp", ss[1])
-				if err == nil {
-					defer cc.Close()
-
-					req.Write(cc)
-					log.Logf("[http] %s <-> %s : forward to %s", conn.LocalAddr(), req.Host, ss[1])
-					transport(conn, cc)
-					log.Logf("[http] %s >-< %s : forward to %s", conn.LocalAddr(), req.Host, ss[1])
-					return
-				}
-			case "file":
-				f, _ := os.Open(ss[1])
-				if f != nil {
-					resp.StatusCode = http.StatusOK
-					if finfo, _ := f.Stat(); finfo != nil {
-						resp.ContentLength = finfo.Size()
-					}
-					resp.Body = f
-				}
-			}
-		}
-
-		if resp.StatusCode == 0 {
-			log.Logf("[http] %s <- %s : proxy authentication required", conn.RemoteAddr(), req.Host)
-			resp.StatusCode = http.StatusProxyAuthRequired
-			resp.Header.Add("Proxy-Authenticate", "Basic realm=\"gost\"")
-		} else {
-			resp.Header = http.Header{}
-			resp.Header.Set("Server", "nginx/1.14.1")
-			resp.Header.Set("Date", time.Now().Format(http.TimeFormat))
-			if resp.ContentLength > 0 {
-				resp.Header.Set("Content-Type", "text/html")
-			}
-			if resp.StatusCode == http.StatusOK {
-				resp.Header.Set("Connection", "keep-alive")
-			}
-		}
-
-		if Debug {
-			dump, _ := httputil.DumpResponse(resp, false)
-			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), req.Host, string(dump))
-		}
-
-		resp.Write(conn)
+	if !h.authenticate(conn, req, resp) {
 		return
 	}
 
@@ -225,7 +181,8 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 
 		if Debug {
 			dump, _ := httputil.DumpResponse(resp, false)
-			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), req.Host, string(dump))
+			log.Logf("[http] %s <- %s\n%s",
+				conn.RemoteAddr(), conn.LocalAddr(), string(dump))
 		}
 
 		resp.Write(conn)
@@ -234,11 +191,6 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 
 	req.Header.Del("Proxy-Authorization")
 
-	host := req.Host
-	if _, port, _ := net.SplitHostPort(host); port == "" {
-		host = net.JoinHostPort(req.Host, "80")
-	}
-
 	retries := 1
 	if h.options.Chain != nil && h.options.Chain.Retries > 0 {
 		retries = h.options.Chain.Retries
@@ -251,11 +203,22 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 	var cc net.Conn
 	var route *Chain
 	for i := 0; i < retries; i++ {
-		route, err = h.options.Chain.selectRouteFor(req.Host)
+		route, err = h.options.Chain.selectRouteFor(host)
 		if err != nil {
-			log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), req.Host, err)
+			log.Logf("[http] %s -> %s : %s",
+				conn.RemoteAddr(), conn.LocalAddr(), err)
 			continue
 		}
+
+		buf := bytes.Buffer{}
+		fmt.Fprintf(&buf, "%s -> %s -> ",
+			conn.RemoteAddr(), h.options.Node.String())
+		for _, nd := range route.route {
+			fmt.Fprintf(&buf, "%d@%s -> ", nd.ID, nd.String())
+		}
+		fmt.Fprintf(&buf, "%s", host)
+		log.Log("[route]", buf.String())
+
 		// forward http request
 		lastNode := route.LastNode()
 		if req.Method != http.MethodConnect && lastNode.Protocol == "http" {
@@ -263,12 +226,11 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 			if err == nil {
 				return
 			}
-			// log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), req.Host, err)
+			log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), conn.LocalAddr(), err)
 			continue
 		}
 
 		cc, err = route.Dial(host,
-			RetryChainOption(1),
 			TimeoutChainOption(h.options.Timeout),
 			HostsChainOption(h.options.Hosts),
 			ResolverChainOption(h.options.Resolver),
@@ -276,15 +238,15 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 		if err == nil {
 			break
 		}
+		log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), conn.LocalAddr(), err)
 	}
 
 	if err != nil {
-		log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), host, err)
 		resp.StatusCode = http.StatusServiceUnavailable
 
 		if Debug {
 			dump, _ := httputil.DumpResponse(resp, false)
-			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), host, string(dump))
+			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), conn.LocalAddr(), string(dump))
 		}
 
 		resp.Write(conn)
@@ -296,26 +258,94 @@ func (h *httpHandler) handleRequest(conn net.Conn, req *http.Request) {
 		b := []byte("HTTP/1.1 200 Connection established\r\n" +
 			"Proxy-Agent: gost/" + Version + "\r\n\r\n")
 		if Debug {
-			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), host, string(b))
+			log.Logf("[http] %s <- %s\n%s", conn.RemoteAddr(), conn.LocalAddr(), string(b))
 		}
 		conn.Write(b)
 	} else {
 		req.Header.Del("Proxy-Connection")
 
 		if err = req.Write(cc); err != nil {
-			log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), host, err)
+			log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), conn.LocalAddr(), err)
 			return
 		}
 	}
 
-	var su string
-	if u != "" {
-		su = u + "@"
+	log.Logf("[http] %s <-> %s", conn.RemoteAddr(), host)
+	transport(conn, cc)
+	log.Logf("[http] %s >-< %s", conn.RemoteAddr(), host)
+}
+
+func (h *httpHandler) authenticate(conn net.Conn, req *http.Request, resp *http.Response) (ok bool) {
+	u, p, _ := basicProxyAuth(req.Header.Get("Proxy-Authorization"))
+	if Debug && (u != "" || p != "") {
+		log.Logf("[http] %s -> %s : Authorization '%s' '%s'",
+			conn.RemoteAddr(), conn.LocalAddr(), u, p)
+	}
+	if authenticate(u, p, h.options.Users...) {
+		return true
 	}
 
-	log.Logf("[http] %s%s <-> %s", su, cc.LocalAddr(), host)
-	transport(conn, cc)
-	log.Logf("[http] %s%s >-< %s", su, cc.LocalAddr(), host)
+	// probing resistance is enabled
+	if ss := strings.SplitN(h.options.ProbeResist, ":", 2); len(ss) == 2 {
+		switch ss[0] {
+		case "code":
+			resp.StatusCode, _ = strconv.Atoi(ss[1])
+		case "web":
+			url := ss[1]
+			if !strings.HasPrefix(url, "http") {
+				url = "http://" + url
+			}
+			if r, err := http.Get(url); err == nil {
+				resp = r
+			}
+		case "host":
+			cc, err := net.Dial("tcp", ss[1])
+			if err == nil {
+				defer cc.Close()
+
+				req.Write(cc)
+				log.Logf("[http] %s <-> %s : forward to %s",
+					conn.RemoteAddr(), conn.LocalAddr(), ss[1])
+				transport(conn, cc)
+				log.Logf("[http] %s >-< %s : forward to %s",
+					conn.RemoteAddr(), conn.LocalAddr(), ss[1])
+				return
+			}
+		case "file":
+			f, _ := os.Open(ss[1])
+			if f != nil {
+				resp.StatusCode = http.StatusOK
+				if finfo, _ := f.Stat(); finfo != nil {
+					resp.ContentLength = finfo.Size()
+				}
+				resp.Header.Set("Content-Type", "text/html")
+				resp.Body = f
+			}
+		}
+	}
+
+	if resp.StatusCode == 0 {
+		log.Logf("[http] %s <- %s : proxy authentication required",
+			conn.RemoteAddr(), conn.LocalAddr())
+		resp.StatusCode = http.StatusProxyAuthRequired
+		resp.Header.Add("Proxy-Authenticate", "Basic realm=\"gost\"")
+	} else {
+		resp.Header = http.Header{}
+		resp.Header.Set("Server", "nginx/1.14.1")
+		resp.Header.Set("Date", time.Now().Format(http.TimeFormat))
+		if resp.StatusCode == http.StatusOK {
+			resp.Header.Set("Connection", "keep-alive")
+		}
+	}
+
+	if Debug {
+		dump, _ := httputil.DumpResponse(resp, false)
+		log.Logf("[http] %s <- %s\n%s",
+			conn.RemoteAddr(), conn.LocalAddr(), string(dump))
+	}
+
+	resp.Write(conn)
+	return
 }
 
 func (h *httpHandler) forwardRequest(conn net.Conn, req *http.Request, route *Chain) error {
@@ -324,9 +354,7 @@ func (h *httpHandler) forwardRequest(conn net.Conn, req *http.Request, route *Ch
 	}
 	lastNode := route.LastNode()
 
-	cc, err := route.Conn(
-		RetryChainOption(1), // we control the retry manually.
-	)
+	cc, err := route.Conn()
 	if err != nil {
 		return err
 	}
@@ -346,7 +374,7 @@ func (h *httpHandler) forwardRequest(conn net.Conn, req *http.Request, route *Ch
 		req.URL.Scheme = "http" // make sure that the URL is absolute
 	}
 	if err = req.WriteProxy(cc); err != nil {
-		log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), req.Host, err)
+		log.Logf("[http] %s -> %s : %s", conn.RemoteAddr(), conn.LocalAddr(), err)
 		return nil
 	}
 	cc.SetWriteDeadline(time.Time{})