Support custom types

TODO.md

@@ -1,3 +1,8 @@
 # TODO
 
-- [ ] Unit tests
+- [ ] Pattern for extending config
+
+## Done
+- [x] Unit tests
+- [x] HTTP Logging Middleware
+- [x] Fix panic with OTEL disabled

pkg/app/setup.go

@@ -23,3 +23,10 @@ func MustSetupConfigAndLogging(ctx context.Context) context.Context {
 	zerolog.Ctx(ctx).Trace().Any("config", *cfg).Send()
 	return ctx
 }
+
+// Unmarshal config into a custom type
+// Type MUST include *config.AppConfig
+// Stored in context as *config.AppConfig but can be asserted back
+func MustSetupConfigAndLoggingInto[T any](ctx context.Context, into T) (context.Context, T) {
+	return ctx, into
+}

pkg/app/setup_custom.go

@@ -0,0 +1,107 @@
+package app
+
+import (
+	"context"
+	"errors"
+	"flag"
+	"fmt"
+	"os"
+	"reflect"
+
+	"gopkg.in/yaml.v3"
+
+	"gitea.libretechconsulting.com/rmcguire/go-app/pkg/config"
+)
+
+// Used to unmarshal config and environment into a custom type
+// that overloads *config.AppConfig. Will perform normal env
+// substitutions for AppConfig, but env overrides for custom type
+// are up to the caller.
+func MustLoadConfigInto[T any](ctx context.Context, into T) (context.Context, T) {
+	// Step 1: Check our custom type for required *config.AppConfig
+	if err := hasAppConfig(into); err != nil {
+		panic(err)
+	}
+
+	// Step 2: Do the normal thing
+	ctx = MustSetupConfigAndLogging(ctx)
+
+	// Step 3: Extract the config
+	cfg := config.MustFromCtx(ctx)
+
+	// Step 4: Unmarshal custom config
+	configPath := flag.Lookup("config")
+	if configPath != nil && configPath.Value.String() != "" {
+		file, err := os.Open(configPath.Value.String())
+		if err != nil {
+			panic(fmt.Errorf("could not open config file: %w", err))
+		}
+		defer file.Close()
+
+		decoder := yaml.NewDecoder(file)
+		if err := decoder.Decode(into); err != nil {
+			panic(fmt.Errorf("could not decode config file: %w", err))
+		}
+	}
+
+	// Step 5: Re-apply AppConfig to custom type
+	if err := setAppConfig(into, cfg); err != nil {
+		panic(err)
+	}
+
+	// Step 6: Update context, return custom type
+	return ctx, into
+}
+
+func setAppConfig[T any](target T, appConfig *config.AppConfig) error {
+	// Ensure target is a pointer to a struct
+	v := reflect.ValueOf(target)
+	if v.Kind() != reflect.Ptr || v.IsNil() {
+		return errors.New("target must be a non-nil pointer to a struct")
+	}
+
+	v = v.Elem() // Dereference the pointer
+	if v.Kind() != reflect.Struct {
+		return errors.New("target must be a pointer to a struct")
+	}
+
+	// Replace *config.AppConfig
+	for i := 0; i < v.NumField(); i++ {
+		field := v.Field(i)
+		if field.Type() == reflect.TypeOf((*config.AppConfig)(nil)) {
+			if !field.CanSet() {
+				return fmt.Errorf("field %q cannot be set", v.Type().Field(i).Name)
+			}
+			field.Set(reflect.ValueOf(appConfig))
+			return nil
+		}
+	}
+
+	return errors.New("no *config.AppConfig field found in target struct")
+}
+
+func hasAppConfig[T any](target T) error {
+	v := reflect.ValueOf(target)
+	if v.Kind() != reflect.Ptr || v.IsNil() {
+		return errors.New("target must be a non-nil pointer to a struct")
+	}
+	v = v.Elem()
+
+	if v.Kind() != reflect.Struct {
+		return errors.New("target must be a pointer to a struct")
+	}
+
+	hasAppConfig := false
+	for i := 0; i < v.NumField(); i++ {
+		field := v.Type().Field(i)
+		if field.Type == reflect.TypeOf((*config.AppConfig)(nil)) {
+			hasAppConfig = true
+			break
+		}
+	}
+	if !hasAppConfig {
+		return errors.New("struct does not contain a *config.AppConfig field")
+	}
+
+	return nil
+}

