Skip to content

Commit

Permalink
Merge pull request #483 from Darkren/feature/improve_therealssh_logging
Browse files Browse the repository at this point in the history 
Improve SSH logging
  • Loading branch information
@jdknives
jdknives authored Aug 5, 2019
2 parents 518e04e + 49b5622 commit f516674
Show file tree
Hide file tree
Showing 5 changed files with 33 additions and 28 deletions.
6 changes: 6 additions & 0 deletions cmd/apps/therealssh-client/therealssh-client.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,9 @@ import (
"log"
"net/http"

"github.com/sirupsen/logrus"
"github.com/skycoin/skycoin/src/util/logging"

ssh "github.com/skycoin/skywire/internal/therealssh"
"github.com/skycoin/skywire/pkg/app"
)
Expand All @@ -29,6 +32,9 @@ func main() {
}()

ssh.Debug = *debug
if !ssh.Debug {
logging.SetLevel(logrus.InfoLevel)
}

rpc, client, err := ssh.NewClient(*rpcAddr, sshApp)
if err != nil {
Expand Down
5 changes: 5 additions & 0 deletions cmd/apps/therealssh/therealssh.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@ import (
"log"

"github.com/mitchellh/go-homedir"
"github.com/sirupsen/logrus"
"github.com/skycoin/skycoin/src/util/logging"

ssh "github.com/skycoin/skywire/internal/therealssh"
"github.com/skycoin/skywire/pkg/app"
Expand Down Expand Up @@ -36,6 +38,9 @@ func main() {
}

ssh.Debug = *debug
if !ssh.Debug {
logging.SetLevel(logrus.InfoLevel)
}

auth, err := ssh.NewFileAuthorizer(path)
if err != nil {
Expand Down
22 changes: 7 additions & 15 deletions internal/therealssh/channel.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
debug("sending request %x", requestType)
log.Debugf("sending request %x", requestType)
req := append([]byte{byte(requestType)}, payload...)

if err := sshCh.Send(CmdChannelRequest, req); err != nil {
Expand All @@ -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
debug("new request %x", data[0])
log.Debugf("new request %x", data[0])
switch RequestType(data[0]) {
case RequestPTY:
var u *user.User
Expand Down Expand Up @@ -152,7 +152,7 @@ func (sshCh *SSHChannel) ServeSocket() error {
log.WithError(err).Warn("Failed to remove SSH channel socket file")
}

debug("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)
Expand All @@ -166,7 +166,7 @@ func (sshCh *SSHChannel) ServeSocket() error {
return fmt.Errorf("failed to accept connection: %s", err)
}

debug("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")
Expand All @@ -181,7 +181,7 @@ func (sshCh *SSHChannel) ServeSocket() error {

go func() {
if _, err := io.Copy(sshCh, conn); err != nil && !strings.Contains(err.Error(), "use of closed network connection") {
log.Println("failed to write to server:", err)
log.Errorf("failed to write to server:", err)
return
}
}()
Expand All @@ -199,7 +199,7 @@ func (sshCh *SSHChannel) OpenPTY(user *user.User, sz *pty.Winsize) (err error) {
return errors.New("session is already started")
}

debug("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
Expand All @@ -226,7 +226,7 @@ func (sshCh *SSHChannel) Start(command string) error {
}
}()

debug("starting new pty process %s", command)
log.Debugf("starting new pty process %s", command)
return sshCh.session.Start(command)
}

Expand Down Expand Up @@ -333,14 +333,6 @@ func (sshCh *SSHChannel) closeListener() error {
return sshCh.listener.Close()
}

func debug(format string, v ...interface{}) {
if !Debug {
return
}

log.Printf(format, v...)
}

func appendU32(buf []byte, n uint32) []byte {
uintBuf := make([]byte, 4)
binary.BigEndian.PutUint32(uintBuf[0:], n)
Expand Down
16 changes: 8 additions & 8 deletions internal/therealssh/client.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -57,7 +57,7 @@ func (c *Client) OpenChannel(remotePK cipher.PubKey) (localID uint32, sshCh *SSH
}

sshCh = OpenClientChannel(0, remotePK, conn)
debug("sending channel open command")
log.Debugln("sending channel open command")
localID = c.chans.add(sshCh)
req := appendU32([]byte{byte(CmdChannelOpen)}, localID)
if _, err := conn.Write(req); err != nil {
Expand All @@ -71,9 +71,9 @@ func (c *Client) OpenChannel(remotePK cipher.PubKey) (localID uint32, sshCh *SSH
}
}()

debug("waiting for channel open response")
log.Debugln("waiting for channel open response")
data := <-sshCh.msgCh
debug("got channel open response")
log.Debugln("got channel open response")
if data[0] == ResponseFail {
cErr = fmt.Errorf("failed to open channel: %s", string(data[1:]))
return
Expand Down Expand Up @@ -121,7 +121,7 @@ func (c *Client) serveConn(conn net.Conn) error {
}

data := payload[5:]
debug("got new command: %x", payload[0])
log.Debugf("got new command: %x", payload[0])
switch CommandType(payload[0]) {
case CmdChannelOpenResponse, CmdChannelResponse:
sshCh.msgCh <- data
Expand Down Expand Up @@ -165,13 +165,13 @@ type RPCClient struct {

// RequestPTY defines RPC request for a new PTY session.
func (rpc *RPCClient) RequestPTY(args *RequestPTYArgs, channelID *uint32) error {
debug("requesting SSH channel")
log.Debugln("requesting SSH channel")
localID, channel, err := rpc.c.OpenChannel(args.RemotePK)
if err != nil {
return err
}

debug("requesting PTY session")
log.Debugln("requesting PTY session")
if _, err := channel.Request(RequestPTY, args.ToBinary()); err != nil {
return fmt.Errorf("PTY request failure: %s", err)
}
Expand All @@ -187,7 +187,7 @@ func (rpc *RPCClient) Exec(args *ExecArgs, socketPath *string) error {
return errors.New("unknown channel")
}

debug("requesting shell process")
log.Debugln("requesting shell process")
if args.CommandWithArgs == nil {
if _, err := sshCh.Request(RequestShell, nil); err != nil {
return fmt.Errorf("shell request failure: %s", err)
Expand All @@ -200,7 +200,7 @@ func (rpc *RPCClient) Exec(args *ExecArgs, socketPath *string) error {

waitCh := make(chan bool)
go func() {
debug("starting socket listener")
log.Debugln("starting socket listener")
waitCh <- true
if err := sshCh.ServeSocket(); err != nil {
log.Error("Session failure:", err)
Expand Down
12 changes: 7 additions & 5 deletions internal/therealssh/server.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import (
"net"

"github.com/skycoin/dmsg/cipher"
"github.com/skycoin/skycoin/src/util/logging"

"github.com/skycoin/skywire/pkg/routing"
)
Expand Down Expand Up @@ -55,18 +56,19 @@ var responseUnauthorized = append([]byte{ResponseFail}, []byte("unauthorized")..

// Server handles remote PTY data exchange.
type Server struct {
log *logging.Logger
auth Authorizer
chans *chanList
}

// NewServer constructs new Server.
func NewServer(auth Authorizer) *Server {
return &Server{auth, newChanList()}
return &Server{logging.MustGetLogger("therealssh_server"), auth, newChanList()}
}

// OpenChannel opens new client channel.
func (s *Server) OpenChannel(remoteAddr routing.Addr, remoteID uint32, conn net.Conn) error {
debug("opening new channel")
log.Debugln("opening new channel")
channel := OpenChannel(remoteID, remoteAddr, conn)
var res []byte

Expand All @@ -76,7 +78,7 @@ func (s *Server) OpenChannel(remoteAddr routing.Addr, remoteID uint32, conn net.
res = appendU32([]byte{ResponseConfirm}, s.chans.add(channel))
}

debug("sending response")
s.log.Debugln("sending response")
if err := channel.Send(CmdChannelOpenResponse, res); err != nil {
if err := channel.Close(); err != nil {
log.WithError(err).Warn("Failed to close channel")
Expand All @@ -85,7 +87,7 @@ func (s *Server) OpenChannel(remoteAddr routing.Addr, remoteID uint32, conn net.
}

go func() {
debug("listening for channel requests")
s.log.Debugln("listening for channel requests")
if err := channel.Serve(); err != nil {
log.Error("channel failure:", err)
}
Expand Down Expand Up @@ -158,7 +160,7 @@ func (s *Server) Serve(conn net.Conn) error {
payloadID := binary.BigEndian.Uint32(payload[1:])
data := payload[5:]

debug("got new command: %x", payload[0])
s.log.Debugf("got new command: %x", payload[0])
switch CommandType(payload[0]) {
case CmdChannelOpen:
err = s.OpenChannel(raddr, payloadID, conn)
Expand Down

0 comments on commit f516674

Please sign in to comment.