add more log

client/control.go

@@ -281,18 +281,21 @@ func (ctl *Control) manager() {
 					ctl.Warn("[%s] start error: %s", m.ProxyName, m.Error)
 					continue
 				}
-				oldPxy, ok := ctl.proxies[m.ProxyName]
-				if ok {
-					oldPxy.Close()
-				}
 				cfg, ok := ctl.pxyCfgs[m.ProxyName]
 				if !ok {
 					// it will never go to this branch
 					ctl.Warn("[%s] no proxy conf found", m.ProxyName)
 					continue
 				}
+				oldPxy, ok := ctl.proxies[m.ProxyName]
+				if ok {
+					oldPxy.Close()
+				}
 				pxy := NewProxy(ctl, cfg)
-				pxy.Run()
+				if err := pxy.Run(); err != nil {
+					ctl.Warn("[%s] proxy start running error: %v", m.ProxyName, err)
+					continue
+				}
 				ctl.proxies[m.ProxyName] = pxy
 				ctl.Info("[%s] start proxy success", m.ProxyName)
 			case *msg.Pong:
@@ -307,46 +310,64 @@ func (ctl *Control) controler() {
 	var err error
 	maxDelayTime := 30 * time.Second
 	delayTime := time.Second
+
+	checkInterval := 60 * time.Second
+	checkProxyTicker := time.NewTicker(checkInterval)
 	for {
-		// we won't get any variable from this channel
-		_, ok := <-ctl.closedCh
-		if !ok {
-			// close related channels
-			close(ctl.readCh)
-			close(ctl.sendCh)
-			time.Sleep(time.Second)
-
-			// loop util reconnect to server success
-			for {
-				ctl.Info("try to reconnect to server...")
-				err = ctl.login()
-				if err != nil {
-					ctl.Warn("reconnect to server error: %v", err)
-					time.Sleep(delayTime)
-					delayTime = delayTime * 2
-					if delayTime > maxDelayTime {
-						delayTime = maxDelayTime
-					}
-					continue
-				}
-				// reconnect success, init the delayTime
-				delayTime = time.Second
-				break
-			}
-
-			// init related channels and variables
-			ctl.init()
-
-			// previous work goroutines should be closed and start them here
-			go ctl.manager()
-			go ctl.writer()
-			go ctl.reader()
-
-			// send NewProxy message for all configured proxies
+		select {
+		case <-checkProxyTicker.C:
+			// Every 60 seconds, check which proxy registered failed and reregister it to server.
 			for _, cfg := range ctl.pxyCfgs {
-				var newProxyMsg msg.NewProxy
-				cfg.UnMarshalToMsg(&newProxyMsg)
-				ctl.sendCh <- &newProxyMsg
+				if _, exist := ctl.proxies[cfg.GetName()]; !exist {
+					ctl.Info("try to reregister proxy [%s]", cfg.GetName())
+					var newProxyMsg msg.NewProxy
+					cfg.UnMarshalToMsg(&newProxyMsg)
+					ctl.sendCh <- &newProxyMsg
+				}
+			}
+		case _, ok := <-ctl.closedCh:
+			// we won't get any variable from this channel
+			if !ok {
+				// close related channels
+				close(ctl.readCh)
+				close(ctl.sendCh)
+				time.Sleep(time.Second)
+
+				// loop util reconnect to server success
+				for {
+					ctl.Info("try to reconnect to server...")
+					err = ctl.login()
+					if err != nil {
+						ctl.Warn("reconnect to server error: %v", err)
+						time.Sleep(delayTime)
+						delayTime = delayTime * 2
+						if delayTime > maxDelayTime {
+							delayTime = maxDelayTime
+						}
+						continue
+					}
+					// reconnect success, init the delayTime
+					delayTime = time.Second
+					break
+				}
+
+				// init related channels and variables
+				ctl.init()
+
+				// previous work goroutines should be closed and start them here
+				go ctl.manager()
+				go ctl.writer()
+				go ctl.reader()
+
+				// send NewProxy message for all configured proxies
+				for _, cfg := range ctl.pxyCfgs {
+					var newProxyMsg msg.NewProxy
+					cfg.UnMarshalToMsg(&newProxyMsg)
+					ctl.sendCh <- &newProxyMsg
+				}
+
+				checkProxyTicker.Stop()
+				checkProxyTicker = time.NewTicker(checkInterval)
 			}
 		}
 	}

client/proxy.go

@@ -25,7 +25,7 @@ import (
 
 // Proxy defines how to work for different proxy type.
 type Proxy interface {
-	Run()
+	Run() error
 
 	// InWorkConn accept work connections registered to server.
 	InWorkConn(conn net.Conn)
@@ -64,7 +64,8 @@ type TcpProxy struct {
 	ctl *Control
 }
 
-func (pxy *TcpProxy) Run() {
+func (pxy *TcpProxy) Run() (err error) {
+	return
 }
 
 func (pxy *TcpProxy) Close() {
@@ -81,7 +82,8 @@ type HttpProxy struct {
 	ctl *Control
 }
 
-func (pxy *HttpProxy) Run() {
+func (pxy *HttpProxy) Run() (err error) {
+	return
 }
 
 func (pxy *HttpProxy) Close() {
@@ -98,7 +100,8 @@ type HttpsProxy struct {
 	ctl *Control
 }
 
-func (pxy *HttpsProxy) Run() {
+func (pxy *HttpsProxy) Run() (err error) {
+	return
 }
 
 func (pxy *HttpsProxy) Close() {
@@ -115,7 +118,8 @@ type UdpProxy struct {
 	ctl *Control
 }
 
-func (pxy *UdpProxy) Run() {
+func (pxy *UdpProxy) Run() (err error) {
+	return
 }
 
 func (pxy *UdpProxy) Close() {

server/control.go

@@ -108,9 +108,9 @@ func (ctl *Control) RegisterWorkConn(conn net.Conn) {
 
 	select {
 	case ctl.workConnCh <- conn:
-		ctl.conn.Debug("new work connection registered.")
+		ctl.conn.Debug("new work connection registered")
 	default:
-		ctl.conn.Debug("work connection pool is full, discarding.")
+		ctl.conn.Debug("work connection pool is full, discarding")
 		conn.Close()
 	}
 }

server/proxy.go

@@ -109,6 +109,7 @@ func (pxy *TcpProxy) Run() error {
 	if err != nil {
 		return err
 	}
+	listener.AddLogPrefix(pxy.name)
 	pxy.listeners = append(pxy.listeners, listener)
 	pxy.Info("tcp proxy listen port [%d]", pxy.cfg.RemotePort)
 
@@ -148,6 +149,7 @@ func (pxy *HttpProxy) Run() (err error) {
 			if err != nil {
 				return err
 			}
+			l.AddLogPrefix(pxy.name)
 			pxy.Info("http proxy listen for host [%s] location [%s]", routeConfig.Domain, routeConfig.Location)
 			pxy.listeners = append(pxy.listeners, l)
 		}
@@ -161,6 +163,7 @@ func (pxy *HttpProxy) Run() (err error) {
 			if err != nil {
 				return err
 			}
+			l.AddLogPrefix(pxy.name)
 			pxy.Info("http proxy listen for host [%s] location [%s]", routeConfig.Domain, routeConfig.Location)
 			pxy.listeners = append(pxy.listeners, l)
 		}
@@ -192,6 +195,7 @@ func (pxy *HttpsProxy) Run() (err error) {
 		if err != nil {
 			return err
 		}
+		l.AddLogPrefix(pxy.name)
 		pxy.Info("https proxy listen for host [%s]", routeConfig.Domain)
 		pxy.listeners = append(pxy.listeners, l)
 	}
@@ -202,6 +206,7 @@ func (pxy *HttpsProxy) Run() (err error) {
 		if err != nil {
 			return err
 		}
+		l.AddLogPrefix(pxy.name)
 		pxy.Info("https proxy listen for host [%s]", routeConfig.Domain)
 		pxy.listeners = append(pxy.listeners, l)
 	}

utils/log/log.go

@@ -82,6 +82,7 @@ func Debug(format string, v ...interface{}) {
 // Logger
 type Logger interface {
 	AddLogPrefix(string)
+	GetAllPrefix() []string
 	ClearLogPrefix()
 	Error(string, ...interface{})
 	Warn(string, ...interface{})
@@ -90,11 +91,14 @@ type Logger interface {
 }
 
 type PrefixLogger struct {
-	prefix string
+	prefix    string
+	allPrefix []string
 }
 
 func NewPrefixLogger(prefix string) *PrefixLogger {
-	logger := &PrefixLogger{}
+	logger := &PrefixLogger{
+		allPrefix: make([]string, 0),
+	}
 	logger.AddLogPrefix(prefix)
 	return logger
 }
@@ -104,14 +108,17 @@ func (pl *PrefixLogger) AddLogPrefix(prefix string) {
 		return
 	}
 
-	if len(pl.prefix) > 0 {
-		pl.prefix += " "
-	}
 	pl.prefix += "[" + prefix + "] "
+	pl.allPrefix = append(pl.allPrefix, prefix)
+}
+
+func (pl *PrefixLogger) GetAllPrefix() []string {
+	return pl.allPrefix
 }
 
 func (pl *PrefixLogger) ClearLogPrefix() {
 	pl.prefix = ""
+	pl.allPrefix = make([]string, 0)
 }
 
 func (pl *PrefixLogger) Error(format string, v ...interface{}) {

utils/net/conn.go

@@ -29,4 +29,5 @@ type Conn interface {
 type Listener interface {
 	Accept() (Conn, error)
 	Close() error
+	log.Logger
 }

utils/net/tcp.go

@@ -30,6 +30,7 @@ type TcpListener struct {
 	listener  net.Listener
 	accept    chan Conn
 	closeFlag bool
+	log.Logger
 }
 
 func ListenTcp(bindAddr string, bindPort int64) (l *TcpListener, err error) {
@@ -47,6 +48,7 @@ func ListenTcp(bindAddr string, bindPort int64) (l *TcpListener, err error) {
 		listener:  listener,
 		accept:    make(chan Conn),
 		closeFlag: false,
+		Logger:    log.NewPrefixLogger(""),
 	}
 
 	go func() {

utils/net/udp.go

@@ -21,7 +21,7 @@ import (
 	"sync"
 	"time"
 
-	flog "github.com/fatedier/frp/utils/log"
+	"github.com/fatedier/frp/utils/log"
 	"github.com/fatedier/frp/utils/pool"
 )
 
@@ -32,7 +32,7 @@ type UdpPacket struct {
 }
 
 type FakeUdpConn struct {
-	flog.Logger
+	log.Logger
 	l *UdpListener
 
 	localAddr  net.Addr
@@ -46,7 +46,7 @@ type FakeUdpConn struct {
 
 func NewFakeUdpConn(l *UdpListener, laddr, raddr net.Addr) *FakeUdpConn {
 	fc := &FakeUdpConn{
-		Logger:     flog.NewPrefixLogger(""),
+		Logger:     log.NewPrefixLogger(""),
 		l:          l,
 		localAddr:  laddr,
 		remoteAddr: raddr,
@@ -163,6 +163,8 @@ type UdpListener struct {
 	closeFlag bool
 
 	fakeConns map[string]*FakeUdpConn
+
+	log.Logger
 }
 
 func ListenUDP(bindAddr string, bindPort int64) (l *UdpListener, err error) {
@@ -177,6 +179,7 @@ func ListenUDP(bindAddr string, bindPort int64) (l *UdpListener, err error) {
 		accept:    make(chan Conn),
 		writeCh:   make(chan *UdpPacket, 1000),
 		fakeConns: make(map[string]*FakeUdpConn),
+		Logger:    log.NewPrefixLogger(""),
 	}
 
 	// for reading

utils/vhost/vhost.go

@@ -20,6 +20,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/fatedier/frp/utils/log"
 	frpNet "github.com/fatedier/frp/utils/net"
 )
 
@@ -77,6 +78,7 @@ func (v *VhostMuxer) Listen(cfg *VhostRouteConfig) (l *Listener, err error) {
 		passWord:    cfg.Password,
 		mux:         v,
 		accept:      make(chan frpNet.Conn),
+		Logger:      log.NewPrefixLogger(""),
 	}
 	v.registryRouter.Add(cfg.Domain, cfg.Location, l)
 	return l, nil
@@ -126,6 +128,7 @@ func (v *VhostMuxer) handle(c frpNet.Conn) {
 
 	sConn, reqInfoMap, err := v.vhostFunc(c)
 	if err != nil {
+		log.Error("get hostname from http/https request error: %v", err)
 		c.Close()
 		return
 	}
@@ -134,16 +137,17 @@ func (v *VhostMuxer) handle(c frpNet.Conn) {
 	path := strings.ToLower(reqInfoMap["Path"])
 	l, ok := v.getListener(name, path)
 	if !ok {
+		log.Debug("http request for host [%s] path [%s] not found", name, path)
 		c.Close()
 		return
 	}
 
 	// if authFunc is exist and userName/password is set
 	// verify user access
-	if l.mux.authFunc != nil &&
-		l.userName != "" && l.passWord != "" {
+	if l.mux.authFunc != nil && l.userName != "" && l.passWord != "" {
 		bAccess, err := l.mux.authFunc(c, l.userName, l.passWord, reqInfoMap["Authorization"])
 		if bAccess == false || err != nil {
+			l.Debug("check Authorization failed")
 			res := noAuthResponse()
 			res.Write(c)
 			c.Close()
@@ -157,6 +161,7 @@ func (v *VhostMuxer) handle(c frpNet.Conn) {
 	}
 	c = sConn
 
+	l.Debug("get new http request host [%s] path [%s]", name, path)
 	l.accept <- c
 }
 
@@ -168,6 +173,7 @@ type Listener struct {
 	passWord    string
 	mux         *VhostMuxer // for closing VhostMuxer
 	accept      chan frpNet.Conn
+	log.Logger
 }
 
 func (l *Listener) Accept() (frpNet.Conn, error) {
@@ -181,11 +187,16 @@ func (l *Listener) Accept() (frpNet.Conn, error) {
 	if l.mux.rewriteFunc != nil && l.rewriteHost != "" {
 		sConn, err := l.mux.rewriteFunc(conn, l.rewriteHost)
 		if err != nil {
-			return nil, fmt.Errorf("http host header rewrite failed")
+			l.Warn("host header rewrite failed: %v", err)
+			return nil, fmt.Errorf("host header rewrite failed")
 		}
+		l.Debug("rewrite host to [%s] success", l.rewriteHost)
 		conn = sConn
 	}
 
+	for _, prefix := range l.GetAllPrefix() {
+		conn.AddLogPrefix(prefix)
+	}
 	return conn, nil
 }