Add initial niaeve implementation of SFTP logging

This will end up flooding the activity logs due to the way SFTP works, we'll need to have an intermediate step in Wings that batches events every 10 seconds or so and submits them as a single "event" for activity.

internal/cron/activity_cron.go

@@ -18,6 +18,7 @@ func processActivityLogs(m *server.Manager, c int64) error {
 	// Don't execute this cron if there is currently one running. Once this task is completed
 	// go ahead and mark it as no longer running.
 	if !processing.SwapIf(true) {
+		log.WithField("subsystem", "cron").Warn("cron: process overlap detected, skipping this run")
 		return nil
 	}
 	defer processing.Store(false)

internal/cron/cron.go

@@ -26,7 +26,7 @@ func Scheduler(m *server.Manager) (*gocron.Scheduler, error) {
 	}
 
 	s := gocron.NewScheduler(l)
-	_, _ = s.Tag("activity").Every(config.Get().System.ActivitySendInterval).Seconds().Do(func() {
+	_, _ = s.Tag("activity").Every(int(config.Get().System.ActivitySendInterval)).Seconds().Do(func() {
 		if err := processActivityLogs(m, config.Get().System.ActivitySendCount); err != nil {
 			log.WithField("error", err).Error("cron: failed to process activity events")
 		}

remote/types.go

@@ -86,6 +86,7 @@ type SftpAuthRequest struct {
 // user for the SFTP subsystem.
 type SftpAuthResponse struct {
 	Server      string   `json:"server"`
+	User        string   `json:"user"`
 	Permissions []string `json:"permissions"`
 }
 

server/activity.go

@@ -17,6 +17,11 @@ const ActivityPowerPrefix = "server:power."
 
 const (
 	ActivityConsoleCommand      = Event("server:console.command")
+	ActivityFileDeleted         = Event("server:file.delete")
+	ActivityFileRename          = Event("server:file.rename")
+	ActivityFileCreateDirectory = Event("server:file.create-directory")
+	ActivityFileWrite           = Event("server:file.write")
+	ActivityFileRead            = Event("server:file.read")
 )
 
 var ipTrimRegex = regexp.MustCompile(`(:\d*)?$`)

sftp/handler.go

@@ -26,30 +26,38 @@ const (
 	PermissionFileDelete      = "file.delete"
 )
 
+type handlerMeta struct {
+	ra     server.RequestActivity
+	server *server.Server
+}
+
 type Handler struct {
 	mu          sync.Mutex
-
+	meta        handlerMeta
 	permissions []string
-	server      *server.Server
 	fs          *filesystem.Filesystem
 	logger      *log.Entry
 	ro          bool
 }
 
-// Returns a new connection handler for the SFTP server. This allows a given user
+// NewHandler returns a new connection handler for the SFTP server. This allows a given user
 // to access the underlying filesystem.
-func NewHandler(sc *ssh.ServerConn, srv *server.Server) *Handler {
+func NewHandler(sc *ssh.ServerConn, srv *server.Server) (*Handler, error) {
+	uuid, ok := sc.Permissions.Extensions["user"]
+	if !ok {
+		return nil, errors.New("sftp: mismatched Wings and Panel versions — Panel 1.10 is required for this version of Wings.")
+	}
+
 	return &Handler{
 		permissions: strings.Split(sc.Permissions.Extensions["permissions"], ","),
+		meta: handlerMeta{
 			server: srv,
+			ra:     srv.NewRequestActivity(uuid, sc.RemoteAddr().String()),
+		},
 		fs:     srv.Filesystem(),
 		ro:     config.Get().System.Sftp.ReadOnly,
-		logger: log.WithFields(log.Fields{
+		logger: log.WithFields(log.Fields{"subsystem": "sftp", "user": uuid, "ip": sc.RemoteAddr()}),
-			"subsystem": "sftp",
+	}, nil
-			"username":  sc.User(),
-			"ip":        sc.RemoteAddr(),
-		}),
-	}
 }
 
 // Returns the sftp.Handlers for this struct.
@@ -80,6 +88,7 @@ func (h *Handler) Fileread(request *sftp.Request) (io.ReaderAt, error) {
 		}
 		return nil, sftp.ErrSSHFxNoSuchFile
 	}
+	h.event(server.ActivityFileRead, server.ActivityMeta{"file": filepath.Clean(request.Filepath)})
 	return f, nil
 }
 
@@ -121,7 +130,8 @@ func (h *Handler) Filewrite(request *sftp.Request) (io.WriterAt, error) {
 	}
 	// Chown may or may not have been called in the touch function, so always do
 	// it at this point to avoid the file being improperly owned.
-	_ = h.server.Filesystem().Chown(request.Filepath)
+	_ = h.fs.Chown(request.Filepath)
+	h.event(server.ActivityFileWrite, server.ActivityMeta{"file": filepath.Clean(request.Filepath)})
 	return f, nil
 }
 
@@ -165,13 +175,21 @@ func (h *Handler) Filecmd(request *sftp.Request) error {
 		if !h.can(PermissionFileUpdate) {
 			return sftp.ErrSSHFxPermissionDenied
 		}
-		if err := h.fs.Rename(request.Filepath, request.Target); err != nil {
+		p := filepath.Clean(request.Filepath)
+		t := filepath.Clean(request.Target)
+		if err := h.fs.Rename(p, t); err != nil {
 			if errors.Is(err, os.ErrNotExist) {
 				return sftp.ErrSSHFxNoSuchFile
 			}
 			l.WithField("error", err).Error("failed to rename file")
 			return sftp.ErrSSHFxFailure
 		}
+		h.event(server.ActivityFileRename, server.ActivityMeta{
+			"directory": filepath.Dir(p),
+			"files": []map[string]string{
+				{"from": filepath.Base(p), "to": t},
+			},
+		})
 		break
 	// Handle deletion of a directory. This will properly delete all of the files and
 	// folders within that directory if it is not already empty (unlike a lot of SFTP
@@ -180,10 +198,15 @@ func (h *Handler) Filecmd(request *sftp.Request) error {
 		if !h.can(PermissionFileDelete) {
 			return sftp.ErrSSHFxPermissionDenied
 		}
-		if err := h.fs.Delete(request.Filepath); err != nil {
+		p := filepath.Clean(request.Filepath)
+		if err := h.fs.Delete(p); err != nil {
 			l.WithField("error", err).Error("failed to remove directory")
 			return sftp.ErrSSHFxFailure
 		}
+		h.event(server.ActivityFileDeleted, server.ActivityMeta{
+			"directory": filepath.Dir(p),
+			"files":     []string{filepath.Base(p)},
+		})
 		return sftp.ErrSSHFxOk
 	// Handle requests to create a new Directory.
 	case "Mkdir":
@@ -191,11 +214,15 @@ func (h *Handler) Filecmd(request *sftp.Request) error {
 			return sftp.ErrSSHFxPermissionDenied
 		}
 		name := strings.Split(filepath.Clean(request.Filepath), "/")
-		err := h.fs.CreateDirectory(name[len(name)-1], strings.Join(name[0:len(name)-1], "/"))
+		p := strings.Join(name[0:len(name)-1], "/")
-		if err != nil {
+		if err := h.fs.CreateDirectory(name[len(name)-1], p); err != nil {
 			l.WithField("error", err).Error("failed to create directory")
 			return sftp.ErrSSHFxFailure
 		}
+		h.event(server.ActivityFileCreateDirectory, server.ActivityMeta{
+			"directory": p,
+			"name":      name[len(name)-1],
+		})
 		break
 	// Support creating symlinks between files. The source and target must resolve within
 	// the server home directory.
@@ -221,13 +248,18 @@ func (h *Handler) Filecmd(request *sftp.Request) error {
 		if !h.can(PermissionFileDelete) {
 			return sftp.ErrSSHFxPermissionDenied
 		}
-		if err := h.fs.Delete(request.Filepath); err != nil {
+		p := filepath.Clean(request.Filepath)
+		if err := h.fs.Delete(p); err != nil {
 			if errors.Is(err, os.ErrNotExist) {
 				return sftp.ErrSSHFxNoSuchFile
 			}
 			l.WithField("error", err).Error("failed to remove a file")
 			return sftp.ErrSSHFxFailure
 		}
+		h.event(server.ActivityFileDeleted, server.ActivityMeta{
+			"directory": filepath.Dir(p),
+			"files":     []string{filepath.Base(p)},
+		})
 		return sftp.ErrSSHFxOk
 	default:
 		return sftp.ErrSSHFxOpUnsupported
@@ -284,10 +316,9 @@ func (h *Handler) Filelist(request *sftp.Request) (sftp.ListerAt, error) {
 // Determines if a user has permission to perform a specific action on the SFTP server. These
 // permissions are defined and returned by the Panel API.
 func (h *Handler) can(permission string) bool {
-	if h.server.IsSuspended() {
+	if h.meta.server.IsSuspended() {
 		return false
 	}
-
 	for _, p := range h.permissions {
 		// If we match the permission specifically, or the user has been granted the "*"
 		// permission because they're an admin, let them through.
@@ -297,3 +328,16 @@ func (h *Handler) can(permission string) bool {
 	}
 	return false
 }
+
+// event is a wrapper around the server.RequestActivity struct for this handler to
+// make logging events a little less noisy for SFTP. This also tags every event logged
+// using it with a "{using_sftp: true}" metadata field to make this easier to understand
+// in the Panel's activity logs.
+func (h *Handler) event(event server.Event, metadata server.ActivityMeta) {
+	m := metadata
+	if m == nil {
+		m = make(map[string]interface{})
+	}
+	m["using_sftp"] = true
+	_ = h.meta.ra.Save(h.meta.server, event, m)
+}

sftp/server.go

@@ -91,19 +91,21 @@ func (c *SFTPServer) Run() error {
 		if conn, _ := listener.Accept(); conn != nil {
 			go func(conn net.Conn) {
 				defer conn.Close()
-				c.AcceptInbound(conn, conf)
+				if err := c.AcceptInbound(conn, conf); err != nil {
+					log.WithField("error", err).Error("sftp: failed to accept inbound connection")
+				}
 			}(conn)
 		}
 	}
 }
 
-// Handles an inbound connection to the instance and determines if we should serve the
+// AcceptInbound handles an inbound connection to the instance and determines if we should
-// request or not.
+// serve the request or not.
-func (c *SFTPServer) AcceptInbound(conn net.Conn, config *ssh.ServerConfig) {
+func (c *SFTPServer) AcceptInbound(conn net.Conn, config *ssh.ServerConfig) error {
 	// Before beginning a handshake must be performed on the incoming net.Conn
 	sconn, chans, reqs, err := ssh.NewServerConn(conn, config)
 	if err != nil {
-		return
+		return errors.WithStack(err)
 	}
 	defer sconn.Close()
 	go ssh.DiscardRequests(reqs)
@@ -149,11 +151,17 @@ func (c *SFTPServer) AcceptInbound(conn net.Conn, config *ssh.ServerConfig) {
 
 		// Spin up a SFTP server instance for the authenticated user's server allowing
 		// them access to the underlying filesystem.
-		handler := sftp.NewRequestServer(channel, NewHandler(sconn, srv).Handlers())
+		handler, err := NewHandler(sconn, srv)
-		if err := handler.Serve(); err == io.EOF {
+		if err != nil {
-			handler.Close()
+			return errors.WithStackIf(err)
+		}
+		rs := sftp.NewRequestServer(channel, handler.Handlers())
+		if err := rs.Serve(); err == io.EOF {
+			_ = rs.Close()
 		}
 	}
+
+	return nil
 }
 
 // Generates a new ED25519 private key that is used for host authentication when
@@ -213,8 +221,9 @@ func (c *SFTPServer) makeCredentialsRequest(conn ssh.ConnMetadata, t remote.Sftp
 	logger.WithField("server", resp.Server).Debug("credentials validated and matched to server instance")
 	permissions := ssh.Permissions{
 		Extensions: map[string]string{
+			"ip":          conn.RemoteAddr().String(),
 			"uuid":        resp.Server,
-			"user":        conn.User(),
+			"user":        resp.User,
 			"permissions": strings.Join(resp.Permissions, ","),
 		},
 	}