Merge pull request #334 from BishopFox/stage

Improved logging

Dockerfile

@@ -1,4 +1,4 @@
-FROM golang:1.16rc1
+FROM golang:1.16
 
 #
 # IMPORTANT: This Dockerfile is used for testing, I do not recommend deploying

client/command/bind-commands.go

@@ -362,7 +362,7 @@ func BindCommands(app *grumble.App, rpc rpcpb.SliverRPCClient) {
 		Flags: func(f *grumble.Flags) {
 			f.String("o", "os", "windows", "operating system")
 			f.String("a", "arch", "amd64", "cpu architecture")
-			f.String("n", "name", "", "agent name")
+			f.String("N", "name", "", "agent name")
 			f.Bool("d", "debug", false, "enable debug features")
 			f.Bool("e", "evasion", false, "enable evasion features")
 			f.Bool("b", "skip-symbols", false, "skip symbol obfuscation")

client/core/tunnel.go

@@ -144,7 +144,7 @@ func TunnelLoop(rpc rpcpb.SliverRPCClient) error {
 	}
 	for {
 
-		log.Printf("Waiting for TunnelData ...")
+		// log.Printf("Waiting for TunnelData ...")
 		incoming, err := stream.Recv()
 		log.Printf("Recv stream msg: %v", incoming)
 		if err == io.EOF {
@@ -155,7 +155,7 @@ func TunnelLoop(rpc rpcpb.SliverRPCClient) error {
 			log.Printf("Tunnel data read error: %s", err)
 			return err
 		}
-		log.Printf("Received TunnelData for tunnel %d", incoming.TunnelID)
+		// log.Printf("Received TunnelData for tunnel %d", incoming.TunnelID)
 		tunnel := Tunnels.Get(incoming.TunnelID)
 		if tunnel != nil {
 			if !incoming.Closed {

server/certs/operators.go

@@ -52,9 +52,9 @@ func OperatorClientRemoveCertificate(operator string) error {
 	return RemoveCertificate(OperatorCA, ECCKey, fmt.Sprintf("%s.%s", clientNamespace, operator))
 }
 
-// OperatorServerGetCertificate - Helper function to fetch a client cert
-func OperatorServerGetCertificate(operator string) ([]byte, []byte, error) {
-	return GetECCCertificate(OperatorCA, fmt.Sprintf("%s.%s", serverNamespace, operator))
+// OperatorServerGetCertificate - Helper function to fetch a server cert
+func OperatorServerGetCertificate(hostname string) ([]byte, []byte, error) {
+	return GetECCCertificate(OperatorCA, fmt.Sprintf("%s.%s", serverNamespace, hostname))
 }
 
 // OperatorServerGenerateCertificate - Generate a certificate signed with a given CA

server/cli/cli.go

@@ -23,6 +23,7 @@ import (
 	"log"
 	"os"
 	"path"
+	"runtime/debug"
 	"strings"
 
 	"github.com/bishopfox/sliver/client/version"
@@ -109,6 +110,14 @@ var rootCmd = &cobra.Command{
 		logFile := initLogging(appDir)
 		defer logFile.Close()
 
+		defer func() {
+			if r := recover(); r != nil {
+				log.Printf("panic:\n%s", debug.Stack())
+				fmt.Println("stacktrace from panic: \n" + string(debug.Stack()))
+				os.Exit(99)
+			}
+		}()
+
 		assets.Setup(false)
 		certs.SetupCAs()
 

server/handlers/sessions.go

@@ -23,8 +23,10 @@ package handlers
 */
 
 import (
+	"encoding/json"
 	"sync"
 
+	"github.com/bishopfox/sliver/protobuf/clientpb"
 	"github.com/bishopfox/sliver/protobuf/sliverpb"
 	"github.com/bishopfox/sliver/server/core"
 	"github.com/bishopfox/sliver/server/log"
@@ -68,23 +70,20 @@ func registerSessionHandler(session *core.Session, data []byte) {
 		return
 	}
 
-	handlerLog.Warnf("%v", session)
-	handlerLog.Warnf("%v", register)
-
 	if session.ID == 0 {
 		session.ID = core.NextSessionID()
 	}
 
 	// Parse Register UUID
-	session_uuid, err := uuid.Parse(register.Uuid)
+	sessionUUID, err := uuid.Parse(register.Uuid)
 	if err != nil {
 		// Generate Random UUID
-		session_uuid = uuid.New()
+		sessionUUID = uuid.New()
 	}
 
 	session.Name = register.Name
 	session.Hostname = register.Hostname
-	session.UUID = session_uuid.String()
+	session.UUID = sessionUUID.String()
 	session.Username = register.Username
 	session.UID = register.Uid
 	session.GID = register.Gid
@@ -97,6 +96,24 @@ func registerSessionHandler(session *core.Session, data []byte) {
 	session.ReconnectInterval = register.ReconnectInterval
 	session.ProxyURL = register.ProxyURL
 	core.Sessions.Add(session)
+	go auditLogSession(session, register)
+}
+
+type auditLogNewSessionMsg struct {
+	Session  *clientpb.Session
+	Register *sliverpb.Register
+}
+
+func auditLogSession(session *core.Session, register *sliverpb.Register) {
+	msg, err := json.Marshal(auditLogNewSessionMsg{
+		Session:  session.ToProtobuf(),
+		Register: register,
+	})
+	if err != nil {
+		handlerLog.Errorf("Failed to log new session to audit log %s", err)
+	} else {
+		log.AuditLogger.Warn(string(msg))
+	}
 }
 
 // The handler mutex prevents a send on a closed channel, without it

server/log/audit.go

@@ -35,7 +35,7 @@ func newAuditLogger() *logrus.Logger {
 	auditLogger := logrus.New()
 	auditLogger.Formatter = &logrus.JSONFormatter{}
 	jsonFilePath := path.Join(GetLogDir(), "audit.json")
-	jsonFile, err := os.OpenFile(jsonFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+	jsonFile, err := os.OpenFile(jsonFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600)
 	if err != nil {
 		panic(fmt.Sprintf("Failed to open log file %v", err))
 	}

server/transport/local.go

@@ -19,6 +19,8 @@ package transport
 */
 
 import (
+	"runtime/debug"
+
 	"github.com/bishopfox/sliver/protobuf/rpcpb"
 	"github.com/bishopfox/sliver/server/log"
 	"github.com/bishopfox/sliver/server/rpc"
@@ -29,13 +31,13 @@ import (
 const bufSize = 2 * mb
 
 var (
-	pipeLog = log.NamedLogger("transport", "local")
+	bufConnLog = log.NamedLogger("transport", "local")
 )
 
 // LocalListener - Bind gRPC server to an in-memory listener, which is
 //                 typically used for unit testing, but ... it should be fine
 func LocalListener() (*grpc.Server, *bufconn.Listener, error) {
-	pipeLog.Infof("Binding gRPC to listener ...")
+	bufConnLog.Infof("Binding gRPC to listener ...")
 	ln := bufconn.Listen(bufSize)
 	options := []grpc.ServerOption{
 		grpc.MaxRecvMsgSize(ServerMaxMessageSize),
@@ -45,8 +47,16 @@ func LocalListener() (*grpc.Server, *bufconn.Listener, error) {
 	grpcServer := grpc.NewServer(options...)
 	rpcpb.RegisterSliverRPCServer(grpcServer, rpc.NewServer())
 	go func() {
+		panicked := true
+		defer func() {
+			if panicked {
+				bufConnLog.Errorf("stacktrace from panic: %s", string(debug.Stack()))
+			}
+		}()
 		if err := grpcServer.Serve(ln); err != nil {
-			pipeLog.Fatalf("gRPC local listener error: %v", err)
+			bufConnLog.Fatalf("gRPC local listener error: %v", err)
+		} else {
+			panicked = false
 		}
 	}()
 	return grpcServer, ln, nil

server/transport/logging.go

@@ -20,6 +20,8 @@ package transport
 
 import (
 	"context"
+	"encoding/json"
+	"fmt"
 
 	"github.com/bishopfox/sliver/server/configs"
 	"github.com/bishopfox/sliver/server/log"
@@ -44,6 +46,7 @@ func initLoggerMiddleware() []grpc.ServerOption {
 	grpc_logrus.ReplaceGrpcLogger(logrusEntry)
 	return []grpc.ServerOption{
 		grpc_middleware.WithUnaryServerChain(
+			auditLogUnaryServerInterceptor(),
 			grpc_tags.UnaryServerInterceptor(grpc_tags.WithFieldExtractor(grpc_tags.CodeGenRequestFieldExtractor)),
 			grpc_logrus.UnaryServerInterceptor(logrusEntry, logrusOpts...),
 			grpc_logrus.PayloadUnaryServerInterceptor(logrusEntry, deciderUnary),
@@ -105,3 +108,30 @@ func codeToLevel(code codes.Code) logrus.Level {
 		return logrus.ErrorLevel
 	}
 }
+
+type auditUnaryLogMsg struct {
+	Request string `json:"request"`
+	Method  string `json:"method"`
+}
+
+func auditLogUnaryServerInterceptor() grpc.UnaryServerInterceptor {
+	return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (_ interface{}, err error) {
+		var request string
+		rawRequest, err := json.Marshal(req)
+		if err != nil {
+			log.AuditLogger.Errorf("Failed to serialize %s", err)
+			request = fmt.Sprintf("%v", req)
+		} else {
+			request = string(rawRequest)
+		}
+
+		msg, _ := json.Marshal(&auditUnaryLogMsg{
+			Request: request,
+			Method:  info.FullMethod,
+		})
+		log.AuditLogger.Info(string(msg))
+
+		resp, err := handler(ctx, req)
+		return resp, err
+	}
+}

server/transport/mtls.go

@@ -23,6 +23,7 @@ import (
 	"crypto/x509"
 	"fmt"
 	"net"
+	"runtime/debug"
 
 	"github.com/bishopfox/sliver/protobuf/rpcpb"
 	"github.com/bishopfox/sliver/server/certs"
@@ -65,8 +66,16 @@ func StartClientListener(host string, port uint16) (*grpc.Server, net.Listener,
 	grpcServer := grpc.NewServer(options...)
 	rpcpb.RegisterSliverRPCServer(grpcServer, rpc.NewServer())
 	go func() {
+		panicked := true
+		defer func() {
+			if panicked {
+				mtlsLog.Errorf("stacktrace from panic: %s", string(debug.Stack()))
+			}
+		}()
 		if err := grpcServer.Serve(ln); err != nil {
 			mtlsLog.Warnf("gRPC server exited with error: %v", err)
+		} else {
+			panicked = false
 		}
 	}()
 	return grpcServer, ln, nil