Added session termination event #39 (#44)

The session termination event records whether it seems like a human was
attached as well as overall session length and characters sent.

In order to capture these same logs in the playground, it has been
updated to use the same execution path as the SSH server.

Fixes #39

cmd/builtins.go

@@ -5,8 +5,8 @@ import (
 	"sort"
 	"strings"
 
-	"github.com/spf13/cobra"
 	"github.com/josephlewis42/honeyssh/commands"
+	"github.com/spf13/cobra"
 )
 
 // serveCmd represents the serve command

cmd/init.go

@@ -3,8 +3,8 @@ package cmd
 import (
 	"log"
 
-	"github.com/spf13/cobra"
 	"github.com/josephlewis42/honeyssh/core/config"
+	"github.com/spf13/cobra"
 )
 
 // initCmd intializes the honeypot configuration

cmd/playground.go

@@ -1,28 +1,37 @@
 package cmd
 
 import (
-	"fmt"
+	"context"
 	"io"
-	"io/ioutil"
 	"log"
 	"net"
 	"os"
 	"path/filepath"
 	"strings"
-	"time"
 
-	"github.com/josephlewis42/honeyssh/commands"
+	"github.com/anmitsu/go-shlex"
+	"github.com/gliderlabs/ssh"
+	"github.com/josephlewis42/honeyssh/core"
 	"github.com/josephlewis42/honeyssh/core/config"
-	"github.com/josephlewis42/honeyssh/core/logger"
 	"github.com/josephlewis42/honeyssh/core/vos"
 	"github.com/spf13/cobra"
 )
 
 type playgroundSession struct {
-	user string
-	out  io.Writer
+	user       string
+	out        io.Writer
+	in         io.Reader
+	rawCommand string
+	subsystem  string
+	environ    []string
+	pty        ssh.Pty
+
+	exitCalled bool
+	exitCode   int
 }
 
+var _ core.SessionInfo = (*playgroundSession)(nil)
+
 func (p *playgroundSession) User() string {
 	return p.user
 }
@@ -32,14 +41,50 @@ func (p *playgroundSession) RemoteAddr() net.Addr {
 }
 
 func (p *playgroundSession) Exit(code int) error {
-	os.Exit(code)
+	p.exitCalled = true
+	p.exitCode = code
 	return nil
 }
 
 func (p *playgroundSession) Write(b []byte) (int, error) {
 	return p.out.Write(b)
 }
 
