More meaningful logs

net/freedom/freedom.go

@@ -24,9 +24,9 @@ func (vconn *FreedomConnection) Start(ray core.OutboundRay) error {
 	conn, err := net.Dial("tcp", vconn.dest.String())
 	if err != nil {
 		close(output)
-		return log.Error("Failed to open tcp: %s : %v", vconn.dest.String(), err)
+		return log.Error("Freedom: Failed to open tcp connection: %s : %v", vconn.dest.String(), err)
 	}
-	log.Debug("Sending outbound tcp: %s", vconn.dest.String())
+	log.Info("Freedom: Sending outbound tcp: %s", vconn.dest.String())
 
 	readFinish := make(chan bool)
 	writeFinish := make(chan bool)
@@ -39,21 +39,18 @@ func (vconn *FreedomConnection) Start(ray core.OutboundRay) error {
 
 func (vconn *FreedomConnection) DumpInput(conn net.Conn, input <-chan []byte, finish chan<- bool) {
 	v2net.ChanToWriter(conn, input)
-	log.Debug("Freedom closing input")
 	finish <- true
 }
 
 func (vconn *FreedomConnection) DumpOutput(conn net.Conn, output chan<- []byte, finish chan<- bool) {
 	v2net.ReaderToChan(output, conn)
 	close(output)
-	log.Debug("Freedom closing output")
 	finish <- true
 }
 
 func (vconn *FreedomConnection) CloseConn(conn net.Conn, readFinish <-chan bool, writeFinish <-chan bool) {
 	<-writeFinish
 	if tcpConn, ok := conn.(*net.TCPConn); ok {
-		log.Debug("Closing freedom write.")
 		tcpConn.CloseWrite()
 	}
 	<-readFinish

net/vmess/vmessin.go

@@ -55,10 +55,10 @@ func (handler *VMessInboundHandler) HandleConnection(connection net.Conn) error
 
 	request, err := reader.Read(connection)
 	if err != nil {
-		log.Debug("Failed to parse VMess request: %v", err)
+		log.Warning("VMessIn: Invalid request from (%s): %v", connection.RemoteAddr().String(), err)
 		return err
 	}
-	log.Debug("Received request for %s", request.Address.String())
+	log.Debug("VMessIn: Received request for %s", request.Address.String())
 
 	ray := handler.vPoint.NewInboundConnectionAccepted(request.Address)
 	input := ray.InboundInput()
@@ -75,7 +75,7 @@ func (handler *VMessInboundHandler) HandleConnection(connection net.Conn) error
 	response := vmessio.NewVMessResponse(request)
 	responseWriter, err := v2io.NewAesEncryptWriter(responseKey[:], responseIV[:], connection)
 	if err != nil {
-		return log.Error("Failed to create encrypt writer: %v", err)
+		return log.Error("VMessIn: Failed to create encrypt writer: %v", err)
 	}
 
 	// Optimize for small response packet
@@ -90,7 +90,6 @@ func (handler *VMessInboundHandler) HandleConnection(connection net.Conn) error
 	}
 
 	if tcpConn, ok := connection.(*net.TCPConn); ok {
-		log.Debug("VMessIn closing write")
 		tcpConn.CloseWrite()
 	}
 	<-readFinish
@@ -104,7 +103,7 @@ func handleInput(request *vmessio.VMessRequest, reader io.Reader, input chan<- [
 
 	requestReader, err := v2io.NewAesDecryptReader(request.RequestKey[:], request.RequestIV[:], reader)
 	if err != nil {
-		log.Error("Failed to create decrypt reader: %v", err)
+		log.Error("VMessIn: Failed to create decrypt reader: %v", err)
 		return
 	}
 
@@ -122,13 +121,13 @@ type VMessInboundHandlerFactory struct {
 func (factory *VMessInboundHandlerFactory) Create(vp *core.Point, rawConfig []byte) (core.InboundConnectionHandler, error) {
 	config, err := loadInboundConfig(rawConfig)
 	if err != nil {
-		panic(log.Error("Failed to load VMess inbound config: %v", err))
+		panic(log.Error("VMessIn: Failed to load VMess inbound config: %v", err))
 	}
 	allowedClients := core.NewTimedUserSet()
 	for _, client := range config.AllowedClients {
 		user, err := client.ToUser()
 		if err != nil {
-			panic(log.Error("Failed to parse user id %s: %v", client.Id, err))
+			panic(log.Error("VMessIn: Failed to parse user id %s: %v", client.Id, err))
 		}
 		allowedClients.AddUser(user)
 	}

net/vmess/vmessout.go

@@ -1,6 +1,7 @@
 package vmess
 
 import (
+	"bytes"
 	"crypto/md5"
 	"crypto/rand"
 	mrand "math/rand"
@@ -38,13 +39,13 @@ func NewVMessOutboundHandler(vp *core.Point, vNextList []VNextServer, dest v2net
 func (handler *VMessOutboundHandler) pickVNext() (v2net.Address, core.User) {
 	vNextLen := len(handler.vNextList)
 	if vNextLen == 0 {
-		panic("Zero vNext is configured.")
+		panic("VMessOut: Zero vNext is configured.")
 	}
 	vNextIndex := mrand.Intn(vNextLen)
 	vNext := handler.vNextList[vNextIndex]
 	vNextUserLen := len(vNext.Users)
 	if vNextUserLen == 0 {
-		panic("Zero User account.")
+		panic("VMessOut: Zero User account.")
 	}
 	vNextUserIndex := mrand.Intn(vNextUserLen)
 	vNextUser := vNext.Users[vNextUserIndex]
@@ -73,14 +74,12 @@ func startCommunicate(request *vmessio.VMessRequest, dest v2net.Address, ray cor
 	output := ray.OutboundOutput()
 
 	conn, err := net.DialTCP("tcp", nil, &net.TCPAddr{dest.IP, int(dest.Port), ""})
-	log.Debug("VMessOutbound dialing tcp: %s", dest.String())
 	if err != nil {
 		log.Error("Failed to open tcp (%s): %v", dest.String(), err)
 		close(output)
 		return err
 	}
-
-	log.Debug("VMessOut: Tunneling request for %s", request.Address.String())
+	log.Info("VMessOut: Tunneling request for %s", request.Address.String())
 
 	defer conn.Close()
 
@@ -96,17 +95,18 @@ func startCommunicate(request *vmessio.VMessRequest, dest v2net.Address, ray cor
 	return nil
 }
 
-func handleRequest(conn *net.TCPConn, request *vmessio.VMessRequest, input <-chan []byte, finish chan<- bool) error {
+func handleRequest(conn *net.TCPConn, request *vmessio.VMessRequest, input <-chan []byte, finish chan<- bool) {
 	defer close(finish)
 	encryptRequestWriter, err := v2io.NewAesEncryptWriter(request.RequestKey[:], request.RequestIV[:], conn)
 	if err != nil {
-		log.Error("Failed to create encrypt writer: %v", err)
-		return err
+		log.Error("VMessOut: Failed to create encrypt writer: %v", err)
+		return
 	}
 
 	buffer, err := request.ToBytes(v2hash.NewTimeHash(v2hash.HMACHash{}), v2math.GenerateRandomInt64InRange)
 	if err != nil {
 		log.Error("VMessOut: Failed to serialize VMess request: %v", err)
+		return
 	}
 
 	// Send first packet of payload together with request, in favor of small requests.
@@ -118,14 +118,15 @@ func handleRequest(conn *net.TCPConn, request *vmessio.VMessRequest, input <-cha
 		_, err = conn.Write(buffer)
 		if err != nil {
 			log.Error("VMessOut: Failed to write VMess request: %v", err)
+			return
 		}
 
 		v2net.ChanToWriter(encryptRequestWriter, input)
 	}
-	return nil
+	return
 }
 
-func handleResponse(conn *net.TCPConn, request *vmessio.VMessRequest, output chan<- []byte, finish chan<- bool) error {
+func handleResponse(conn *net.TCPConn, request *vmessio.VMessRequest, output chan<- []byte, finish chan<- bool) {
 	defer close(finish)
 	defer close(output)
 	responseKey := md5.Sum(request.RequestKey[:])
@@ -133,21 +134,23 @@ func handleResponse(conn *net.TCPConn, request *vmessio.VMessRequest, output cha
 
 	decryptResponseReader, err := v2io.NewAesDecryptReader(responseKey[:], responseIV[:], conn)
 	if err != nil {
-		log.Error("Failed to create decrypt reader: %v", err)
-		return err
+		log.Error("VMessOut: Failed to create decrypt reader: %v", err)
+		return
 	}
 
 	response := vmessio.VMessResponse{}
 	nBytes, err := decryptResponseReader.Read(response[:])
 	if err != nil {
-		log.Error("Failed to read VMess response (%d bytes): %v", nBytes, err)
-		return err
+		log.Error("VMessOut: Failed to read VMess response (%d bytes): %v", nBytes, err)
+		return
+	}
+	if !bytes.Equal(response[:], request.ResponseHeader[:]) {
+		log.Warning("VMessOut: unexepcted response header. The connection is probably hijacked.")
+		return
 	}
-	log.Debug("Got response %v", response)
-	// TODO: check response
 
 	v2net.ReaderToChan(output, decryptResponseReader)
-	return nil
+	return
 }
 
 type VMessOutboundHandlerFactory struct {