change log method

This commit is contained in:
fatedier
2019-10-12 20:13:12 +08:00
parent 5dc8175fc8
commit 649f47c345
44 changed files with 670 additions and 688 deletions

View File

@@ -15,8 +15,10 @@
package server
import (
"context"
"fmt"
"io"
"net"
"runtime/debug"
"sync"
"time"
@@ -28,8 +30,8 @@ import (
"github.com/fatedier/frp/server/controller"
"github.com/fatedier/frp/server/proxy"
"github.com/fatedier/frp/server/stats"
"github.com/fatedier/frp/utils/net"
"github.com/fatedier/frp/utils/version"
"github.com/fatedier/frp/utils/xlog"
"github.com/fatedier/golib/control/shutdown"
"github.com/fatedier/golib/crypto"
@@ -131,9 +133,12 @@ type Control struct {
// Server configuration information
serverCfg config.ServerCommonConf
xl *xlog.Logger
ctx context.Context
}
func NewControl(rc *controller.ResourceController, pxyManager *proxy.ProxyManager,
func NewControl(ctx context.Context, rc *controller.ResourceController, pxyManager *proxy.ProxyManager,
statsCollector stats.Collector, ctlConn net.Conn, loginMsg *msg.Login,
serverCfg config.ServerCommonConf) *Control {
@@ -161,6 +166,8 @@ func NewControl(rc *controller.ResourceController, pxyManager *proxy.ProxyManage
managerShutdown: shutdown.New(),
allShutdown: shutdown.New(),
serverCfg: serverCfg,
xl: xlog.FromContextSafe(ctx),
ctx: ctx,
}
}
@@ -185,18 +192,19 @@ func (ctl *Control) Start() {
}
func (ctl *Control) RegisterWorkConn(conn net.Conn) {
xl := ctl.xl
defer func() {
if err := recover(); err != nil {
ctl.conn.Error("panic error: %v", err)
ctl.conn.Error(string(debug.Stack()))
xl.Error("panic error: %v", err)
xl.Error(string(debug.Stack()))
}
}()
select {
case ctl.workConnCh <- conn:
ctl.conn.Debug("new work connection registered")
xl.Debug("new work connection registered")
default:
ctl.conn.Debug("work connection pool is full, discarding")
xl.Debug("work connection pool is full, discarding")
conn.Close()
}
}
@@ -206,10 +214,11 @@ func (ctl *Control) RegisterWorkConn(conn net.Conn) {
// and wait until it is available.
// return an error if wait timeout
func (ctl *Control) GetWorkConn() (workConn net.Conn, err error) {
xl := ctl.xl
defer func() {
if err := recover(); err != nil {
ctl.conn.Error("panic error: %v", err)
ctl.conn.Error(string(debug.Stack()))
xl.Error("panic error: %v", err)
xl.Error(string(debug.Stack()))
}
}()
@@ -221,14 +230,14 @@ func (ctl *Control) GetWorkConn() (workConn net.Conn, err error) {
err = frpErr.ErrCtlClosed
return
}
ctl.conn.Debug("get work connection from pool")
xl.Debug("get work connection from pool")
default:
// no work connections available in the poll, send message to frpc to get more
err = errors.PanicToError(func() {
ctl.sendCh <- &msg.ReqWorkConn{}
})
if err != nil {
ctl.conn.Error("%v", err)
xl.Error("%v", err)
return
}
@@ -236,13 +245,13 @@ func (ctl *Control) GetWorkConn() (workConn net.Conn, err error) {
case workConn, ok = <-ctl.workConnCh:
if !ok {
err = frpErr.ErrCtlClosed
ctl.conn.Warn("no work connections avaiable, %v", err)
xl.Warn("no work connections avaiable, %v", err)
return
}
case <-time.After(time.Duration(ctl.serverCfg.UserConnTimeout) * time.Second):
err = fmt.Errorf("timeout trying to get work connection")
ctl.conn.Warn("%v", err)
xl.Warn("%v", err)
return
}
}
@@ -255,16 +264,18 @@ func (ctl *Control) GetWorkConn() (workConn net.Conn, err error) {
}
func (ctl *Control) Replaced(newCtl *Control) {
ctl.conn.Info("Replaced by client [%s]", newCtl.runId)
xl := ctl.xl
xl.Info("Replaced by client [%s]", newCtl.runId)
ctl.runId = ""
ctl.allShutdown.Start()
}
func (ctl *Control) writer() {
xl := ctl.xl
defer func() {
if err := recover(); err != nil {
ctl.conn.Error("panic error: %v", err)
ctl.conn.Error(string(debug.Stack()))
xl.Error("panic error: %v", err)
xl.Error(string(debug.Stack()))
}
}()
@@ -273,17 +284,17 @@ func (ctl *Control) writer() {
encWriter, err := crypto.NewWriter(ctl.conn, []byte(ctl.serverCfg.Token))
if err != nil {
ctl.conn.Error("crypto new writer error: %v", err)
xl.Error("crypto new writer error: %v", err)
ctl.allShutdown.Start()
return
}
for {
if m, ok := <-ctl.sendCh; !ok {
ctl.conn.Info("control writer is closing")
xl.Info("control writer is closing")
return
} else {
if err := msg.WriteMsg(encWriter, m); err != nil {
ctl.conn.Warn("write message to control connection error: %v", err)
xl.Warn("write message to control connection error: %v", err)
return
}
}
@@ -291,10 +302,11 @@ func (ctl *Control) writer() {
}
func (ctl *Control) reader() {
xl := ctl.xl
defer func() {
if err := recover(); err != nil {
ctl.conn.Error("panic error: %v", err)
ctl.conn.Error(string(debug.Stack()))
xl.Error("panic error: %v", err)
xl.Error(string(debug.Stack()))
}
}()
@@ -305,10 +317,10 @@ func (ctl *Control) reader() {
for {
if m, err := msg.ReadMsg(encReader); err != nil {
if err == io.EOF {
ctl.conn.Debug("control connection closed")
xl.Debug("control connection closed")
return
} else {
ctl.conn.Warn("read error: %v", err)
xl.Warn("read error: %v", err)
ctl.conn.Close()
return
}
@@ -319,10 +331,11 @@ func (ctl *Control) reader() {
}
func (ctl *Control) stoper() {
xl := ctl.xl
defer func() {
if err := recover(); err != nil {
ctl.conn.Error("panic error: %v", err)
ctl.conn.Error(string(debug.Stack()))
xl.Error("panic error: %v", err)
xl.Error(string(debug.Stack()))
}
}()
@@ -355,7 +368,7 @@ func (ctl *Control) stoper() {
}
ctl.allShutdown.Done()
ctl.conn.Info("client exit success")
xl.Info("client exit success")
ctl.statsCollector.Mark(stats.TypeCloseClient, &stats.CloseClientPayload{})
}
@@ -366,10 +379,11 @@ func (ctl *Control) WaitClosed() {
}
func (ctl *Control) manager() {
xl := ctl.xl
defer func() {
if err := recover(); err != nil {
ctl.conn.Error("panic error: %v", err)
ctl.conn.Error(string(debug.Stack()))
xl.Error("panic error: %v", err)
xl.Error(string(debug.Stack()))
}
}()
@@ -383,7 +397,7 @@ func (ctl *Control) manager() {
select {
case <-heartbeat.C:
if time.Since(ctl.lastPing) > time.Duration(ctl.serverCfg.HeartBeatTimeout)*time.Second {
ctl.conn.Warn("heartbeat timeout")
xl.Warn("heartbeat timeout")
return
}
case rawMsg, ok := <-ctl.readCh:
@@ -400,10 +414,10 @@ func (ctl *Control) manager() {
}
if err != nil {
resp.Error = err.Error()
ctl.conn.Warn("new proxy [%s] error: %v", m.ProxyName, err)
xl.Warn("new proxy [%s] error: %v", m.ProxyName, err)
} else {
resp.RemoteAddr = remoteAddr
ctl.conn.Info("new proxy [%s] success", m.ProxyName)
xl.Info("new proxy [%s] success", m.ProxyName)
ctl.statsCollector.Mark(stats.TypeNewProxy, &stats.NewProxyPayload{
Name: m.ProxyName,
ProxyType: m.ProxyType,
@@ -412,10 +426,10 @@ func (ctl *Control) manager() {
ctl.sendCh <- resp
case *msg.CloseProxy:
ctl.CloseProxy(m)
ctl.conn.Info("close proxy [%s] success", m.ProxyName)
xl.Info("close proxy [%s] success", m.ProxyName)
case *msg.Ping:
ctl.lastPing = time.Now()
ctl.conn.Debug("receive heartbeat")
xl.Debug("receive heartbeat")
ctl.sendCh <- &msg.Pong{}
}
}
@@ -432,7 +446,7 @@ func (ctl *Control) RegisterProxy(pxyMsg *msg.NewProxy) (remoteAddr string, err
// NewProxy will return a interface Proxy.
// In fact it create different proxies by different proxy type, we just call run() here.
pxy, err := proxy.NewProxy(ctl.runId, ctl.rc, ctl.statsCollector, ctl.poolCount, ctl.GetWorkConn, pxyConf, ctl.serverCfg)
pxy, err := proxy.NewProxy(ctl.ctx, ctl.runId, ctl.rc, ctl.statsCollector, ctl.poolCount, ctl.GetWorkConn, pxyConf, ctl.serverCfg)
if err != nil {
return remoteAddr, err
}