+func (p *playgroundSession) Command() []string {
+	// Ignore the error, it doesn't matter for the playground.
+	cmd, _ := shlex.Split(p.rawCommand, true)
+	return cmd
+}
+
+func (p *playgroundSession) RawCommand() string {
+	return p.rawCommand
+}
+func (p *playgroundSession) Subsystem() string {
+	return p.subsystem
+}
+
+func (p *playgroundSession) Context() context.Context {
+	return context.Background()
+}
+
+func (p *playgroundSession) Environ() []string {
+	return p.environ
+}
+
+func (p *playgroundSession) Pty() (ssh.Pty, <-chan ssh.Window, bool) {
+	output := make(<-chan ssh.Window)
+	return p.pty, output, true
+}
+
+func (p *playgroundSession) Read(b []byte) (int, error) {
+	return p.in.Read(b)
+}
+
+func (p *playgroundSession) Close() error {
+	// Close does nothing in playground
+	return nil
+}
+
 type SSHSession interface {
 	User() string
 	RemoteAddr() net.Addr
@@ -72,7 +117,7 @@ var playgroundCmd = &cobra.Command{
 	RunE: func(cmd *cobra.Command, args []string) error {
 		cmd.SilenceUsage = true
 
-		dir, err := ioutil.TempDir("", "playground")
+		dir, err := os.MkdirTemp("", "playground")
 		if err != nil {
 			return err
 		}
@@ -88,48 +133,42 @@ var playgroundCmd = &cobra.Command{
 		// a real one -- it's surprisingly convincing.
 		cfg.Uname.Nodename = "playground🍯"
 
-		fs, err := vos.NewVFSFromConfig(cfg)
+		playgroundLogger.Printf("Logging to: file://%s\n", dir)
+		playgroundLogger.Printf("See logs with: tail -f %s\n", filepath.Join(dir, config.AppLogName))
+		playgroundLogger.Println(strings.Repeat("=", 80))
+
+		honeypot, err := core.NewHoneypot(cfg, io.Discard)
 		if err != nil {
 			return err
 		}
 
-		logFd, err := cfg.OpenAppLog()
-		if err != nil {
+		session := &playgroundSession{
+			out:        cmd.OutOrStdout(),
+			in:         cmd.InOrStdin(),
+			user:       "root",
+			rawCommand: "/bin/sh",
+			subsystem:  "",
+			environ:    []string{},
+			pty: ssh.Pty{
+				Term: "playground",
+				Window: ssh.Window{
+					Width:  80,
+					Height: 40,
+				},
+			},
+		}
+
+		if err := honeypot.HandleConnection(session); err != nil {
 			return err
 		}
-		defer logFd.Close()
-		logRecorder := logger.NewJsonLinesLogRecorder(logFd)
 
-		playgroundLogger.Printf("Logging to: file://%s\n", dir)
-		playgroundLogger.Printf("See logs with: tail -f %s\n", filepath.Join(dir, logFd.Name()))
 		playgroundLogger.Println(strings.Repeat("=", 80))
-
-		sharedOS := vos.NewSharedOS(fs, commands.BuiltinProcessResolver, cfg, time.Now)
-		tenantOS := vos.NewTenantOS(sharedOS, logRecorder.NewSession("playground"), &playgroundSession{
-			out:  cmd.OutOrStdout(),
-			user: "root",
-		})
-		// TODO: Connect to the real PTY
-		tenantOS.SetPTY(vos.PTY{
-			Width:  80,
-			Height: 40,
-			Term:   "playground",
-			IsPTY:  true,
-		})
-
-		initProc := tenantOS.LoginProc()
-
-		runner, err := initProc.StartProcess("/bin/sh", []string{}, &vos.ProcAttr{
-			Dir:   "/",
-			Env:   initProc.Environ(),
-			Files: &osVIO{},
-		})
-		if err != nil {
-			return err
+		if session.exitCalled {
+			playgroundLogger.Printf("Session ended, exit code: %d\n", session.exitCode)
+		} else {
+			playgroundLogger.Println("Session ended, exit not called")
 		}
 
-		exitCode := runner.Run()
-		fmt.Fprintf(cmd.OutOrStdout(), "Exit code: %d\n", exitCode)
 		return nil
 	},
 }

cmd/root.go

@@ -5,8 +5,8 @@ import (
 	"io/fs"
 	"log"
 
-	"github.com/spf13/cobra"
 	"github.com/josephlewis42/honeyssh/core/config"
+	"github.com/spf13/cobra"
 )
 
 var cfgPath string

cmd/serve.go

@@ -8,8 +8,8 @@ import (
 	"syscall"
 	"time"
 
-	"github.com/spf13/cobra"
 	"github.com/josephlewis42/honeyssh/core"
+	"github.com/spf13/cobra"
 )
 
 // serveCmd represents the serve command

commands/env_test.go

@@ -3,8 +3,8 @@ package commands
 import (
 	"testing"
 
-	"github.com/stretchr/testify/assert"
 	"github.com/josephlewis42/honeyssh/core/vos/vostest"
+	"github.com/stretchr/testify/assert"
 )
 
 func TestEnv(t *testing.T) {

core/config/initialize.go

@@ -16,7 +16,7 @@ import (
 	"github.com/spf13/afero"
 )
 
-// Initialize creates the honeypot configuartion in the given directory.
+// Initialize creates the honeypot configuration in the given directory.
 func Initialize(path string, logger *log.Logger) (*Configuration, error) {
 	// Make sure path exists
 	full, err := filepath.Abs(path)

core/honeypot.go

@@ -147,8 +147,23 @@ func (h *Honeypot) Close() error {
 	return h.toClose.Close()
 }
 
-func (h *Honeypot) HandleConnection(s ssh.Session) error {
-	sessionID := fmt.Sprintf("%d", time.Now().UnixNano())
+// Minimal properties from ssh.Session needed for the honeypot.
+type SessionInfo interface {
+	Context() context.Context
+	Environ() []string
+	RawCommand() string
+	Subsystem() string
+	Command() []string
+	Pty() (ssh.Pty, <-chan ssh.Window, bool)
+	vos.SSHSession
+	io.ReadCloser
+}
+
+var _ SessionInfo = (ssh.Session)(nil)
+
+func (h *Honeypot) HandleConnection(s SessionInfo) error {
+	sessionStartTime := time.Now()
+	sessionID := fmt.Sprintf("%d", sessionStartTime.UnixNano())
 	sessionLogger := h.logger.NewSession(sessionID)
 
 	// Log panics to prevent a single connection from bringing down the whole
@@ -179,7 +194,7 @@ func (h *Honeypot) HandleConnection(s ssh.Session) error {
 		},
 	})
 
-	// Set up I/O and loging.
+	// Set up I/O and logging.
 	logFileName := fmt.Sprintf("%s.%s", time.Now().Format(time.RFC3339Nano), ttylog.AsciicastFileExt)
 	sessionLogger.Record(&logger.LogEntry_OpenTtyLog{
 		OpenTtyLog: &logger.OpenTTYLog{
@@ -194,7 +209,21 @@ func (h *Honeypot) HandleConnection(s ssh.Session) error {
 	defer logFd.Close()
 
 	// Start logging the terminal interactions
-	vio := ttylog.NewRecorder(vos.NewVIOAdapter(s, s, s), ttylog.NewAsciicastLogSink(logFd))
+	readCounter := vos.NewCounter(s, func(b byte) bool {
+		return b == 127 || // Delete
+			b == 8 // Backspace
+	})
+	vio := ttylog.NewRecorder(vos.NewVIOAdapter(readCounter, s, s), ttylog.NewAsciicastLogSink(logFd))
+
+	defer func() {
+		sessionLogger.Record(&logger.LogEntry_SessionEnded{
+			SessionEnded: &logger.SessionEnded{
+				DurationMs:         time.Since(sessionStartTime).Milliseconds(),
+				HumanKeypressCount: int64(readCounter.MatchedTotal),
+				StdinByteCount:     int64(readCounter.Total),
+			},
+		})
+	}()
 
 	procName := h.configuration.OS.DefaultShell
 	procArgs := []string{procName}