Merge pull request #33 from CrowdStrike/fix/log_routing

fix: update newHandlerFn to take a logger to canonicalize logging for system integration

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
 }
 
 ```

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{

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{

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{

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,
 }

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) {

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
 		})