From 37692d4104fb71a1ba11aaf9fbc4c5b2cd0653ae Mon Sep 17 00:00:00 2001 From: Masahiro Nagano Date: Tue, 5 Feb 2019 00:37:35 +0900 Subject: [PATCH] use zap --- Gopkg.lock | 81 ++++++++++++++++++++++++++++++++++++++-------- wsgate-server.go | 83 ++++++++++++++++++++++++++++++------------------ 2 files changed, 119 insertions(+), 45 deletions(-) diff --git a/Gopkg.lock b/Gopkg.lock index 91a2e0b..ac552e5 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -2,50 +2,103 @@ [[projects]] + digest = "1:6098222470fe0172157ce9bbef5d2200df4edde17ee649c5d6e48330e4afa4c6" name = "github.com/dgrijalva/jwt-go" packages = ["."] + pruneopts = "" revision = "06ea1031745cb8b3dab3f6a236daf2b0aa468b7e" version = "v3.2.0" [[projects]] + digest = "1:e692d16fdfbddb94e9e4886aaf6c08bdbae5cb4ac80651445de9181b371c6e46" name = "github.com/go-sql-driver/mysql" packages = ["."] - revision = "a0583e0143b1624142adab07e0e97fe106d99561" - version = "v1.3" - -[[projects]] - name = "github.com/gorilla/context" - packages = ["."] - revision = "1ea25387ff6f684839d82767c1733ff4d4d15d0a" - version = "v1.1" + pruneopts = "" + revision = "72cd26f257d44c1114970e19afddcd812016007e" + version = "v1.4.1" [[projects]] + digest = "1:a3c01bbe8766cbce019cdb900aa51460a6f7bd4266a18d80722dc92297302bc3" name = "github.com/gorilla/mux" packages = ["."] - revision = "53c1911da2b537f792e7cafcb446b05ffe33b996" - version = "v1.6.1" + pruneopts = "" + revision = "a7962380ca08b5a188038c69871b8d3fbdf31e89" + version = "v1.7.0" [[projects]] + digest = "1:09aa5dd1332b93c96bde671bafb053249dc813febf7d5ca84e8f382ba255d67d" name = "github.com/gorilla/websocket" packages = ["."] - revision = "ea4d1f681babbce9545c9c5f3d5194a789c89f5b" - version = "v1.2.0" + pruneopts = "" + revision = "66b9c49e59c6c48f0ffce28c2d8b8a5678502c6d" + version = "v1.4.0" [[projects]] branch = "master" + digest = "1:bdc52a35e5f4d15e49a3c2fa8de3c407c952800c26a20818dfd9248611d6b572" name = "github.com/lestrrat/go-server-starter-listener" packages = ["."] + pruneopts = "" revision = "00dd68592c85334ce94a28199ec7961352c0ba6d" +[[projects]] + digest = "1:74f86c458e82e1c4efbab95233e0cf51b7cc02dc03193be9f62cd81224e10401" + name = "go.uber.org/atomic" + packages = ["."] + pruneopts = "" + revision = "1ea20fb1cbb1cc08cbd0d913a96dead89aa18289" + version = "v1.3.2" + +[[projects]] + digest = "1:22c7effcb4da0eacb2bb1940ee173fac010e9ef3c691f5de4b524d538bd980f5" + name = "go.uber.org/multierr" + packages = ["."] + pruneopts = "" + revision = "3c4937480c32f4c13a875a1829af76c98ca3d40a" + version = "v1.1.0" + +[[projects]] + digest = "1:246f378f80fba6fcf0f191c486b6613265abd2bc0f2fa55a36b928c67352021e" + name = "go.uber.org/zap" + packages = [ + ".", + "buffer", + "internal/bufferpool", + "internal/color", + "internal/exit", + "zapcore", + ] + pruneopts = "" + revision = "ff33455a0e382e8a81d14dd7c922020b6b5e7982" + version = "v1.9.1" + [[projects]] branch = "master" + digest = "1:1e9704e5379e68ac473c28aeb3f7e7cd4036ae8a246bf0285b5ebdbb8e0cfacf" name = "golang.org/x/net" packages = ["websocket"] - revision = "b3c676e531a6dc479fa1b35ac961c13f5e2b4d2e" + pruneopts = "" + revision = "d26f9f9a57f3fab6a695bec0d84433c2c50f8bbf" + +[[projects]] + digest = "1:bc09e719c4e2a15d17163f5272d9a3131c45d77542b7fdc53ff518815bc19ab3" + name = "google.golang.org/appengine" + packages = ["cloudsql"] + pruneopts = "" + revision = "e9657d882bb81064595ca3b56cbe2546bbabf7b1" + version = "v1.4.0" [solve-meta] analyzer-name = "dep" analyzer-version = 1 - inputs-digest = "fe901a54c9c0ed5c0fd48d4112e7ed9e8f1829d83392de84950ba9349862109e" + input-imports = [ + "github.com/dgrijalva/jwt-go", + "github.com/go-sql-driver/mysql", + "github.com/gorilla/mux", + "github.com/gorilla/websocket", + "github.com/lestrrat/go-server-starter-listener", + "go.uber.org/zap", + "golang.org/x/net/websocket", + ] solver-name = "gps-cdcl" solver-version = 1 diff --git a/wsgate-server.go b/wsgate-server.go index 9e6bbc6..deb3e73 100644 --- a/wsgate-server.go +++ b/wsgate-server.go @@ -7,7 +7,6 @@ import ( "fmt" "io" "io/ioutil" - "log" "net" "net/http" "os" @@ -20,6 +19,7 @@ import ( "github.com/gorilla/mux" "github.com/gorilla/websocket" ss "github.com/lestrrat/go-server-starter-listener" + "go.uber.org/zap" ) var ( @@ -42,7 +42,7 @@ func handleHello(w http.ResponseWriter, r *http.Request) { w.Write([]byte("OK\n")) } -func handleProxy(w http.ResponseWriter, r *http.Request) { +func handleProxy(w http.ResponseWriter, r *http.Request, logger *zap.Logger) { vars := mux.Vars(r) proxyDest := vars["dest"] upstream := "" @@ -51,6 +51,13 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { hasError := false disconnectAt := "" + logger = logger.With( + zap.String("user-email", r.Header.Get("X-Goog-Authenticated-User-Email")), + zap.String("x-forwarded-for", r.Header.Get("X-Forwarded-For")), + zap.String("remote-addr", r.RemoteAddr), + zap.String("destination", proxyDest), + ) + if *publicKeyFile != "" { tokenString := r.Header.Get("Authorization") if tokenString == "" { @@ -79,16 +86,18 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { upstream, ok := mapping[proxyDest] if !ok { hasError = true - log.Printf("No map for '%s' found", proxyDest) + logger.Warn("No map found") http.Error(w, fmt.Sprintf("Not found: %s", proxyDest), 404) return } + logger = logger.With(zap.String("upstream", upstream)) + s, err := net.DialTimeout("tcp", upstream, *dialTimeout) if err != nil { hasError = true - log.Printf("DialTimeout: %v", err) + logger.Warn("DialTimeout", zap.Error(err)) http.Error(w, fmt.Sprintf("Could not connect upstream: %v", err), 500) return } @@ -97,21 +106,23 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { if err != nil { hasError = true s.Close() - log.Printf("Failed to Upgrade: %v", err) + logger.Warn("Failed to Upgrade", zap.Error(err)) return } - log.Printf("status:Connected dest:%s upstream:%s x-forwarded-for:%s remote_addr:%s", - proxyDest, upstream, r.Header.Get("X-Forwarded-For"), - r.RemoteAddr) + + logger.Info("log", zap.String("status", "Connected")) defer func() { status := "Suceeded" if hasError { status = "Failed" } - log.Printf("status:%s dest:%s upstream:%s x-forwarded-for:%s remote_addr:%s read:%d write:%d disconnect_at:%s", - status, proxyDest, upstream, r.Header.Get("X-Forwarded-For"), - r.RemoteAddr, readLen, writeLen, disconnectAt) + logger.Info("log", + zap.String("status", status), + zap.Int64("read", readLen), + zap.Int64("write", writeLen), + zap.String("disconnect_at", disconnectAt), + ) }() doneCh := make(chan bool) @@ -130,7 +141,7 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { } if err != nil { if !goClose { - log.Printf("NextReader: %v", err) + logger.Warn("NextReader", zap.Error(err)) hasError = true } if disconnectAt == "" { @@ -139,14 +150,14 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { return } if mt != websocket.BinaryMessage { - log.Printf("BinaryMessage required: %d", mt) + logger.Warn("BinaryMessage required", zap.Int("messageType", mt)) hasError = true return } n, err := io.Copy(s, r) if err != nil { if !goClose { - log.Printf("Reading from websocket: %v", err) + logger.Warn("Reading from websocket", zap.Error(err)) hasError = true } if disconnectAt == "" { @@ -166,7 +177,7 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { n, err := s.Read(b) if err != nil { if !goClose && err != io.EOF { - log.Printf("Reading from dest: %v", err) + logger.Warn("Reading from dest", zap.Error(err)) hasError = true } if disconnectAt == "" { @@ -179,7 +190,7 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { if err := conn.WriteMessage(websocket.BinaryMessage, b); err != nil { if !goClose { - log.Printf("WriteMessage: %v", err) + logger.Warn("WriteMessage", zap.Error(err)) hasError = true } if disconnectAt == "" { @@ -199,26 +210,30 @@ func handleProxy(w http.ResponseWriter, r *http.Request) { } +func printVersion() { + fmt.Printf(`wsgate-server %s +Compiler: %s %s +`, + Version, + runtime.Compiler, + runtime.Version()) +} func main() { flag.Parse() if *showVersion { - fmt.Printf(`wsgate-server %s -Compiler: %s %s -`, - Version, - runtime.Compiler, - runtime.Version()) + printVersion() return - } + logger, _ := zap.NewProduction() + r := regexp.MustCompile(`^ *#`) mapping = make(map[string]string) if *mapFile != "" { f, err := os.Open(*mapFile) if err != nil { - log.Fatal(err) + logger.Fatal("Failed to open mapFile", zap.Error(err)) } s := bufio.NewScanner(f) for s.Scan() { @@ -227,9 +242,13 @@ Compiler: %s %s } l := strings.SplitN(s.Text(), ",", 2) if len(l) != 2 { - log.Fatalf("Invalid line in %s: %s", *mapFile, s.Text()) + logger.Fatal("Invalid line", + zap.String("mapFile", *mapFile), + zap.String("line", s.Text())) } - log.Printf("Create map: %s => %s", l[0], l[1]) + logger.Info("Created map", + zap.String("from", l[0]), + zap.String("to", l[1])) mapping[l[0]] = l[1] } } @@ -237,11 +256,11 @@ Compiler: %s %s if *publicKeyFile != "" { verifyBytes, err := ioutil.ReadFile(*publicKeyFile) if err != nil { - log.Fatalf("Failed read pubkey: %v", err) + logger.Fatal("Failed read pubkey", zap.Error(err)) } verifyKey, err = jwt.ParseRSAPublicKeyFromPEM(verifyBytes) if err != nil { - log.Fatalf("Failed read pubkey: %v", err) + logger.Fatal("Failed read pubkey", zap.Error(err)) } } @@ -257,14 +276,16 @@ Compiler: %s %s m := mux.NewRouter() m.HandleFunc("/", handleHello) m.HandleFunc("/live", handleHello) - m.HandleFunc("/proxy/{dest}", handleProxy) + m.HandleFunc("/proxy/{dest}", func(w http.ResponseWriter, r *http.Request) { + handleProxy(w, r, logger) + }) l, err := ss.NewListener() if l == nil || err != nil { // Fallback if not running under Server::Starter l, err = net.Listen("tcp", *listen) if err != nil { - panic(fmt.Sprintf("Failed to listen to port %s", *listen)) + logger.Fatal("Failed to listen to port", zap.String("listen", *listen)) } } @@ -274,5 +295,5 @@ Compiler: %s %s WriteTimeout: 10 * time.Second, MaxHeaderBytes: 1 << 20, } - log.Fatal(s.Serve(l)) + s.Serve(l) }