AUTH-1942 added event log to ssh server

sshserver/sshserver_unix.go

@@ -3,6 +3,7 @@
 package sshserver
 
 import (
+	"encoding/json"
 	"errors"
 	"fmt"
 	"io"
@@ -11,6 +12,7 @@ import (
 	"os/user"
 	"runtime"
 	"strconv"
+	"strings"
 	"syscall"
 	"time"
 	"unsafe"
@@ -23,6 +25,27 @@ import (
 	"github.com/sirupsen/logrus"
 )
 
+const (
+	auditEventAuth   = "auth"
+	auditEventStart  = "session_start"
+	auditEventStop   = "session_stop"
+	auditEventExec   = "exec"
+	auditEventScp    = "scp"
+	auditEventResize = "resize"
+	auditEventTamper = "tamper"
+)
+
+type auditEvent struct {
+	Event     string `json:"event,omitempty"`
+	EventType string `json:"event_type,omitempty"`
+	SessionID string `json:"session_id,omitempty"`
+	User      string `json:"user,omitempty"`
+	Login     string `json:"login,omitempty"`
+	Datetime  string `json:"datetime,omitempty"`
+	IPAddress string `json:"ip_address,omitempty"`
+}
+
+// SSHServer adds on to the ssh.Server of the gliderlabs package
 type SSHServer struct {
 	ssh.Server
 	logger     *logrus.Logger
@@ -31,6 +54,7 @@ type SSHServer struct {
 	logManager sshlog.Manager
 }
 
+// New creates a new SSHServer and configures its host keys and authenication by the data provided
 func New(logManager sshlog.Manager, logger *logrus.Logger, version, address string, shutdownC chan struct{}, idleTimeout, maxTimeout time.Duration) (*SSHServer, error) {
 	currentUser, err := user.Current()
 	if err != nil {
@@ -60,6 +84,7 @@ func New(logManager sshlog.Manager, logger *logrus.Logger, version, address stri
 	return &sshServer, nil
 }
 
+// Start the SSH server listener to start handling SSH connections from clients
 func (s *SSHServer) Start() error {
 	s.logger.Infof("Starting SSH server at %s", s.Addr)
 
@@ -75,61 +100,52 @@ func (s *SSHServer) Start() error {
 }
 
 func (s *SSHServer) connectionHandler(session ssh.Session) {
-	sessionID, err := uuid.NewRandom()
+	sessionUUID, err := uuid.NewRandom()
+
 	if err != nil {
 		if _, err := io.WriteString(session, "Failed to generate session ID\n"); err != nil {
 			s.logger.WithError(err).Error("Failed to generate session ID: Failed to write to SSH session")
 		}
-		s.CloseSession(session)
+		s.errorAndExit(session, "", nil)
+		return
+	}
+	sessionID := sessionUUID.String()
+
+	eventLogger, err := s.logManager.NewLogger(fmt.Sprintf("%s-event.log", sessionID), s.logger)
+	if err != nil {
+		if _, err := io.WriteString(session, "Failed to create event log\n"); err != nil {
+			s.logger.WithError(err).Error("Failed to create event log: Failed to write to create event logger")
+		}
+		s.errorAndExit(session, "", nil)
+		return
 	}
 
 	// Get uid and gid of user attempting to login
-	sshUser, ok := session.Context().Value("sshUser").(*User)
+	sshUser, uidInt, gidInt, success := s.getSSHUser(session, sessionID, eventLogger)
-	if !ok || sshUser == nil {
+	if !success {
-		s.logger.Error("Error retrieving credentials from session")
-		s.CloseSession(session)
-		return
-	}
-
-	uidInt, err := stringToUint32(sshUser.Uid)
-	if err != nil {
-		s.logger.WithError(err).Error("Invalid user")
-		s.CloseSession(session)
-		return
-	}
-	gidInt, err := stringToUint32(sshUser.Gid)
-	if err != nil {
-		s.logger.WithError(err).Error("Invalid user group")
-		s.CloseSession(session)
 		return
 	}
 
 	// Spawn shell under user
-	var cmd *exec.Cmd
+	cmd := s.spawnCmd(session, sshUser, uidInt, gidInt)
-	if session.RawCommand() != "" {
-		cmd = exec.Command(sshUser.Shell, "-c", session.RawCommand())
-	} else {
-		cmd = exec.Command(sshUser.Shell)
-	}
-	// Supplementary groups are not explicitly specified. They seem to be inherited by default.
-	cmd.SysProcAttr = &syscall.SysProcAttr{Credential: &syscall.Credential{Uid: uidInt, Gid: gidInt}, Setsid: true}
-	cmd.Env = append(cmd.Env, session.Environ()...)
-	cmd.Env = append(cmd.Env, fmt.Sprintf("USER=%s", sshUser.Username))
-	cmd.Env = append(cmd.Env, fmt.Sprintf("HOME=%s", sshUser.HomeDir))
-	cmd.Dir = sshUser.HomeDir
 
-	ptyReq, winCh, isPty := session.Pty()
 	var shellInput io.WriteCloser
 	var shellOutput io.ReadCloser
 
+	ptyReq, winCh, isPty := session.Pty()
+
 	if isPty {
 		cmd.Env = append(cmd.Env, fmt.Sprintf("TERM=%s", ptyReq.Term))
-		shellInput, shellOutput, err = s.startPtySession(cmd, winCh)
+		shellInput, shellOutput, err = s.startPtySession(cmd, winCh, func() {
+			s.logAuditEvent(eventLogger, session, sessionID, auditEventResize)
+		})
 		if err != nil {
 			s.logger.WithError(err).Error("Failed to start pty session")
 			close(s.shutdownC)
 			return
 		}
+		s.logAuditEvent(eventLogger, session, sessionID, auditEventStart)
+		defer s.logAuditEvent(eventLogger, session, sessionID, auditEventStop)
 	} else {
 		shellInput, shellOutput, err = s.startNonPtySession(cmd)
 		if err != nil {
@@ -137,6 +153,11 @@ func (s *SSHServer) connectionHandler(session ssh.Session) {
 			close(s.shutdownC)
 			return
 		}
+		event := auditEventExec
+		if strings.HasPrefix(session.RawCommand(), "scp") {
+			event = auditEventScp
+		}
+		s.logAuditEvent(eventLogger, session, sessionID, event)
 	}
 
 	// Write incoming commands to shell
@@ -155,7 +176,8 @@ func (s *SSHServer) connectionHandler(session ssh.Session) {
 		if _, err := io.WriteString(session, "Failed to create log\n"); err != nil {
 			s.logger.WithError(err).Error("Failed to create log: Failed to write to SSH session")
 		}
-		s.CloseSession(session)
+		s.errorAndExit(session, "", nil)
+		return
 	}
 	defer sessionLogger.Close()
 	go func() {
@@ -175,9 +197,54 @@ func (s *SSHServer) connectionHandler(session ssh.Session) {
 	}
 }
 
-func (s *SSHServer) CloseSession(session ssh.Session) {
+// spawnCmd spawns a shell under the user
+func (s *SSHServer) spawnCmd(session ssh.Session, sshUser *User, uidInt, gidInt uint32) *exec.Cmd {
+	var cmd *exec.Cmd
+	if session.RawCommand() != "" {
+		cmd = exec.Command(sshUser.Shell, "-c", session.RawCommand())
+	} else {
+		cmd = exec.Command(sshUser.Shell)
+	}
+	// Supplementary groups are not explicitly specified. They seem to be inherited by default.
+	cmd.SysProcAttr = &syscall.SysProcAttr{Credential: &syscall.Credential{Uid: uidInt, Gid: gidInt}, Setsid: true}
+	cmd.Env = append(cmd.Env, session.Environ()...)
+	cmd.Env = append(cmd.Env, fmt.Sprintf("USER=%s", sshUser.Username))
+	cmd.Env = append(cmd.Env, fmt.Sprintf("HOME=%s", sshUser.HomeDir))
+	cmd.Dir = sshUser.HomeDir
+	return cmd
+}
+
+// getSSHUser gets the ssh user, uid, and gid of the user attempting to login
+func (s *SSHServer) getSSHUser(session ssh.Session, sessionID string, eventLogger io.WriteCloser) (*User, uint32, uint32, bool) {
+	// Get uid and gid of user attempting to login
+	sshUser, ok := session.Context().Value("sshUser").(*User)
+	if !ok || sshUser == nil {
+		s.errorAndExit(session, "Error retrieving credentials from session", nil)
+		return nil, 0, 0, false
+	}
+	s.logAuditEvent(eventLogger, session, sessionID, auditEventAuth)
+
+	uidInt, err := stringToUint32(sshUser.Uid)
+	if err != nil {
+		s.errorAndExit(session, "Invalid user", err)
+		return sshUser, 0, 0, false
+	}
+	gidInt, err := stringToUint32(sshUser.Gid)
+	if err != nil {
+		s.errorAndExit(session, "Invalid user group", err)
+		return sshUser, 0, 0, false
+	}
+	return sshUser, uidInt, gidInt, true
+}
+
+// errorAndExit reports an error with the session and exits
+func (s *SSHServer) errorAndExit(session ssh.Session, errText string, err error) {
 	if err := session.Exit(1); err != nil {
 		s.logger.WithError(err).Error("Failed to close SSH session")
+	} else if err != nil {
+		s.logger.WithError(err).Error(errText)
+	} else if errText != "" {
+		s.logger.Error(errText)
 	}
 }
 
@@ -197,7 +264,7 @@ func (s *SSHServer) startNonPtySession(cmd *exec.Cmd) (io.WriteCloser, io.ReadCl
 	return in, out, nil
 }
 
-func (s *SSHServer) startPtySession(cmd *exec.Cmd, winCh <-chan ssh.Window) (io.WriteCloser, io.ReadCloser, error) {
+func (s *SSHServer) startPtySession(cmd *exec.Cmd, winCh <-chan ssh.Window, logCallback func()) (io.WriteCloser, io.ReadCloser, error) {
 	tty, err := pty.Start(cmd)
 	if err != nil {
 		return nil, nil, err
@@ -211,6 +278,7 @@ func (s *SSHServer) startPtySession(cmd *exec.Cmd, winCh <-chan ssh.Window) (io.
 				close(s.shutdownC)
 				return
 			}
+			logCallback()
 		}
 	}()
 
@@ -229,3 +297,28 @@ func stringToUint32(str string) (uint32, error) {
 	return uint32(uid), err
 
 }
+
+func (s *SSHServer) logAuditEvent(writer io.WriteCloser, session ssh.Session, sessionID string, eventType string) {
+	username := "unknown"
+	sshUser, ok := session.Context().Value("sshUser").(*User)
+	if ok && sshUser != nil {
+		username = sshUser.Username
+	}
+
+	event := auditEvent{
+		Event:     session.RawCommand(),
+		EventType: eventType,
+		SessionID: sessionID,
+		User:      username,
+		Login:     username,
+		Datetime:  time.Now().UTC().Format(time.RFC3339),
+		IPAddress: session.RemoteAddr().String(),
+	}
+	data, err := json.Marshal(&event)
+	if err != nil {
+		s.logger.WithError(err).Error("Failed to log audit event. malformed audit object")
+		return
+	}
+	line := string(data) + "\n"
+	writer.Write([]byte(line))
+}