Improve connection access logs. Make them more uniform and include al…

…l port numbers.

.travis.yml

@@ -3,7 +3,6 @@ go:
 - 1.13.x
 before_install:
 - go get -u github.com/mattn/goveralls
-- go get -u github.com/golangci/golangci-lint/cmd/golangci-lint
 script:
 - export GO111MODULE=on
 - make

fwd.go

@@ -62,7 +62,7 @@ func LocalForwardUDP(state *State, s *stack.Stack, rf FwdAddr, doneChannel <-cha
 		Port: int(rf.bind.Port),
 	}
 
-	host := &net.UDPAddr{
+	targetAddr := &net.UDPAddr{
 		IP:   net.IP(rf.host.Addr),
 		Port: int(rf.host.Port),
 	}
@@ -86,35 +86,34 @@ func LocalForwardUDP(state *State, s *stack.Stack, rf FwdAddr, doneChannel <-cha
 			raddr := addr.(*net.UDPAddr)
 
 			// Warning, this is racy, what if two packets are in the queue?
-			remote, err := MagicDialUDP(laddr, raddr)
+			connectedUdp, err := MagicDialUDP(laddr, raddr)
 			if err != nil {
 				// This actually can totally happen in
 				// the said race. Just drop the packet then.
 				continue
 			}
 
 			if rf.kaEnable && rf.kaInterval == 0 {
-				remote.closeOnWrite = true
+				connectedUdp.closeOnWrite = true
 			}
 
 			go func() {
-				LocalForward(state, s, remote, host, buf[:n], rf.proxyProtocol)
+				LocalForward(state, s, connectedUdp, targetAddr, buf[:n], rf.proxyProtocol)
 			}()
 		}
 	}()
 	return &UDPListner{srv}, nil
 }
 
