Added request recording and profiling handlers

Signed-off-by: Micah Hausler <mhausler@amazon.com>

.golangci.yml

@@ -1,5 +1,5 @@
 run:
-  deadline: 5m
+  timeout: 5m
   allow-parallel-runners: true
 
 issues:

internal/server/config/config.go

@@ -15,10 +15,19 @@ type AuthorizationWebhookConfig struct {
 
 	ErrorInjection *ErrorInjectionConfig
 	SecureServing  *apiserver.SecureServingInfo
+
+	DebugOptions *DebugOptions
 }
 
 type ErrorInjectionConfig struct {
 	ArtificialErrorRate float64
 	ArtificialDenyRate  float64
 	Enabled             bool
 }
+
+type DebugOptions struct {
+	EnableProfiling bool
+
+	EnableRecording bool
+	RecordingDir    string
+}

internal/server/handler.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"net/http"
 	"net/http/httputil"
+	"net/http/pprof"
 	"strings"
 	"time"
 
@@ -30,22 +31,42 @@ import (
 type AuthorizerServer struct {
 	handler    http.Handler
 	authorizer cedarauthorizer.Authorizer
+
+	cfg *config.AuthorizationWebhookConfig
 }
 
 // NewServer is a constructor for the AuthorizerServer.  It defines the
-// /authorize handler.
+// /v1/authorize and /v1/admit handlers.
 func NewServer(authorizer cedarauthorizer.Authorizer, admissionHandler http.Handler, cfg *config.AuthorizationWebhookConfig) *AuthorizerServer {
 	mux := http.NewServeMux()
-	errorInjector := NewErrorInjector(cfg.ErrorInjection)
-	mux.HandleFunc("/v1/authorize", authorizeHandlerFunc(authorizer, errorInjector))
-	mux.Handle("/v1/admit", admissionHandler)
-	return &AuthorizerServer{
+	as := &AuthorizerServer{
 		handler:    mux,
 		authorizer: authorizer,
+		cfg:        cfg,
+	}
+	errorInjector := NewErrorInjector(cfg.ErrorInjection)
+
+	var authzHandler http.Handler = as.authorizeHandlerFunc(authorizer, errorInjector)
+
+	if cfg.DebugOptions.EnableRecording {
+		authzHandler = RecordRequest(cfg.DebugOptions.RecordingDir)(authzHandler)
+		admissionHandler = RecordRequest(cfg.DebugOptions.RecordingDir)(admissionHandler)
+	}
+
+	mux.Handle("/v1/authorize", authzHandler)
+	mux.Handle("/v1/admit", admissionHandler)
+
+	if cfg.DebugOptions.EnableProfiling {
+		mux.HandleFunc("/debug/pprof/", pprof.Index)
+		mux.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
+		mux.HandleFunc("/debug/pprof/profile", pprof.Profile)
+		mux.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
+		mux.HandleFunc("/debug/pprof/trace", pprof.Trace)
 	}
+	return as
 }
 
-func newServer() *http.ServeMux {
+func newHealthHandlers() *http.ServeMux {
 	mux := http.NewServeMux()
 	// TODO: actually check health status
 	mux.HandleFunc("/healthz", healthzHandlerFunc())
@@ -58,13 +79,13 @@ func newServer() *http.ServeMux {
 func NewMetricsServer() *http.Server {
 	return &http.Server{
 		Addr:         fmt.Sprintf("%s:%d", options.CedarAuthorizerDefaultAddress, options.CedarAuthorizerMetricsPort),
-		Handler:      newServer(),
+		Handler:      newHealthHandlers(),
 		ReadTimeout:  5 * time.Second,
 		WriteTimeout: 5 * time.Second,
 	}
 }
 
-func authorizeHandlerFunc(authorizer cedarauthorizer.Authorizer, errorInjector *ErrorInjector) http.HandlerFunc {
+func (as *AuthorizerServer) authorizeHandlerFunc(authorizer cedarauthorizer.Authorizer, errorInjector *ErrorInjector) http.HandlerFunc {
 	return func(w http.ResponseWriter, r *http.Request) {
 		var (
 			err                   error

internal/server/options/options.go

@@ -46,13 +46,20 @@ type AuthorizerOptions struct {
 	SecureServing  *apiserveroptions.SecureServingOptions
 	ErrorInjection *ErrorInjectionOptions
 	Cedar          *CedarOptions
+	DebugOptions   *DebugOptions
 }
 
 type CedarOptions struct {
 	PolicyDir                 string
 	PolicyDirRrefreshInterval time.Duration
 }
 
+type DebugOptions struct {
+	EnableProfiling bool
+	EnableRecording bool
+	RecordingDir    string
+}
+
 type ErrorInjectionOptions struct {
 	// ArtificialErrorRate is the maximum number of fake errors returned per second by the error injector
 	ArtificialErrorRate float64
@@ -68,6 +75,7 @@ func NewCedarAuthorizerOptions() *AuthorizerOptions {
 		SecureServing:   NewAuthorizerSecureServingOptions(),
 		ErrorInjection:  NewErrorInjectionOptions(),
 		Cedar:           NewCedarOptions(),
+		DebugOptions:    NewDebugOptions(),
 	}
 }
 
@@ -99,6 +107,14 @@ func NewCedarOptions() *CedarOptions {
 	}
 }
 
+func NewDebugOptions() *DebugOptions {
+	return &DebugOptions{
+		EnableProfiling: false,
+		EnableRecording: false,
+		RecordingDir:    "",
+	}
+}
+
 // Config creates a runtime config object from the options (command line flags).
 func (o *AuthorizerOptions) Config() (*config.AuthorizationWebhookConfig, error) {
 	// If we ever need to listen on non-localhost, provide the address here
@@ -109,7 +125,9 @@ func (o *AuthorizerOptions) Config() (*config.AuthorizationWebhookConfig, error)
 		return nil, err
 	}
 
-	cfg := &config.AuthorizationWebhookConfig{}
+	cfg := &config.AuthorizationWebhookConfig{
+		DebugOptions: &config.DebugOptions{},
+	}
 	if err := o.ApplyTo(cfg); err != nil {
 		return nil, err
 	}
@@ -134,6 +152,10 @@ func (o *AuthorizerOptions) ApplyTo(cfg *config.AuthorizationWebhookConfig) erro
 	cfg.PolicyDir = o.Cedar.PolicyDir
 	cfg.PolicyDirRefreshInterval = o.Cedar.PolicyDirRrefreshInterval
 
+	if o.DebugOptions != nil {
+		o.DebugOptions.ApplyTo(cfg.DebugOptions)
+	}
+
 	return nil
 }
 
@@ -157,6 +179,15 @@ func (o *ErrorInjectionOptions) ApplyTo(cfg **config.ErrorInjectionConfig) {
 	}
 }
 
+func (o *DebugOptions) ApplyTo(cfg *config.DebugOptions) {
+	if o == nil {
+		return
+	}
+	cfg.EnableProfiling = o.EnableProfiling
+	cfg.EnableRecording = o.EnableRecording
+	cfg.RecordingDir = o.RecordingDir
+}
+
 // Flags adds flags to fs and binds them to the CedarAuthorizerOptions
 func (o *AuthorizerOptions) Flags() *cliflag.NamedFlagSets {
 	fss := cliflag.NamedFlagSets{}
@@ -173,6 +204,11 @@ func (o *AuthorizerOptions) Flags() *cliflag.NamedFlagSets {
 	fs.Float64Var(&o.ErrorInjection.ArtificialErrorRate, "artificial-error-rate", o.ErrorInjection.ArtificialErrorRate, "Cause the authorizer to occasionally return errors at the specified rate.  Useful to validate metrics are working as expected.")
 	fs.Float64Var(&o.ErrorInjection.ArtificialDenyRate, "artificial-deny-rate", o.ErrorInjection.ArtificialDenyRate, "Cause the authorizer to occasionally return denies at the specified rate.  Useful to validate metrics are working as expected.")
 
+	fs = fss.FlagSet("debug")
+	fs.BoolVar(&o.DebugOptions.EnableProfiling, "profiling", o.DebugOptions.EnableProfiling, "Enable profiling via web interface host:port/debug/pprof/")
+	fs.BoolVar(&o.DebugOptions.EnableRecording, "enable-request-recording", o.DebugOptions.EnableRecording, "Enable recording of requests")
+	fs.StringVar(&o.DebugOptions.RecordingDir, "request-recording-dir", o.DebugOptions.RecordingDir, "The directory to record requests to")
+
 	o.SecureServing.AddFlags(fss.FlagSet("secure serving"))
 
 	return &fss

internal/server/recorder.go

@@ -0,0 +1,64 @@
+package server
+
+import (
+	"fmt"
+	"io"
+	"net/http"
+	"os"
+	"path/filepath"
+	"time"
+
+	"k8s.io/klog/v2"
+)
+
+type Middleware func(http.Handler) http.Handler
+
+// Apply wraps a list of middlewares around a handler and returns it
+func Apply(h http.Handler, middlewares ...Middleware) http.Handler {
+	for _, adapter := range middlewares {
+		h = adapter(h)
+	}
+	return h
+}
+
+func RecordRequest(recordingDir string) Middleware {
+	fi, err := os.Stat(recordingDir)
+	if err != nil && !os.IsNotExist(err) {
+		klog.Fatalf("Unable to open recording dir: %v", err)
+	} else if err != nil && os.IsNotExist(err) {
+		err = os.MkdirAll(recordingDir, 0644)
+		if err != nil {
+			klog.Fatalf("Unable to create recording dir: %v", err)
+		}
+	} else if !fi.IsDir() {
+		klog.Fatalf("Recording directory is not a directory: %s", recordingDir)
+	}
+	return func(h http.Handler) http.Handler {
+		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			defer func() {
+				if r.Body == nil {
+					return
+				}
+				filename := filepath.Join(
+					recordingDir,
+					fmt.Sprintf(
+						"req-%s-%d.json",
+						filepath.Base(r.URL.Path),
+						time.Now().UnixNano()))
+				f, err := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY, 0666)
+				if err != nil {
+					klog.ErrorS(err, "Failed to open file", "filename", filename)
+					return
+				}
+				defer f.Close()      //nolint:all
+				defer r.Body.Close() //nolint:all
+				_, err = io.Copy(f, r.Body)
+				if err != nil {
+					klog.ErrorS(err, "Failed to write request", "filename", filename)
+				}
+				klog.V(8).InfoS("Recorded request", "filename", filename)
+			}()
+			h.ServeHTTP(w, r)
+		})
+	}
+}

internal/server/store/store.go

@@ -3,7 +3,6 @@ package store
 import (
 	"github.com/cedar-policy/cedar-go"
 	cedartypes "github.com/cedar-policy/cedar-go/types"
-	"k8s.io/klog/v2"
 )
 
 type PolicyStore interface {
@@ -31,7 +30,6 @@ func (s TieredPolicyStores) IsAuthorized(entities cedartypes.EntityMap, req ceda
 		}
 
 		if decision == cedar.Deny && len(diagnostic.Reasons) == 0 && len(diagnostic.Errors) == 0 {
-			klog.V(2).InfoS("No explicit decision found", "store", store.Name())
 			continue
 		}
 		break

manifests/cedar-authorization-webhook.yaml

@@ -70,13 +70,19 @@ spec:
           readOnly: true
         - mountPath: /var/run/cedar-authorizer/certs
           name: var-run-cedar-authorizer-certs
+        - mountPath: /cedar/logs
+          name: cedar-logs
   hostNetwork: true
   priority: 2000001000
   priorityClassName: system-node-critical
   securityContext:
     seccompProfile:
       type: RuntimeDefault
   volumes:
+    - hostPath:
+        path: /cedar-authorizer/logs
+        type: ""
+      name: cedar-logs
     - hostPath:
         path: /cedar-authorizer
         type: ""