log in apps and further polishment

skycoin · Aug 26, 2019 · 085b9de · 085b9de
1 parent a2d2b7b
commit 085b9de
Show file tree

Hide file tree

Showing 16 changed files with 103 additions and 72 deletions.
diff --git a/cmd/apps/therealproxy-client/therealproxy-client.go b/cmd/apps/therealproxy-client/therealproxy-client.go
@@ -5,7 +5,6 @@ package main
 
 import (
 	"flag"
-	"log"
 	"net"
 	"time"
 
@@ -22,6 +21,9 @@ const socksPort = 3
 var r = netutil.NewRetrier(time.Second, 0, 1)
 
 func main() {
+	log := app.NewLogger("socksproxy-client")
+	therealproxy.Log = log.PackageLogger("therealproxy")
+
 	var addr = flag.String("addr", ":1080", "Client address to listen on")
 	var serverPK = flag.String("srv", "", "PubKey of the server to connect to")
 	flag.Parse()

diff --git a/cmd/apps/therealproxy/therealproxy.go b/cmd/apps/therealproxy/therealproxy.go
@@ -5,13 +5,15 @@ package main
 
 import (
 	"flag"
-	"log"
 
 	"github.com/skycoin/skywire/internal/therealproxy"
 	"github.com/skycoin/skywire/pkg/app"
 )
 
 func main() {
+	log := app.NewLogger("socksproxy")
+	therealproxy.Log = log.PackageLogger("therealproxy")
+
 	var passcode = flag.String("passcode", "", "Authorize user against this passcode")
 	flag.Parse()
 
@@ -26,7 +28,7 @@ func main() {
 		}
 	}()
 
-	srv, err := therealproxy.NewServer(*passcode)
+	srv, err := therealproxy.NewServer(*passcode, log)
 	if err != nil {
 		log.Fatal("Failed to create a new server: ", err)
 	}

diff --git a/cmd/apps/therealssh-client/therealssh-client.go b/cmd/apps/therealssh-client/therealssh-client.go
@@ -5,7 +5,6 @@ package main
 
 import (
 	"flag"
-	"log"
 	"net/http"
 
 	"github.com/sirupsen/logrus"
@@ -15,7 +14,12 @@ import (
 	ssh "github.com/skycoin/skywire/pkg/therealssh"
 )
 
+var log *logging.MasterLogger
+
 func main() {
+	log = app.NewLogger("SSH-client")
+	ssh.Log = log.PackageLogger("therealssh")
+
 	var rpcAddr = flag.String("rpc", ":2222", "Client RPC address to listen on")
 	var debug = flag.Bool("debug", false, "enable debug messages")
 	flag.Parse()

diff --git a/cmd/apps/therealssh/therealssh.go b/cmd/apps/therealssh/therealssh.go
@@ -5,7 +5,6 @@ package main
 
 import (
 	"flag"
-	"log"
 
 	"github.com/mitchellh/go-homedir"
 	"github.com/sirupsen/logrus"
@@ -15,7 +14,12 @@ import (
 	ssh "github.com/skycoin/skywire/pkg/therealssh"
 )
 
+var log *logging.MasterLogger
+
 func main() {
+	log = app.NewLogger("SSH")
+	ssh.Log = log.PackageLogger("therealssh")
+
 	var authFile = flag.String("auth", "~/.therealssh/authorized_keys", "Auth file location. Should contain one PubKey per line.")
 	var debug = flag.Bool("debug", false, "enable debug messages")
 
@@ -47,7 +51,7 @@ func main() {
 		log.Fatal("Failed to setup Authorizer: ", err)
 	}
 
-	server := ssh.NewServer(auth)
+	server := ssh.NewServer(auth, log)
 	defer func() {
 		if err := server.Close(); err != nil {
 			log.Println("Failed to close server:", err)

diff --git a/internal/therealproxy/client.go b/internal/therealproxy/client.go
@@ -9,7 +9,8 @@ import (
 	"github.com/skycoin/skycoin/src/util/logging"
 )
 
-var log = logging.MustGetLogger("therealproxy")
+// Log is therealproxy package level logger, it can be replaced with a different one from outside the package
+var Log = logging.MustGetLogger("therealproxy")
 
 // Client implement multiplexing proxy client using yamux.
 type Client struct {
@@ -64,14 +65,14 @@ func (c *Client) ListenAndServe(addr string) error {
 
 			for err := range errCh {
 				if err := conn.Close(); err != nil {
-					log.WithError(err).Warn("Failed to close connection")
+					Log.WithError(err).Warn("Failed to close connection")
 				}
 				if err := stream.Close(); err != nil {
-					log.WithError(err).Warn("Failed to close stream")
+					Log.WithError(err).Warn("Failed to close stream")
 				}
 
 				if err != nil {
-					log.Error("Copy error:", err)
+					Log.Error("Copy error:", err)
 				}
 			}
 		}()

diff --git a/internal/therealproxy/server.go b/internal/therealproxy/server.go
@@ -6,16 +6,18 @@ import (
 
 	"github.com/armon/go-socks5"
 	"github.com/hashicorp/yamux"
+	"github.com/skycoin/skycoin/src/util/logging"
 )
 
 // Server implements multiplexing proxy server using yamux.
 type Server struct {
 	socks    *socks5.Server
 	listener net.Listener
+	log      *logging.MasterLogger
 }
 
 // NewServer constructs a new Server.
-func NewServer(passcode string) (*Server, error) {
+func NewServer(passcode string, l *logging.MasterLogger) (*Server, error) {
 	var credentials socks5.CredentialStore
 	if passcode != "" {
 		credentials = passcodeCredentials(passcode)
@@ -26,7 +28,7 @@ func NewServer(passcode string) (*Server, error) {
 		return nil, fmt.Errorf("socks5: %s", err)
 	}
 
-	return &Server{socks: s}, nil
+	return &Server{socks: s, log: l}, nil
 }
 
 // Serve accept connections from listener and serves socks5 proxy for
@@ -46,7 +48,7 @@ func (s *Server) Serve(l net.Listener) error {
 
 		go func() {
 			if err := s.socks.Serve(session); err != nil {
-				log.Error("Failed to start SOCKS5 server:", err)
+				s.log.Error("Failed to start SOCKS5 server:", err)
 			}
 		}()
 	}

diff --git a/internal/therealproxy/server_test.go b/internal/therealproxy/server_test.go
@@ -22,7 +22,7 @@ func TestMain(m *testing.M) {
 	if ok {
 		lvl, err := logging.LevelFromString(loggingLevel)
 		if err != nil {
-			log.Fatal(err)
+			Log.Fatal(err)
 		}
 		logging.SetLevel(lvl)
 	} else {

diff --git a/pkg/hypervisor/hypervisor.go b/pkg/hypervisor/hypervisor.go
@@ -27,7 +27,8 @@ import (
 )
 
 var (
-	log = logging.MustGetLogger("hypervisor")
+	log           = logging.MustGetLogger("hypervisor")
+	healthTimeout = 5 * time.Second
 )
 
 type appNodeConn struct {
@@ -155,31 +156,45 @@ func (m *Node) ServeHTTP(w http.ResponseWriter, req *http.Request) {
 	r.ServeHTTP(w, req)
 }
 
-// VisorHealth represents a node's health report attached to it's pk for identification
+// VisorHealth represents a node's health report attached to hypervisor to visor request status
 type VisorHealth struct {
 	Status int `json:"status"`
 	*visor.HealthInfo
 }
 
 // provides summary of health information for every visor
 func (m *Node) getHealth() http.HandlerFunc {
-	healthStatuses := make([]*VisorHealth, 0, len(m.nodes))
-
 	return m.withCtx(m.nodeCtx, func(w http.ResponseWriter, r *http.Request, ctx *httpCtx) {
 		vh := &VisorHealth{}
 
-		hi, err := ctx.RPC.Health()
-		if err != nil {
-			vh.Status = http.StatusInternalServerError
-		} else {
-			vh.HealthInfo = hi
-			vh.Status = http.StatusOK
-			healthStatuses = append(healthStatuses, vh)
+		type healthRes struct {
+			h   *visor.HealthInfo
+			err error
+		}
+
+		resCh := make(chan healthRes)
+		tCh := time.After(healthTimeout)
+		go func() {
+			hi, err := ctx.RPC.Health()
+			resCh <- healthRes{hi, err}
+		}()
+		select {
+		case res := <-resCh:
+			if res.err != nil {
+				vh.Status = http.StatusInternalServerError
+			} else {
+				vh.HealthInfo = res.h
+				vh.Status = http.StatusOK
+			}
+			httputil.WriteJSON(w, r, http.StatusOK, vh)
+			return
+		case <-tCh:
+			httputil.WriteJSON(w, r, http.StatusRequestTimeout, &VisorHealth{Status: http.StatusRequestTimeout})
 		}
-		httputil.WriteJSON(w, r, http.StatusOK, healthStatuses)
 	})
 }
 
+// getUptime gets given node's uptime
 func (m *Node) getUptime() http.HandlerFunc {
 	return m.withCtx(m.nodeCtx, func(w http.ResponseWriter, r *http.Request, ctx *httpCtx) {
 		u, err := ctx.RPC.Uptime()

diff --git a/pkg/therealssh/auth.go b/pkg/therealssh/auth.go
@@ -72,7 +72,7 @@ func (auth *FileAuthorizer) Close() error {
 func (auth *FileAuthorizer) Authorize(remotePK cipher.PubKey) error {
 	defer func() {
 		if _, err := auth.authFile.Seek(0, 0); err != nil {
-			log.WithError(err).Warn("Failed to seek to the beginning of auth file")
+			Log.WithError(err).Warn("Failed to seek to the beginning of auth file")
 		}
 	}()
 

diff --git a/pkg/therealssh/channel.go b/pkg/therealssh/channel.go
@@ -79,7 +79,7 @@ func (sshCh *SSHChannel) Write(p []byte) (n int, err error) {
 
 // Request sends request message and waits for response.
 func (sshCh *SSHChannel) Request(requestType RequestType, payload []byte) ([]byte, error) {
-	log.Debugf("sending request %x", requestType)
+	Log.Debugf("sending request %x", requestType)
 	req := append([]byte{byte(requestType)}, payload...)
 
 	if err := sshCh.Send(CmdChannelRequest, req); err != nil {
@@ -98,7 +98,7 @@ func (sshCh *SSHChannel) Request(requestType RequestType, payload []byte) ([]byt
 func (sshCh *SSHChannel) Serve() error {
 	for data := range sshCh.msgCh {
 		var err error
-		log.Debugf("new request %x", data[0])
+		Log.Debugf("new request %x", data[0])
 		switch RequestType(data[0]) {
 		case RequestPTY:
 			var u *user.User
@@ -151,10 +151,10 @@ func (sshCh *SSHChannel) SocketPath() string {
 // ServeSocket starts socket handling loop.
 func (sshCh *SSHChannel) ServeSocket() error {
 	if err := os.Remove(sshCh.SocketPath()); err != nil {
-		log.WithError(err).Warn("Failed to remove SSH channel socket file")
+		Log.WithError(err).Warn("Failed to remove SSH channel socket file")
 	}
 
-	log.Debugf("waiting for new socket connections on: %s", sshCh.SocketPath())
+	Log.Debugf("waiting for new socket connections on: %s", sshCh.SocketPath())
 	l, err := net.ListenUnix("unix", &net.UnixAddr{Name: sshCh.SocketPath(), Net: "unix"})
 	if err != nil {
 		return fmt.Errorf("failed to open unix socket: %s", err)
@@ -168,22 +168,22 @@ func (sshCh *SSHChannel) ServeSocket() error {
 		return fmt.Errorf("failed to accept connection: %s", err)
 	}
 
-	log.Debugln("got new socket connection")
+	Log.Debugln("got new socket connection")
 	defer func() {
 		if err := conn.Close(); err != nil {
-			log.WithError(err).Warn("Failed to close connection")
+			Log.WithError(err).Warn("Failed to close connection")
 		}
 		if err := sshCh.closeListener(); err != nil {
-			log.WithError(err).Warn("Failed to close listener")
+			Log.WithError(err).Warn("Failed to close listener")
 		}
 		if err := os.Remove(sshCh.SocketPath()); err != nil {
-			log.WithError(err).Warn("Failed to close SSH channel socket file")
+			Log.WithError(err).Warn("Failed to close SSH channel socket file")
 		}
 	}()
 
 	go func() {
 		if _, err := io.Copy(sshCh, conn); err != nil && !strings.Contains(err.Error(), "use of closed network connection") {
-			log.Errorf("failed to write to server:", err)
+			Log.Errorf("failed to write to server:", err)
 			return
 		}
 	}()
@@ -201,7 +201,7 @@ func (sshCh *SSHChannel) OpenPTY(user *user.User, sz *pty.Winsize) (err error) {
 		return errors.New("session is already started")
 	}
 
-	log.Debugf("starting new session for %s with %#v", user.Username, sz)
+	Log.Debugf("starting new session for %s with %#v", user.Username, sz)
 	sshCh.session, err = OpenSession(user, sz)
 	if err != nil {
 		sshCh.session = nil
@@ -224,11 +224,11 @@ func (sshCh *SSHChannel) Start(command string) error {
 
 	go func() {
 		if err := sshCh.serveSession(); err != nil {
-			log.Error("Session failure:", err)
+			Log.Error("Session failure:", err)
 		}
 	}()
 
-	log.Debugf("starting new pty process %s", command)
+	Log.Debugf("starting new pty process %s", command)
 	return sshCh.session.Start(command)
 }
 
@@ -246,7 +246,7 @@ func (sshCh *SSHChannel) Run(command string) error {
 	go func() {
 		_, err := sshCh.Write(out)
 		if err != nil {
-			log.Warn("error writing to channel: ", err)
+			Log.Warn("error writing to channel: ", err)
 		}
 	}()
 	return err
@@ -255,16 +255,16 @@ func (sshCh *SSHChannel) Run(command string) error {
 func (sshCh *SSHChannel) serveSession() error {
 	defer func() {
 		if err := sshCh.Send(CmdChannelServerClose, nil); err != nil {
-			log.WithError(err).Warn("Failed to send to SSH channel")
+			Log.WithError(err).Warn("Failed to send to SSH channel")
 		}
 		if err := sshCh.Close(); err != nil {
-			log.WithError(err).Warn("Failed to close SSH channel")
+			Log.WithError(err).Warn("Failed to close SSH channel")
 		}
 	}()
 
 	go func() {
 		if _, err := io.Copy(sshCh.session, sshCh); err != nil {
-			log.Error("PTY copy: ", err)
+			Log.Error("PTY copy: ", err)
 			return
 		}
 	}()