-func LocalForward(state *State, s *stack.Stack, host KaConn, gaddr net.Addr, buf []byte, proxyProtocol bool) {
+func LocalForward(state *State, s *stack.Stack, conn KaConn, targetAddr net.Addr, buf []byte, proxyProtocol bool) {
 	var (
 		err          error
-		raddr        = host.RemoteAddr()
 		ppSrc, ppDst net.Addr
 		sppHeader    []byte
 	)
 	if proxyProtocol && buf == nil {
 		buf = make([]byte, 4096)
-		n, err := host.Read(buf)
+		n, err := conn.Read(buf)
 		if err != nil {
 			goto pperror
 		}
@@ -125,7 +124,7 @@ func LocalForward(state *State, s *stack.Stack, host KaConn, gaddr net.Addr, buf
 		var (
 			n int
 		)
-		if gaddr.Network() == "tcp" {
+		if targetAddr.Network() == "tcp" {
 			n, ppSrc, ppDst, err = DecodePP(buf)
 			buf = buf[n:]
 		} else {
@@ -149,6 +148,7 @@ func LocalForward(state *State, s *stack.Stack, host KaConn, gaddr net.Addr, buf
 			// connection had routable IP (unlike
 			// 127.0.0.1)... well... spoof it! The client might find it
 			// useful who launched the connection in the first place.
+			raddr := conn.RemoteAddr()
 			if IPNetContains(state.RoutingDeny, netAddrIP(raddr)) == false {
 				srcIP = raddr
 			}
@@ -172,62 +172,72 @@ func LocalForward(state *State, s *stack.Stack, host KaConn, gaddr net.Addr, buf
 			srcIP = netAddrSetPort(srcIP, 0)
 		}
 
-		if netAddrPort(gaddr) == 0 {
+		if netAddrPort(targetAddr) == 0 {
 			// If the guest has dport equal to zero, fill
 			// it up somehow. First guess - use dport of
 			// host connection.
-			hostPort := netAddrPort(host.LocalAddr())
+			hostPort := netAddrPort(conn.LocalAddr())
 
 			// Alternatively if we got dport from PP, use that
 			if ppDst != nil {
 				hostPort = netAddrPort(ppDst)
 			}
 
-			gaddr = netAddrSetPort(gaddr, hostPort)
+			targetAddr = netAddrSetPort(targetAddr, hostPort)
 		}
 
-		if logConnections {
-			fmt.Printf("[+] %s://%s/%s/%s local-fwd %sconn\n",
-				gaddr.Network(),
-				raddr,
-				host.LocalAddr(),
-				gaddr.String(),
-				ppPrefix)
-		}
-
-		guest, err := GonetDial(s, srcIP, gaddr)
-
+		guest, err := GonetDial(s, srcIP, targetAddr)
 		var pe ProxyError
 		if err != nil {
-			SetResetOnClose(host)
-			host.Close()
+			SetResetOnClose(conn)
+			conn.Close()
 			pe.RemoteRead = fmt.Errorf("%s", err)
 			pe.First = 2
+			if logConnections {
+				fmt.Printf("[!] %s://%s-%s/%s local-fwd %serror: %s\n",
+					targetAddr.Network(),
+					conn.RemoteAddr(),
+					conn.LocalAddr(),
+					targetAddr.String(),
+					ppPrefix,
+					pe)
+			}
 		} else {
+			if logConnections {
+				fmt.Printf("[+] %s://%s-%s/%s-%s local-fwd %sconn\n",
+					targetAddr.Network(),
+					conn.RemoteAddr(),
+					conn.LocalAddr(),
+					guest.LocalAddr(),
+					targetAddr.String(),
+					ppPrefix)
+			}
+
 			guest.Write(buf)
-			pe = connSplice(host, guest, sppHeader)
-		}
-		if logConnections {
-			fmt.Printf("[-] %s://%s/%s/%s (guest-src:%s) local-fwd %sdone: %s\n",
-				gaddr.Network(),
-				raddr,
-				host.LocalAddr(),
-				gaddr.String(),
-				guest.LocalAddr(),
-				ppPrefix,
-				pe)
+			pe = connSplice(conn, guest, sppHeader)
+
+			if logConnections {
+				fmt.Printf("[-] %s://%s-%s/%s-%s local-fwd %sdone: %s\n",
+					targetAddr.Network(),
+					conn.RemoteAddr(),
+					conn.LocalAddr(),
+					guest.LocalAddr(),
+					targetAddr.String(),
+					ppPrefix,
+					pe)
+			}
 		}
 	}
 	return
 pperror:
 	if logConnections {
-		fmt.Printf("[!] %s://%s/%s/%s local-fwd PP error: %s\n",
-			gaddr.Network(),
-			raddr,
-			host.LocalAddr(),
-			gaddr.String(),
+		fmt.Printf("[!] %s://%s-%s/%s local-fwd PP error: %s\n",
+			targetAddr.Network(),
+			conn.RemoteAddr(),
+			conn.LocalAddr(),
+			targetAddr.String(),
 			err)
 	}
-	host.Close()
+	conn.Close()
 	return
 }

proxy.go

@@ -2,6 +2,7 @@ package main
 
 import (
 	"fmt"
+	"strings"
 	"time"
 )
 
@@ -19,23 +20,29 @@ type ProxyError struct {
 	First       int
 }
 
+// See this and cry: https://github.com/golang/go/issues/4373
+func ErrIsMyFault(err error) bool {
+	s := err.Error()
+	return strings.HasSuffix(s, "use of closed network connection")
+}
+
 func (pe ProxyError) String() string {
 	x := []string{
 		fmt.Sprintf("%s", pe.LocalRead),
 		fmt.Sprintf("%s", pe.LocalWrite),
 		fmt.Sprintf("%s", pe.RemoteRead),
 		fmt.Sprintf("%s", pe.RemoteWrite),
 	}
-	if pe.LocalRead == nil {
+	if pe.LocalRead == nil || ErrIsMyFault(pe.LocalRead) {
 		x[0] = "0"
 	}
-	if pe.LocalWrite == nil {
+	if pe.LocalWrite == nil || ErrIsMyFault(pe.LocalWrite) {
 		x[1] = "0"
 	}
-	if pe.RemoteRead == nil {
+	if pe.RemoteRead == nil || ErrIsMyFault(pe.RemoteRead) {
 		x[2] = "0"
 	}
-	if pe.RemoteWrite == nil {
+	if pe.RemoteWrite == nil || ErrIsMyFault(pe.RemoteWrite) {
 		x[3] = "0"
 	}
 	x[pe.First] = fmt.Sprintf("[%s]", x[pe.First])
@@ -105,6 +112,16 @@ func proxyOneFlow(
 		}
 	}
 
+	// Synchronize with parent. It's important to do this _before_
+	// closing sockets, since .Close() might trigger the other
+	// proxy goroutine to exit with "use of closed fd"
+	// error. There is no race here. We can push to channel
+	// without closing yet.
+	doneCh <- scDir
+
+	in.SetTimeouts(5*time.Second, 2)
+	out.SetTimeouts(5*time.Second, 2)
+
 	if c, ok := in.(Closer); ok {
 		c.CloseRead()
 	} else {
@@ -115,12 +132,6 @@ func proxyOneFlow(
 	} else {
 		out.Close()
 	}
-
-	in.SetTimeouts(5*time.Second, 2)
-	out.SetTimeouts(5*time.Second, 2)
-
-	// Synchronize with parent.
-	doneCh <- scDir
 }
 
 func connSplice(local KaConn, remote KaConn, sppHeader []byte) ProxyError {

routing.go

@@ -117,13 +117,9 @@ func TcpRoutingHandler(state *State) func(*tcp.ForwarderRequest) {
 }
 
 func RoutingForward(guest KaConn, srcIPs *SrcIPs, loc net.Addr) {
-	ga := guest.RemoteAddr()
-	if logConnections {
-		fmt.Printf("[+] %s://%s/%s Routing conn new\n",
-			loc.Network(),
-			ga,
-			loc.String())
-	}
+	// Cache guest.RemoteAddr() because it becomes nil on
+	// guest.Close() for UDP.
+	guestRemoteAddr := guest.RemoteAddr()
 
 	var pe ProxyError
 	xhost, err := OutboundDial(srcIPs, loc)
@@ -132,7 +128,21 @@ func RoutingForward(guest KaConn, srcIPs *SrcIPs, loc net.Addr) {
 		guest.Close()
 		pe.RemoteRead = err
 		pe.First = 2
+		if logConnections {
+			fmt.Printf("[!] %s://%s/%s Routing conn error: %s\n",
+				loc.Network(),
+				guestRemoteAddr,
+				loc.String(),
+				pe)
+		}
 	} else {
+		if logConnections {
+			fmt.Printf("[+] %s://%s/%s-%s Routing conn new\n",
+				loc.Network(),
+				guestRemoteAddr,
+				xhost.LocalAddr(),
+				xhost.RemoteAddr())
+		}
 		var host KaConn
 		switch v := xhost.(type) {
 		case *net.TCPConn:
@@ -141,33 +151,44 @@ func RoutingForward(guest KaConn, srcIPs *SrcIPs, loc net.Addr) {
 			host = &KaUDPConn{Conn: v}
 		}
 		pe = connSplice(guest, host, nil)
-	}
-	if logConnections {
-		fmt.Printf("[-] %s://%s/%s Routing conn done: %s\n",
-			loc.Network(),
-			ga,
-			loc.String(),
-			pe)
+		if logConnections {
+			fmt.Printf("[-] %s://%s/%s-%s Routing conn done: %s\n",
+				loc.Network(),
+				guestRemoteAddr,
+				xhost.LocalAddr(),
+				xhost.RemoteAddr(),
+				pe)
+		}
 	}
 }
 
 func RemoteForward(guest KaConn, srcIPs *SrcIPs, rf *FwdAddr) {
-	ga := guest.RemoteAddr()
-	if logConnections {
-		fmt.Printf("[+] %s://%s/%s %s-remote-fwd conn new\n",
-			rf.network,
-			guest.RemoteAddr(),
-			guest.LocalAddr(),
-			rf.HostAddr().String())
-	}
 	var pe ProxyError
 	xhost, err := OutboundDial(srcIPs, rf.HostAddr())
 	if err != nil {
 		SetResetOnClose(guest)
 		guest.Close()
 		pe.RemoteRead = err
 		pe.First = 2
+		if logConnections {
+			fmt.Printf("[!] %s://%s-%s/%s %s-remote-fwd conn error: %s\n",
+				rf.network,
+				guest.RemoteAddr(),
+				guest.LocalAddr(),
+				rf.HostAddr(),
+				rf.HostAddr().String(),
+				pe)
+		}
 	} else {
+		if logConnections {
+			fmt.Printf("[+] %s://%s-%s/%s-%s %s-remote-fwd conn new\n",
+				rf.network,
+				guest.RemoteAddr(),
+				guest.LocalAddr(),
+				xhost.LocalAddr(),
+				xhost.RemoteAddr(),
+				rf.HostAddr().String())
+		}
 		var host KaConn
 		switch v := xhost.(type) {
 		case *net.TCPConn:
@@ -176,13 +197,15 @@ func RemoteForward(guest KaConn, srcIPs *SrcIPs, rf *FwdAddr) {
 			host = &KaUDPConn{Conn: v}
 		}
 		pe = connSplice(guest, host, nil)
-	}
-	if logConnections {
-		fmt.Printf("[-] %s://%s/%s %s-remote-fwd conn done: %s\n",
-			rf.network,
-			ga,
-			guest.LocalAddr(),
-			rf.HostAddr().String(),
-			pe)
+		if logConnections {
+			fmt.Printf("[-] %s://%s-%s/%s-%s %s-remote-fwd conn done: %s\n",
+				rf.network,
+				guest.RemoteAddr(),
+				guest.LocalAddr(),
+				xhost.LocalAddr(),
+				xhost.RemoteAddr(),
+				rf.HostAddr().String(),
+				pe)
+		}
 	}
 }

stack.go

@@ -104,6 +104,11 @@ func NewStack(rcvBufferSize, sndBufferSize int) *stack.Stack {
 		tcp.ReceiveBufferSizeOption{1, rcvBufferSize, rcvBufferSize})
 	s.SetTransportProtocolOption(tcp.ProtocolNumber,
 		tcp.SendBufferSizeOption{1, sndBufferSize, sndBufferSize})
+
+	// Enable Receive Buffer Auto-Tuning, see:
+	// https://github.com/google/gvisor/issues/1666
+	s.SetTransportProtocolOption(tcp.ProtocolNumber,
+		tcpip.ModerateReceiveBufferOption(true))
 	return s
 }