pkg/app/setup_test.go

@@ -0,0 +1,123 @@
+package app
+
+import (
+	"bufio"
+	"context"
+	"flag"
+	"io"
+	"os"
+	"regexp"
+	"testing"
+
+	"github.com/rs/zerolog"
+
+	"gitea.libretechconsulting.com/rmcguire/go-app/pkg/config"
+)
+
+func TestMustSetupConfigAndLogging(t *testing.T) {
+	// Configure app and logger
+	type inputs struct {
+		envs map[string]string
+	}
+	type outputs struct {
+		appName        string
+		logLevel       zerolog.Level
+		logRegexChecks []*regexp.Regexp
+	}
+	tests := []struct {
+		name   string
+		inputs inputs
+		want   outputs
+	}{
+		{
+			name: "Test json logging with short timestamp",
+			inputs: inputs{
+				envs: map[string]string{
+					"APP_NAME":            "testapp",
+					"APP_LOG_LEVEL":       "warn",
+					"APP_LOG_FORMAT":      "json",
+					"APP_LOG_TIME_FORMAT": "short",
+				},
+			},
+			want: outputs{
+				appName:  "testapp",
+				logLevel: zerolog.WarnLevel,
+				logRegexChecks: []*regexp.Regexp{
+					regexp.MustCompile(`^\{.*time":"\d{1,}:\d{2}`),
+				},
+			},
+		},
+		{
+			name: "Test json logging with unix timestamp",
+			inputs: inputs{
+				envs: map[string]string{
+					"APP_NAME":            "testapp",
+					"APP_LOG_LEVEL":       "info",
+					"APP_LOG_FORMAT":      "json",
+					"APP_LOG_TIME_FORMAT": "unix",
+				},
+			},
+			want: outputs{
+				appName:  "testapp",
+				logLevel: zerolog.InfoLevel,
+				logRegexChecks: []*regexp.Regexp{
+					regexp.MustCompile(`time":\d+,`),
+				},
+			},
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			// Set environment variables
+			for key, val := range tt.inputs.envs {
+				os.Setenv(key, val)
+			}
+
+			// Prepare config in context
+			ctx := MustSetupConfigAndLogging(context.Background())
+
+			// Retrieve config and logger from prepared context
+			cfg := config.MustFromCtx(ctx)
+			logger := zerolog.Ctx(ctx)
+
+			// Check wants
+			if cfg.Name != tt.want.appName {
+				t.Errorf("Expected app name %s, got %s", tt.want.appName, cfg.Name)
+			}
+			if logger.GetLevel() != tt.want.logLevel {
+				t.Errorf("Expected log level %#v, got %#v", tt.want.logLevel, logger.GetLevel())
+			}
+
+			// Send and capture a log
+			r, w := io.Pipe()
+			testLogger := logger.Output(w)
+			scanner := bufio.NewScanner(r)
+
+			go func() {
+				testLogger.Error().Msg("test message")
+				w.Close()
+			}()
+
+			logOut := make([]byte, 0)
+			if scanner.Scan() {
+				logOut = scanner.Bytes()
+			}
+
+			// Check all expressions
+			for _, expr := range tt.want.logRegexChecks {
+				if !expr.Match(logOut) {
+					t.Errorf("Regex %s did not match log %s", expr.String(), logOut)
+				}
+			}
+
+			// Super annoying need to reset due to app framework package
+			// using flag.Parse() and go test also using it
+			testlog := flag.Lookup("test.testlogfile").Value.String()
+			flag.CommandLine = flag.NewFlagSet(os.Args[0], flag.ExitOnError)
+			flag.String("test.testlogfile", testlog, "")
+			flag.String("test.paniconexit0", "", "")
+			flag.String("test.v", "", "")
+			flag.Parse()
+		})
+	}
+}

pkg/config/config_test.go

