From 9637cde6599b5bc89ed94a8ddb32a9cfbaa9de03 Mon Sep 17 00:00:00 2001 From: lqqyt2423 <974923609@qq.com> Date: Mon, 7 Dec 2020 22:06:33 +0800 Subject: [PATCH] logger --- README.md | 4 +-- cert/cert.go | 7 +++-- cmd/mitmproxy/main.go | 10 +++++-- go.mod | 1 + go.sum | 7 +++++ proxy/mitm.go | 5 ++-- proxy/proxy.go | 68 ++++++++++++++++++++++++++++++++----------- 7 files changed, 76 insertions(+), 26 deletions(-) diff --git a/README.md b/README.md index db35648..09917cd 100644 --- a/README.md +++ b/README.md @@ -9,6 +9,6 @@ - [x] cert - [x] https handler - [ ] http2 -- [ ] logger +- [x] logger - [ ] 经内存转发 https 流量 -- [ ] 忽略某些错误例如：broken pipe, reset by peer, timeout +- [x] 忽略某些错误例如：broken pipe, reset by peer, timeout diff --git a/cert/cert.go b/cert/cert.go index 3a10960..7f9868c 100644 --- a/cert/cert.go +++ b/cert/cert.go @@ -11,15 +11,17 @@ import ( "fmt" "io" "io/ioutil" - "log" "math/big" "os" "path/filepath" "time" "github.com/golang/groupcache/lru" + _log "github.com/sirupsen/logrus" ) +var log = _log.WithField("at", "cert") + // reference // https://docs.mitmproxy.org/stable/concepts-certificates/ // https://github.com/mitmproxy/mitmproxy/blob/master/mitmproxy/certs.py @@ -49,13 +51,14 @@ func NewCA(path string) (*CA, error) { return nil, err } } else { + log.Debug("load root ca") return ca, nil } - log.Println("begin create ca") if err := ca.create(); err != nil { return nil, err } + log.Debug("create root ca") return ca, nil } diff --git a/cmd/mitmproxy/main.go b/cmd/mitmproxy/main.go index 9281ca8..1350928 100644 --- a/cmd/mitmproxy/main.go +++ b/cmd/mitmproxy/main.go @@ -1,13 +1,19 @@ package main import ( - "log" + "os" "github.com/lqqyt2423/go-mitmproxy/proxy" + log "github.com/sirupsen/logrus" ) func main() { - log.SetFlags(log.LstdFlags | log.Lshortfile) + log.SetLevel(log.InfoLevel) + log.SetReportCaller(false) + log.SetOutput(os.Stdout) + log.SetFormatter(&log.TextFormatter{ + FullTimestamp: true, + }) opts := &proxy.Options{ Addr: ":9080", diff --git a/go.mod b/go.mod index 296778d..9501986 100644 --- a/go.mod +++ b/go.mod @@ -6,4 +6,5 @@ require ( github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e github.com/golang/protobuf v1.4.3 // indirect github.com/joho/godotenv v1.3.0 + github.com/sirupsen/logrus v1.7.0 ) diff --git a/go.sum b/go.sum index 647b21d..e976b32 100644 --- a/go.sum +++ b/go.sum @@ -1,3 +1,4 @@ +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e h1:1r7pUrabqp18hOBcwBwiTsbnFeTZHV9eER/QT5JVZxY= github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/protobuf v1.4.0-rc.1/go.mod h1:ceaxUfeHdC40wWswd/P6IGgMaK3YpKi5j83Wpe3EHw8= @@ -12,6 +13,12 @@ github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMyw github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/joho/godotenv v1.3.0 h1:Zjp+RcGpHhGlrMbJzXTrZZPrWj+1vfm90La1wgB6Bhc= github.com/joho/godotenv v1.3.0/go.mod h1:7hK45KPybAkOC6peb+G5yklZfMxEjkZhHbwpqxOKXbg= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/sirupsen/logrus v1.7.0 h1:ShrD1U9pZB12TX0cVy0DtePoCH97K8EtX+mg7ZARUtM= +github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= +golang.org/x/sys v0.0.0-20191026070338-33540a1f6037 h1:YyJpGZS1sBuBCzLAR1VEpK193GlqGZbnPFnPV/5Rsb4= +golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= google.golang.org/protobuf v0.0.0-20200109180630-ec00e32a8dfd/go.mod h1:DFci5gLYBciE7Vtevhsrf46CRTquxDuWsQurQQe4oz8= google.golang.org/protobuf v0.0.0-20200221191635-4d8936d0db64/go.mod h1:kwYJMbMJ01Woi6D6+Kah6886xMZcty6N08ah7+eCXa0= diff --git a/proxy/mitm.go b/proxy/mitm.go index 616c4a5..6068890 100644 --- a/proxy/mitm.go +++ b/proxy/mitm.go @@ -2,7 +2,6 @@ package proxy import ( "crypto/tls" - "log" "net" "net/http" "time" @@ -52,7 +51,7 @@ func NewMitmServer(proxy *Proxy) (Mitm, error) { TLSNextProto: make(map[string]func(*http.Server, *tls.Conn, http.Handler)), // disable http2 TLSConfig: &tls.Config{ GetCertificate: func(chi *tls.ClientHelloInfo) (*tls.Certificate, error) { - // log.Printf("MitmServer GetCertificate ServerName: %v\n", chi.ServerName) + log.Debugf("MitmServer GetCertificate ServerName: %v\n", chi.ServerName) return ca.GetCert(chi.ServerName) }, }, @@ -70,7 +69,7 @@ func (m *MitmServer) Start() error { } m.Listener = ln m.Server.Addr = ln.Addr().String() - log.Printf("MitmServer Server Addr is %v\n", m.Server.Addr) + log.Infof("MitmServer Server Addr is %v\n", m.Server.Addr) defer ln.Close() return m.Server.ServeTLS(ln, "", "") diff --git a/proxy/proxy.go b/proxy/proxy.go index 9de34fd..21f4245 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -3,14 +3,36 @@ package proxy import ( "crypto/tls" "io" - "log" "net" "net/http" "os" + "strings" "sync" "time" + + _log "github.com/sirupsen/logrus" ) +var log = _log.WithField("at", "proxy") + +var ignoreErr = func(log *_log.Entry, err error) bool { + errs := err.Error() + strs := []string{ + "read: connection reset by peer", + "write: broken pipe", + "i/o timeout", + } + + for _, str := range strs { + if strings.Contains(errs, str) { + log.Debug(str) + return true + } + } + + return false +} + type Options struct { Addr string } @@ -30,7 +52,7 @@ func (proxy *Proxy) Start() error { } }() - log.Printf("Proxy start listen at %v\n", proxy.Server.Addr) + log.Infof("Proxy start listen at %v\n", proxy.Server.Addr) return proxy.Server.ListenAndServe() } @@ -40,11 +62,16 @@ func (proxy *Proxy) ServeHTTP(res http.ResponseWriter, req *http.Request) { return } + log := log.WithFields(_log.Fields{ + "in": "ServeHTTP", + "url": req.URL, + }) + if !req.URL.IsAbs() || req.URL.Host == "" { res.WriteHeader(400) _, err := io.WriteString(res, "此为代理服务器，不能直接发起请求") if err != nil { - log.Printf("error: %v, url: %v\n", err, req.URL.String()) + log.Error(err) } return } @@ -53,7 +80,7 @@ func (proxy *Proxy) ServeHTTP(res http.ResponseWriter, req *http.Request) { proxyReq, err := http.NewRequest(req.Method, req.URL.String(), req.Body) if err != nil { - log.Printf("error: %v, url: %v\n", err, req.URL.String()) + log.Error(err) res.WriteHeader(502) return } @@ -65,7 +92,9 @@ func (proxy *Proxy) ServeHTTP(res http.ResponseWriter, req *http.Request) { } proxyRes, err := proxy.Client.Do(proxyReq) if err != nil { - log.Printf("error: %v, url: %v\n", err, req.URL.String()) + if !ignoreErr(log, err) { + log.Error(err) + } res.WriteHeader(502) return } @@ -78,21 +107,26 @@ func (proxy *Proxy) ServeHTTP(res http.ResponseWriter, req *http.Request) { } res.WriteHeader(proxyRes.StatusCode) _, err = io.Copy(res, proxyRes.Body) - if err != nil { - log.Printf("error: %v, url: %v\n", err, req.URL.String()) + if err != nil && !ignoreErr(log, err) { + log.Error(err) return } - log.Printf("%v %v %v - %v ms", req.Method, req.URL.String(), proxyRes.StatusCode, time.Since(start).Milliseconds()) + log.Infof("%v %v %v - %v ms", req.Method, req.URL.String(), proxyRes.StatusCode, time.Since(start).Milliseconds()) } func (proxy *Proxy) handleConnect(res http.ResponseWriter, req *http.Request) { - // log.Printf("CONNECT: %v\n", req.Host) + log := log.WithFields(_log.Fields{ + "in": "handleConnect", + "host": req.Host, + }) + + log.Debug("CONNECT") conn, err := proxy.Mitm.Dial(req.Host) if err != nil { - log.Printf("error: %v, host: %v\n", err, req.Host) + log.Error(err) res.WriteHeader(502) return } @@ -100,7 +134,7 @@ func (proxy *Proxy) handleConnect(res http.ResponseWriter, req *http.Request) { cconn, _, err := res.(http.Hijacker).Hijack() if err != nil { - log.Printf("error: %v, host: %v\n", err, req.Host) + log.Error(err) res.WriteHeader(502) return } @@ -108,22 +142,22 @@ func (proxy *Proxy) handleConnect(res http.ResponseWriter, req *http.Request) { _, err = io.WriteString(cconn, "HTTP/1.1 200 Connection Established\r\n\r\n") if err != nil { - log.Printf("error: %v, host: %v\n", err, req.Host) + log.Error(err) return } ch := make(chan bool) go func() { _, err := io.Copy(conn, cconn) - if err != nil { - log.Printf("error: %v, host: %v\n", err, req.Host) + if err != nil && !ignoreErr(log, err) { + log.Error(err) } ch <- true }() _, err = io.Copy(cconn, conn) - if err != nil { - log.Printf("error: %v, host: %v\n", err, req.Host) + if err != nil && !ignoreErr(log, err) { + log.Error(err) } <-ch @@ -180,7 +214,7 @@ func GetTlsKeyLogWriter() io.Writer { writer, err := os.OpenFile(logfile, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0666) if err != nil { - log.Printf("GetTlsKeyLogWriter error: %v\n", err) + log.WithField("in", "GetTlsKeyLogWriter").Debug(err) return }