From bfe0633469e63b2904d78527d7b326ae15feb3a1 Mon Sep 17 00:00:00 2001 From: Johnny Steenbergen Date: Fri, 6 Sep 2024 11:21:43 -0500 Subject: [PATCH] fix: update newHandlerFn to take a logger to canonicalize logging for system integration --- README.md | 79 +++++++++++++++++++++-------------- examples/complex/handler.go | 4 +- examples/fn_config/main.go | 3 +- examples/fn_no_config/main.go | 3 +- runner.go | 12 +++--- runner_http.go | 64 +++++++++++++++------------- runner_test.go | 15 +++---- sdk.go | 31 +++++++------- 8 files changed, 116 insertions(+), 95 deletions(-) diff --git a/README.md b/README.md index 11bc672..877063b 100644 --- a/README.md +++ b/README.md @@ -37,8 +37,8 @@ package main import ( "context" - "encoding/json" "errors" + "log/slog" "net/http" fdk "github.com/CrowdStrike/foundry-fn-go" @@ -48,14 +48,28 @@ func main() { fdk.Run(context.Background(), newHandler) } +type request struct { + Name string `json:"name"` + Val string `json:"val"` +} + // newHandler here is showing how a config is integrated. It is using generics, // so we can unmarshal the config into a concrete type and then validate it. The // OK method is run to validate the contents of the config. -func newHandler(_ context.Context, cfg config) fdk.Handler { +func newHandler(_ context.Context, logger *slog.Logger, cfg config) fdk.Handler { mux := fdk.NewMux() - mux.Post("/echo", fdk.HandlerFn(func(ctx context.Context, r fdk.Request) fdk.Response { + mux.Get("/name", fdk.HandlerFn(func(_ context.Context, r fdk.Request) fdk.Response { + return fdk.Response{ + Body: fdk.JSON(map[string]string{"name": r.Params.Query.Get("name")}), + Code: 200, + } + })) + mux.Post("/echo", fdk.HandlerFnOfOK(func(_ context.Context, r fdk.RequestOf[request]) fdk.Response { + if r.Body.Name == "kaboom" { + logger.Error("encountered the kaboom") + } return fdk.Response{ - Body: r.Body, + Body: fdk.JSON(r.Body), Code: 201, Header: http.Header{"X-Cs-Method": []string{r.Method}}, } @@ -78,21 +92,27 @@ func (c config) OK() error { } return errors.Join(errs...) } + ``` 1. `config`: A type the raw json config is unmarshalled into. -2. `Request`: Request payload and metadata. At the time of this writing, the `Request` struct consists of: - 1. `Body`: The raw request payload as given in the Function Gateway `body` payload field. +2. `logger`: A dedicated logger is provided to capture function logs in all environments (both locally and distributed). + 1. Using a different logger may produce logs in the runtime but won't make it into the logscale infrastructure. +3. `Request`: Request payload and metadata. At the time of this writing, the `Request` struct consists of: + 1. `Body`: The input io.Reader for the payload as given in the Function Gateway `body` payload field or streamed + in. 2. `Params`: Contains request headers and query parameters. 3. `URL`: The request path relative to the function as a string. 4. `Method`: The request HTTP method or verb. 5. `Context`: Caller-supplied raw context. 6. `AccessToken`: Caller-supplied access token. -3. `Response` +4. `RequestOf`: The same as Request only that the Body field is json unmarshalled into the generic type (i.e. `request` + type above) +5. `Response` 1. The `Response` contains fields `Body` (the payload of the response), `Code` (an HTTP status code), `Errors` (a slice of `APIError`s), and `Headers` (a map of any special HTTP headers which should be present on the response). -4. `main()`: Initialization and bootstrap logic all contained with fdk.Run and handler constructor. +6. `main()`: Initialization and bootstrap logic all contained with fdk.Run and handler constructor. more examples can be found at: @@ -138,13 +158,14 @@ package main import ( "context" + "log/slog" - fdk "github.com/CrowdStrike/foundry-fn-go" + fdk "github.com/CrowdStrike/foundry-fn-go" "github.com/CrowdStrike/gofalcon/falcon" "github.com/CrowdStrike/gofalcon/falcon/client" ) -func newHandler(_ context.Context, cfg config) fdk.Handler { +func newHandler(_ context.Context, _ *slog.Logger, cfg config) fdk.Handler { mux := fdk.NewMux() mux.Post("/echo", fdk.HandlerFn(func(ctx context.Context, r fdk.Request) fdk.Response { client, err := newFalconClient(ctx, r.AccessToken) @@ -188,6 +209,7 @@ package somefn import ( "context" + "log/slog" fdk "github.com/CrowdStrike/foundry-fn-go" ) @@ -196,7 +218,7 @@ type reqBody struct { Foo string `json:"foo"` } -func New(ctx context.Context, _ fdk.SkipCfg) fdk.Handler { +func New(ctx context.Context, _ *slog.Logger, _ fdk.SkipCfg) fdk.Handler { m := fdk.NewMux() // for get/delete reqs use HandleWorkflow. The path is just an examples, any payh can be used. @@ -290,34 +312,29 @@ to the caller. Otherwise, it'll `os.Exit` and all stakeholders will have no idea of it. Instead, use something like the following in `fdk.Run`: ```go -// sdk.go - -package fdk +package main import ( "context" -) + "log/slog" + "net/http" -// Run is the meat and potatoes. This is the entrypoint for everything. -func Run[T Cfg](ctx context.Context, newHandlerFn func(_ context.Context, cfg T) Handler) { - // ... trim + fdk "github.com/CrowdStrike/foundry-fn-go" +) - cfg, loadErr := readCfg[T](ctx) - if loadErr != nil { - if loadErr.err != nil { - // these being specific to the author's eyes only - logger.Error("failed to load config", "err", loadErr.err) - } - // here we return a useful error to the caller of the function - run(ctx, logger, ErrHandler(loadErr.apiErr)) - return +func newHandler(_ context.Context, logger *slog.Logger, _ fdk.SkipCfg) fdk.Handler { + foo, err := newFoo() + if err != nil { + // leave yourself/author the nitty-gritty details and return to the end user/caller + // a valid error that doesn't expose all the implementation details + logger.Error("failed to create foo", "err", err.Error()) + return fdk.ErrHandler(fdk.APIError{Code: http.StatusInternalServerError, Message: "unexpected error starting function"}) } - h := newHandlerFn(ctx, cfg) - - run(ctx, logger, h) + mux := fdk.NewMux() + // ...trim rest of setup - return + return mux } ``` diff --git a/examples/complex/handler.go b/examples/complex/handler.go index becfaeb..f2e0b03 100644 --- a/examples/complex/handler.go +++ b/examples/complex/handler.go @@ -4,7 +4,6 @@ import ( "context" "log/slog" "net/http" - "os" fdk "github.com/CrowdStrike/foundry-fn-go" ) @@ -17,8 +16,7 @@ func (c config) OK() error { return nil } -func newHandler(ctx context.Context, cfg config) fdk.Handler { - logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true})) +func newHandler(_ context.Context, logger *slog.Logger, cfg config) fdk.Handler { mux := fdk.NewMux() h := handler{ diff --git a/examples/fn_config/main.go b/examples/fn_config/main.go index 548a44c..ef7eedd 100644 --- a/examples/fn_config/main.go +++ b/examples/fn_config/main.go @@ -4,6 +4,7 @@ import ( "context" "encoding/json" "errors" + "log/slog" "net/http" fdk "github.com/CrowdStrike/foundry-fn-go" @@ -16,7 +17,7 @@ func main() { // newHandler here is showing how a config is integrated. It is using generics, // so we can unmarshal the config into a concrete type and then validate it. The // OK method is run to validate the contents of the config. -func newHandler(_ context.Context, cfg config) fdk.Handler { +func newHandler(context.Context, *slog.Logger, config) fdk.Handler { mux := fdk.NewMux() mux.Get("/foo", fdk.HandlerFn(func(ctx context.Context, r fdk.Request) fdk.Response { return fdk.Response{ diff --git a/examples/fn_no_config/main.go b/examples/fn_no_config/main.go index e4b3cfb..862367f 100644 --- a/examples/fn_no_config/main.go +++ b/examples/fn_no_config/main.go @@ -3,6 +3,7 @@ package main import ( "context" "encoding/json" + "log/slog" "net/http" fdk "github.com/CrowdStrike/foundry-fn-go" @@ -15,7 +16,7 @@ func main() { // newHandlerWithCfg here is showcasing a handler that does not utilize a config, so // it provides the SkipCfg as the config so no config load is attempted. This is the // minority of functions. -func newHandler(context.Context, fdk.SkipCfg) fdk.Handler { +func newHandler(context.Context, *slog.Logger, fdk.SkipCfg) fdk.Handler { mux := fdk.NewMux() mux.Get("/", fdk.HandlerFn(func(ctx context.Context, r fdk.Request) fdk.Response { return fdk.Response{ diff --git a/runner.go b/runner.go index dda87ec..52c1809 100644 --- a/runner.go +++ b/runner.go @@ -8,9 +8,7 @@ import ( ) // Runner defines the runtime that executes the request/response handler lifecycle. -type Runner interface { - Run(ctx context.Context, logger *slog.Logger, h Handler) -} +type Runner func(ctx context.Context, newHandlerFn func(context.Context, *slog.Logger) Handler) // RegisterRunner registers a runner. func RegisterRunner(runnerType string, r Runner) { @@ -21,7 +19,7 @@ func RegisterRunner(runnerType string, r Runner) { runners[runnerType] = r } -func run(ctx context.Context, logger *slog.Logger, h Handler) { +func run(ctx context.Context, newHandlerFn func(context.Context, *slog.Logger) Handler) { rt := os.Getenv("CS_RUNNER_TYPE") if rt == "" { rt = "http" @@ -32,9 +30,9 @@ func run(ctx context.Context, logger *slog.Logger, h Handler) { panic(fmt.Sprintf("invalid RUNNER_TYPE provided: %q", rt)) } - r.Run(ctx, logger, h) + r(ctx, newHandlerFn) } -var runners = map[string]Runner{ - "http": new(runnerHTTP), +var runners = map[string]func(ctx context.Context, newHandlerFn func(context.Context, *slog.Logger) Handler){ + "http": runHTTP, } diff --git a/runner_http.go b/runner_http.go index 5d53498..1ba4572 100644 --- a/runner_http.go +++ b/runner_http.go @@ -24,11 +24,40 @@ const ( mb = 1 << 20 ) -type runnerHTTP struct{} +func runHTTP(ctx context.Context, newHandlerFn func(context.Context, *slog.Logger) Handler) { + logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true})) + + handler := newHandlerFn(ctx, logger) -func (r *runnerHTTP) Run(ctx context.Context, logger *slog.Logger, h Handler) { mux := http.NewServeMux() - mux.Handle("/", http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { + mux.Handle("/", dispatchReq(logger, handler)) + + s := &http.Server{ + Addr: fmt.Sprintf(":%d", port()), + Handler: mux, + MaxHeaderBytes: mb, + } + go func() { + select { + case <-ctx.Done(): + shutdownCtx, cancel := context.WithTimeout(context.Background(), 15*time.Second) + defer cancel() + + logger.Info("shutting down HTTP server...") + if err := s.Shutdown(shutdownCtx); err != nil { + logger.Error("failed to shutdown server", "err", err) + } + } + }() + + logger.Info("serving HTTP server on port " + strconv.Itoa(port())) + if err := s.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) { + logger.Error("unexpected shutdown of server", "err", err) + } +} + +func dispatchReq(logger *slog.Logger, handler Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { defer func() { if n, err := io.Copy(io.Discard, req.Body); err != nil { logger.Error("failed to drain request body", "err", err.Error(), "bytes_drained", n) @@ -54,9 +83,9 @@ func (r *runnerHTTP) Run(ctx context.Context, logger *slog.Logger, h Handler) { }() const ctxKeyTraceID = "_traceid" - ctx = context.WithValue(ctx, ctxKeyTraceID, r.TraceID) + ctx := context.WithValue(req.Context(), ctxKeyTraceID, r.TraceID) - resp := h.Handle(ctx, r) + resp := handler.Handle(ctx, r) if f, ok := resp.Body.(File); ok { f = NormalizeFile(f) @@ -94,30 +123,7 @@ func (r *runnerHTTP) Run(ctx context.Context, logger *slog.Logger, h Handler) { if err != nil { logger.Error("failed to write response", "err", err) } - })) - - s := &http.Server{ - Addr: fmt.Sprintf(":%d", port()), - Handler: mux, - MaxHeaderBytes: mb, - } - go func() { - select { - case <-ctx.Done(): - shutdownCtx, cancel := context.WithTimeout(context.Background(), 15*time.Second) - defer cancel() - - logger.Info("shutting down HTTP server...") - if err := s.Shutdown(shutdownCtx); err != nil { - logger.Error("failed to shutdown server", "err", err) - } - } - }() - - logger.Info("serving HTTP server on port " + strconv.Itoa(port())) - if err := s.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) { - logger.Error("unexpected shutdown of server", "err", err) - } + }) } func toRequest(req *http.Request) (Request, func() error, error) { diff --git a/runner_test.go b/runner_test.go index ad883cc..59ada46 100644 --- a/runner_test.go +++ b/runner_test.go @@ -7,6 +7,7 @@ import ( "encoding/json" "errors" "io" + "log/slog" "net" "net/http" "net/url" @@ -567,7 +568,7 @@ integer: 1`, ctx, cancel := context.WithCancel(context.Background()) defer cancel() - addr := newServer(ctx, t, func(ctx context.Context, cfg config) fdk.Handler { + addr := newServer(ctx, t, func(ctx context.Context, _ *slog.Logger, cfg config) fdk.Handler { return tt.newHandlerFn(ctx, cfg) }) @@ -720,7 +721,7 @@ integer: 1`, ctx, cancel := context.WithCancel(context.Background()) defer cancel() - addr := newServer(ctx, t, func(ctx context.Context, cfg config) fdk.Handler { + addr := newServer(ctx, t, func(ctx context.Context, _ *slog.Logger, cfg config) fdk.Handler { return tt.newHandlerFn(ctx, cfg) }) @@ -840,7 +841,7 @@ integer: 1`, ctx, cancel := context.WithCancel(context.Background()) defer cancel() - addr := newServer(ctx, t, func(ctx context.Context, cfg fdk.SkipCfg) fdk.Handler { + addr := newServer(ctx, t, func(ctx context.Context, _ *slog.Logger, cfg fdk.SkipCfg) fdk.Handler { return tt.newHandlerFn(ctx, cfg) }) @@ -1006,7 +1007,7 @@ integer: 1`, ctx, cancel := context.WithCancel(context.Background()) defer cancel() - addr := newServer(ctx, t, func(ctx context.Context, _ fdk.SkipCfg) fdk.Handler { + addr := newServer(ctx, t, func(ctx context.Context, _ *slog.Logger, _ fdk.SkipCfg) fdk.Handler { return tt.newHandlerFn(ctx) }) @@ -1250,7 +1251,7 @@ func decodeJSON(t testing.TB, b []byte, v any) { } } -func newServer[CFG fdk.Cfg](ctx context.Context, t *testing.T, newHandlerFn func(context.Context, CFG) fdk.Handler) string { +func newServer[CFG fdk.Cfg](ctx context.Context, t *testing.T, newHandlerFn func(context.Context, *slog.Logger, CFG) fdk.Handler) string { t.Helper() port := newIP(t) @@ -1261,8 +1262,8 @@ func newServer[CFG fdk.Cfg](ctx context.Context, t *testing.T, newHandlerFn func done := make(chan struct{}) go func() { defer close(done) - fdk.Run(ctx, func(ctx context.Context, cfg CFG) fdk.Handler { - h := newHandlerFn(ctx, cfg) + fdk.Run(ctx, func(ctx context.Context, logger *slog.Logger, cfg CFG) fdk.Handler { + h := newHandlerFn(ctx, logger, cfg) close(readyChan) return h }) diff --git a/sdk.go b/sdk.go index 1933ea8..9ecd47f 100644 --- a/sdk.go +++ b/sdk.go @@ -4,7 +4,6 @@ import ( "context" "log/slog" "net/http" - "os" "runtime/debug" ) @@ -14,25 +13,25 @@ type Handler interface { } // Run is the meat and potatoes. This is the entrypoint for everything. -func Run[T Cfg](ctx context.Context, newHandlerFn func(_ context.Context, cfg T) Handler) { - logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true})) - - var runFn Handler = HandlerFn(func(ctx context.Context, r Request) Response { - cfg, loadErr := readCfg[T](ctx) - if loadErr != nil { - if loadErr.err != nil { - logger.Error("failed to load config", "err", loadErr.err) +func Run[T Cfg](ctx context.Context, newHandlerFn func(context.Context, *slog.Logger, T) Handler) { + run(ctx, func(ctx context.Context, logger *slog.Logger) Handler { + var runFn Handler = HandlerFn(func(ctx context.Context, r Request) Response { + cfg, loadErr := readCfg[T](ctx) + if loadErr != nil { + if loadErr.err != nil { + logger.Error("failed to load config", "err", loadErr.err) + } + return ErrResp(loadErr.apiErr) } - return ErrResp(loadErr.apiErr) - } - h := newHandlerFn(ctx, cfg) + h := newHandlerFn(ctx, logger, cfg) - return h.Handle(ctx, r) - }) - runFn = recoverer(logger)(runFn) + return h.Handle(ctx, r) + }) + runFn = recoverer(logger)(runFn) - run(ctx, logger, runFn) + return runFn + }) } func recoverer(logger *slog.Logger) func(Handler) Handler {