@@ -0,0 +1,81 @@
+package config
+
+import (
+	"encoding/json"
+	"testing"
+)
+
+// Changing defaults could be a breaking change,
+// if this needs to be modified to pass the test,
+// an item should be added to the changelog.
+//
+// This should be maintained, as it is the primary
+// interface between an app and the app framework.
+var testDefaultConfig = &AppConfig{
+	Environment: "development",
+	Version:     getVersion(),
+	Logging: &LogConfig{
+		Enabled:    true,
+		Level:      "info",
+		Format:     LogFormatJSON,
+		Output:     "stderr",
+		TimeFormat: TimeFormatLong,
+	},
+	HTTP: &HTTPConfig{
+		Listen:       "127.0.0.1:8080",
+		LogRequests:  false,
+		ReadTimeout:  "10s",
+		WriteTimeout: "10s",
+		IdleTimeout:  "1m",
+	},
+	OTEL: &OTELConfig{
+		Enabled:            true,
+		PrometheusEnabled:  true,
+		PrometheusPath:     "/metrics",
+		StdoutEnabled:      false,
+		MetricIntervalSecs: 30,
+	},
+}
+
+func Test_loadConfig(t *testing.T) {
+	type args struct {
+		configPath string
+	}
+	tests := []struct {
+		name    string
+		args    args
+		want    *AppConfig
+		wantErr bool
+	}{
+		{
+			name:    "Ensure defaults",
+			args:    args{configPath: ""},
+			want:    testDefaultConfig,
+			wantErr: false,
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			got, err := loadConfig(tt.args.configPath)
+			if (err != nil) != tt.wantErr {
+				t.Errorf("loadConfig() error = %v, wantErr %v", err, tt.wantErr)
+				return
+			}
+
+			// Marshal both the expected and actual structs to JSON
+			gotJSON, err := json.Marshal(got)
+			if err != nil {
+				t.Fatalf("Failed to marshal got to JSON: %v", err)
+			}
+			wantJSON, err := json.Marshal(tt.want)
+			if err != nil {
+				t.Fatalf("Failed to marshal want to JSON: %v", err)
+			}
+
+			// Compare the JSON strings
+			if string(gotJSON) != string(wantJSON) {
+				t.Errorf("loadConfig() JSON = %s, want JSON = %s", string(gotJSON), string(wantJSON))
+			}
+		})
+	}
+}

pkg/config/ctx_test.go

@@ -0,0 +1,43 @@
+package config
+
+import (
+	"context"
+	"testing"
+)
+
+func TestFromCtx(t *testing.T) {
+	app := &AppConfig{
+		Name: "testapp",
+	}
+	appCtx := app.AddToCtx(context.Background())
+
+	type args struct {
+		ctx context.Context
+	}
+
+	tests := []struct {
+		name    string
+		args    args
+		wantErr bool
+	}{
+		{
+			name:    "Unprepared app context",
+			args:    args{ctx: context.Background()},
+			wantErr: true,
+		},
+		{
+			name:    "Prepared app context",
+			args:    args{ctx: appCtx},
+			wantErr: false,
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			_, err := FromCtx(tt.args.ctx)
+			if (err != nil) != tt.wantErr {
+				t.Errorf("FromCtx() error = %v, wantErr %v", err, tt.wantErr)
+				return
+			}
+		})
+	}
+}

pkg/config/types.go

@@ -15,6 +15,7 @@ var DefaultConfig = &AppConfig{
 	},
 	HTTP: &HTTPConfig{
 		Listen:       "127.0.0.1:8080",
+		LogRequests:  false,
 		ReadTimeout:  "10s",
 		WriteTimeout: "10s",
 		IdleTimeout:  "1m",
@@ -76,6 +77,7 @@ const (
 // HTTP Configuration
 type HTTPConfig struct {
 	Listen       string `yaml:"listen,omitempty" env:"APP_HTTP_LISTEN"`
+	LogRequests  bool   `yaml:"logRequests" env:"APP_HTTP_LOG_REQUESTS"`
 	ReadTimeout  string `yaml:"readTimeout" env:"APP_HTTP_READ_TIMEOUT"`   // Go duration (e.g. 10s)
 	WriteTimeout string `yaml:"writeTimeout" env:"APP_HTTP_WRITE_TIMEOUT"` // Go duration (e.g. 10s)
 	IdleTimeout  string `yaml:"idleTimeout" env:"APP_HTTP_IDLE_TIMEOUT"`   // Go duration (e.g. 10s)

pkg/otel/otel.go

@@ -46,6 +46,11 @@ func Init(ctx context.Context) (context.Context, func(context.Context) error) {
 	if !cfg.OTEL.Enabled {
 		opentelemetry.SetMeterProvider(noopMetric.NewMeterProvider())
 		opentelemetry.SetTracerProvider(noop.NewTracerProvider())
+		// Won't function with noop providers
+		meter := opentelemetry.Meter(cfg.Name)
+		ctx = AddMeterToCtx(ctx, meter)
+		tracer := opentelemetry.Tracer(cfg.Name)
+		ctx = AddTracerToCtx(ctx, tracer)
 		return ctx, func(context.Context) error {
 			return nil
 		}
@@ -62,12 +67,12 @@ func Init(ctx context.Context) (context.Context, func(context.Context) error) {
 	if cfg.OTEL.StdoutEnabled {
 		options = append(options, EnableStdoutExporter)
 	}
-	if cfg.OTEL.MetricIntervalSecs > 0 {
-		metricInterval = time.Duration(cfg.OTEL.MetricIntervalSecs) * time.Second
-	}
 	if cfg.OTEL.PrometheusEnabled {
 		options = append(options, EnablePrometheusExporter)
 	}
+	if cfg.OTEL.MetricIntervalSecs > 0 {
+		metricInterval = time.Duration(cfg.OTEL.MetricIntervalSecs) * time.Second
+	}
 	options = append(options,
 		WithMetricExportInterval(metricInterval))
 

pkg/srv/http.go

@@ -89,6 +89,11 @@ func prepHTTPServer(ctx context.Context, handleFuncs []HTTPFunc, hcFuncs ...Heal
 		idleTimeout = *iT
 	}
 
+	// Inject logging middleware
+	if cfg.HTTP.LogRequests {
+		handler = loggingMiddleware(ctx, handler)
+	}
+
 	return &http.Server{
 		Addr:         cfg.HTTP.Listen,
 		ReadTimeout:  readTimeout,

pkg/srv/http_log.go

@@ -0,0 +1,87 @@
+package srv
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"net/http"
+	"regexp"
+	"time"
+
+	"github.com/rs/zerolog"
+)
+
+var ExcludeFromLogging = regexp.MustCompile(`\/(ready|live|metrics)$`)
+
+type LoggingResponseWriter struct {
+	http.ResponseWriter
+	statusCode int
+	body       *bytes.Buffer
+}
+
+func loggingMiddleware(appCtx context.Context, next http.Handler) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		if ExcludeFromLogging.Match([]byte(r.URL.Path)) {
+			next.ServeHTTP(w, r)
+			return
+		}
+
+		log := zerolog.Ctx(appCtx)
+
+		start := time.Now()
+		lrr := newLoggingResponseWriter(w)
+		next.ServeHTTP(lrr, r)
+
+		log.Debug().
+			Str("path", r.URL.Path).
+			Any("query", r.URL.Query()).
+			Int("statusCode", lrr.statusCode).
+			Str("protocol", r.Proto).
+			Str("remote", r.RemoteAddr).
+			Dur("duration", time.Since(start)).
+			Msg("http request served")
+
+		// Log response body
+		trcLog := log.Trace().
+			Str("path", r.URL.Path).
+			Int("statusCode", lrr.statusCode)
+
+		// Check if it's JSON
+		firstByte, err := lrr.body.ReadByte()
+		if err != nil {
+			trcLog.Err(errors.New("invalid response body")).Send()
+			return
+		}
+		lrr.body.UnreadByte()
+
+		if firstByte == '{' {
+			trcLog = trcLog.RawJSON("response", lrr.body.Bytes())
+		} else {
+			trcLog = trcLog.Bytes("response", lrr.body.Bytes())
+		}
+		trcLog.Msg("response payload")
+	})
+}
+
+// Implement Flush to support the http.Flusher interface
+func (w *LoggingResponseWriter) Flush() {
+	if flusher, ok := w.ResponseWriter.(http.Flusher); ok {
+		flusher.Flush()
+	}
+}
+
+func (w *LoggingResponseWriter) WriteHeader(code int) {
+	w.statusCode = code
+	w.ResponseWriter.WriteHeader(code)
+}
+
+func (w *LoggingResponseWriter) Write(b []byte) (int, error) {
+	w.body.Write(b)
+	return w.ResponseWriter.Write(b)
+}
+
+func newLoggingResponseWriter(w http.ResponseWriter) *LoggingResponseWriter {
+	return &LoggingResponseWriter{
+		ResponseWriter: w, statusCode: http.StatusOK, body: bytes.NewBuffer(nil),
+	}
+}