Skip to content

Commit 12479d0

Browse files
authored
chore: Production-ready router (#196)
* chore: Set Gin mode to release by default * chore: Logger & latency middleware * chore: Improve API logger content * feat: Log error stacktrace * refactor: Request log fields * chore: Revert unnecessary change
1 parent 5274380 commit 12479d0

9 files changed

+276
-18
lines changed

internal/app/app.go

+3-1
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,9 @@ func (a *App) Run(ctx context.Context) error {
3434
}
3535

3636
func run(mainContext context.Context, cfg *config.Config) error {
37-
zapLogger, err := zap.NewProduction()
37+
zapConfig := zap.NewProductionConfig()
38+
zapConfig.Level = zap.NewAtomicLevelAt(zap.InfoLevel)
39+
zapLogger, err := zapConfig.Build()
3840
if err != nil {
3941
return err
4042
}

internal/config/config.go

+2
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@ type Config struct {
4242
APIPort int `yaml:"api_port" env:"API_PORT"`
4343
APIKey string `yaml:"api_key" env:"API_KEY"`
4444
APIJWTSecret string `yaml:"api_jwt_secret" env:"API_JWT_SECRET"`
45+
GinMode string `yaml:"gin_mode" env:"GIN_MODE"`
4546

4647
// Application
4748
AESEncryptionSecret string `yaml:"aes_encryption_secret" env:"AES_ENCRYPTION_SECRET"`
@@ -97,6 +98,7 @@ var (
9798
func (c *Config) InitDefaults() {
9899
c.APIPort = 3333
99100
c.OpenTelemetry = OpenTelemetryConfig{}
101+
c.GinMode = "release"
100102
c.Redis = RedisConfig{
101103
Host: "127.0.0.1",
102104
Port: 6379,

internal/services/api/api.go

+1
Original file line numberDiff line numberDiff line change
@@ -87,6 +87,7 @@ func NewService(ctx context.Context, wg *sync.WaitGroup, cfg *config.Config, log
8787
Topics: cfg.Topics,
8888
Registry: registry,
8989
PortalConfig: cfg.GetPortalConfig(),
90+
GinMode: cfg.GinMode,
9091
},
9192
logger,
9293
redisClient,

internal/services/api/errorhandler_middleware.go

+8-8
Original file line numberDiff line numberDiff line change
@@ -10,11 +10,10 @@ import (
1010
"github.com/gin-gonic/gin"
1111
"github.com/go-playground/validator/v10"
1212
"github.com/hookdeck/outpost/internal/destregistry"
13-
"github.com/uptrace/opentelemetry-go-extra/otelzap"
14-
"go.uber.org/zap"
13+
pkgerrors "github.com/pkg/errors"
1514
)
1615

17-
func ErrorHandlerMiddleware(logger *otelzap.Logger) gin.HandlerFunc {
16+
func ErrorHandlerMiddleware() gin.HandlerFunc {
1817
return func(c *gin.Context) {
1918
c.Next()
2019

@@ -25,10 +24,6 @@ func ErrorHandlerMiddleware(logger *otelzap.Logger) gin.HandlerFunc {
2524

2625
var errorResponse ErrorResponse
2726
errorResponse.Parse(err.Err)
28-
29-
if errorResponse.Code > 499 {
30-
logger.Ctx(c.Request.Context()).Error("internal server error", zap.Error(errorResponse.Err))
31-
}
3227
handleErrorResponse(c, errorResponse)
3328
}
3429
}
@@ -48,6 +43,7 @@ func (e *ErrorResponse) Parse(err error) {
4843
var errorResponse ErrorResponse
4944
if errors.As(err, &errorResponse) {
5045
*e = errorResponse
46+
e.Err = errorResponse.Err
5147
return
5248
}
5349

@@ -59,11 +55,13 @@ func (e *ErrorResponse) Parse(err error) {
5955
e.Code = -1
6056
e.Message = "validation error"
6157
e.Data = out
58+
e.Err = err
6259
return
6360
}
6461
if isInvalidJSON(err) {
6562
e.Code = http.StatusBadRequest
6663
e.Message = "invalid JSON"
64+
e.Err = err
6765
return
6866
}
6967

@@ -77,10 +75,12 @@ func (e *ErrorResponse) Parse(err error) {
7775
e.Code = http.StatusUnprocessableEntity
7876
e.Message = "validation error"
7977
e.Data = validationDetails
78+
e.Err = err
8079
return
8180
}
8281

8382
e.Message = err.Error()
83+
e.Err = err
8484
}
8585

8686
func isInvalidJSON(err error) bool {
@@ -98,7 +98,7 @@ func handleErrorResponse(c *gin.Context, response ErrorResponse) {
9898

9999
func NewErrInternalServer(err error) ErrorResponse {
100100
return ErrorResponse{
101-
Err: err,
101+
Err: pkgerrors.WithStack(err),
102102
Code: http.StatusInternalServerError,
103103
Message: "internal server error",
104104
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,28 @@
1+
package api
2+
3+
import (
4+
"time"
5+
6+
"github.com/gin-gonic/gin"
7+
)
8+
9+
const latencyContextKey = "latencymiddleware_duration"
10+
11+
func LatencyMiddleware() gin.HandlerFunc {
12+
return func(c *gin.Context) {
13+
start := time.Now()
14+
c.Next()
15+
duration := time.Since(start)
16+
c.Set(latencyContextKey, duration)
17+
}
18+
}
19+
20+
// GetRequestLatency returns the request latency from the context
21+
func GetRequestLatency(c *gin.Context) time.Duration {
22+
if v, exists := c.Get(latencyContextKey); exists {
23+
if duration, ok := v.(time.Duration); ok {
24+
return duration
25+
}
26+
}
27+
return 0
28+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,77 @@
1+
package api
2+
3+
import (
4+
"net/http"
5+
"net/http/httptest"
6+
"testing"
7+
"time"
8+
9+
"github.com/gin-gonic/gin"
10+
"github.com/stretchr/testify/assert"
11+
)
12+
13+
func TestMiddlewareOrder(t *testing.T) {
14+
gin.SetMode(gin.TestMode)
15+
16+
// Track middleware execution order
17+
var executionOrder []string
18+
var metricsLatency time.Duration
19+
var loggerLatency time.Duration
20+
21+
// Mock metrics middleware
22+
mockMetrics := func() gin.HandlerFunc {
23+
return func(c *gin.Context) {
24+
executionOrder = append(executionOrder, "metrics_start")
25+
c.Next()
26+
executionOrder = append(executionOrder, "metrics_end")
27+
metricsLatency = GetRequestLatency(c)
28+
}
29+
}
30+
31+
// Mock logger middleware
32+
mockLogger := func() gin.HandlerFunc {
33+
return func(c *gin.Context) {
34+
executionOrder = append(executionOrder, "logger_start")
35+
c.Next()
36+
executionOrder = append(executionOrder, "logger_end")
37+
loggerLatency = GetRequestLatency(c)
38+
}
39+
}
40+
41+
// Create router with our middleware order
42+
r := gin.New()
43+
r.Use(mockMetrics())
44+
r.Use(mockLogger())
45+
r.Use(LatencyMiddleware())
46+
47+
// Add a handler that sleeps to simulate work
48+
r.GET("/test", func(c *gin.Context) {
49+
executionOrder = append(executionOrder, "handler")
50+
time.Sleep(10 * time.Millisecond) // Simulate some work
51+
})
52+
53+
// Make request
54+
w := httptest.NewRecorder()
55+
req, _ := http.NewRequest("GET", "/test", nil)
56+
r.ServeHTTP(w, req)
57+
58+
// Verify execution order
59+
expectedOrder := []string{
60+
"metrics_start",
61+
"logger_start",
62+
"handler",
63+
"logger_end",
64+
"metrics_end",
65+
}
66+
assert.Equal(t, expectedOrder, executionOrder)
67+
68+
// Verify latency was captured
69+
assert.Greater(t, metricsLatency, time.Duration(0))
70+
assert.Greater(t, loggerLatency, time.Duration(0))
71+
72+
// Both middleware should see the same latency
73+
assert.Equal(t, metricsLatency, loggerLatency)
74+
75+
// Latency should be at least our sleep duration
76+
assert.GreaterOrEqual(t, metricsLatency, 10*time.Millisecond)
77+
}
+139
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,139 @@
1+
package api
2+
3+
import (
4+
"fmt"
5+
"math"
6+
"strings"
7+
"time"
8+
9+
"github.com/gin-gonic/gin"
10+
"github.com/pkg/errors"
11+
"github.com/uptrace/opentelemetry-go-extra/otelzap"
12+
"go.uber.org/zap"
13+
)
14+
15+
func LoggerMiddleware(logger *otelzap.Logger) gin.HandlerFunc {
16+
return func(c *gin.Context) {
17+
logger := logger.Ctx(c.Request.Context()).WithOptions(zap.AddStacktrace(zap.FatalLevel))
18+
c.Next()
19+
20+
fields := []zap.Field{}
21+
fields = append(fields, basicFields(c)...)
22+
fields = append(fields, pathFields(c)...)
23+
fields = append(fields, queryFields(c)...)
24+
fields = append(fields, errorFields(c)...)
25+
26+
if c.Writer.Status() >= 500 {
27+
logger.Error("request completed", fields...)
28+
} else {
29+
logger.Info("request completed", fields...)
30+
}
31+
}
32+
}
33+
34+
func basicFields(c *gin.Context) []zap.Field {
35+
return []zap.Field{
36+
zap.String("method", c.Request.Method),
37+
zap.Int("status", c.Writer.Status()),
38+
zap.Float64("latency_ms", math.Round(float64(GetRequestLatency(c))/float64(time.Millisecond)*100)/100),
39+
zap.String("client_ip", c.ClientIP()),
40+
}
41+
}
42+
43+
func pathFields(c *gin.Context) []zap.Field {
44+
rawPath := c.Request.URL.Path
45+
normalizedPath := rawPath
46+
params := make(map[string]string)
47+
for _, p := range c.Params {
48+
normalizedPath = strings.Replace(normalizedPath, p.Value, ":"+p.Key, 1)
49+
params[p.Key] = p.Value
50+
}
51+
52+
fields := []zap.Field{
53+
zap.String("path", normalizedPath),
54+
zap.String("raw_path", rawPath),
55+
}
56+
57+
if len(params) > 0 {
58+
fields = append(fields, zap.Any("params", params))
59+
}
60+
61+
return fields
62+
}
63+
64+
func queryFields(c *gin.Context) []zap.Field {
65+
if c.Request.URL.RawQuery == "" {
66+
return nil
67+
}
68+
return []zap.Field{
69+
zap.String("query", c.Request.URL.RawQuery),
70+
}
71+
}
72+
73+
func errorFields(c *gin.Context) []zap.Field {
74+
if len(c.Errors) == 0 {
75+
return nil
76+
}
77+
78+
err := c.Errors.Last().Err
79+
if c.Writer.Status() >= 500 {
80+
return getErrorFields(err)
81+
}
82+
return []zap.Field{
83+
zap.String("error", err.Error()),
84+
}
85+
}
86+
87+
func getErrorFields(err error) []zap.Field {
88+
var originalErr error
89+
90+
// If it's our ErrorResponse, get the inner error
91+
if errResp, ok := err.(ErrorResponse); ok {
92+
err = errResp.Err
93+
}
94+
95+
// Keep the wrapped error for stack trace but get original for type/message
96+
wrappedErr := err
97+
if cause := errors.Unwrap(err); cause != nil {
98+
originalErr = cause
99+
} else {
100+
originalErr = err
101+
}
102+
103+
fields := []zap.Field{
104+
zap.String("error", originalErr.Error()),
105+
zap.String("error_type", fmt.Sprintf("%T", originalErr)),
106+
}
107+
108+
// Get the stack trace from the wrapped error
109+
type stackTracer interface {
110+
StackTrace() errors.StackTrace
111+
}
112+
var st stackTracer
113+
if errors.As(wrappedErr, &st) {
114+
trace := fmt.Sprintf("%+v", st.StackTrace())
115+
lines := strings.Split(trace, "\n")
116+
var filtered []string
117+
118+
for i := 0; i < len(lines); i++ {
119+
line := lines[i]
120+
if strings.Contains(line, "github.com/hookdeck/outpost") {
121+
filtered = append(filtered, line)
122+
// Include the next line if it's a file path
123+
if i+1 < len(lines) && strings.HasPrefix(lines[i+1], "\t") {
124+
filtered = append(filtered, lines[i+1])
125+
}
126+
// Stop at the first handler
127+
if strings.Contains(line, "Handler") {
128+
break
129+
}
130+
}
131+
}
132+
133+
if len(filtered) > 0 {
134+
fields = append(fields, zap.String("error_trace", strings.Join(filtered, "\n")))
135+
}
136+
}
137+
138+
return fields
139+
}

internal/services/api/metrics_middleware.go

+2-4
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,6 @@
11
package api
22

33
import (
4-
"time"
5-
64
"github.com/gin-gonic/gin"
75
"github.com/hookdeck/outpost/internal/emetrics"
86
)
@@ -13,13 +11,13 @@ func MetricsMiddleware() gin.HandlerFunc {
1311
panic(err)
1412
}
1513
return func(c *gin.Context) {
16-
start := time.Now()
1714
defer func() {
15+
latency := GetRequestLatency(c)
1816
emeter.APICalls(c.Request.Context(), emetrics.APICallsOpts{
1917
Method: c.Request.Method,
2018
Path: c.FullPath(),
2119
})
22-
emeter.APIResponseLatency(c.Request.Context(), time.Since(start), emetrics.APIResponseLatencyOpts{
20+
emeter.APIResponseLatency(c.Request.Context(), latency, emetrics.APIResponseLatencyOpts{
2321
Method: c.Request.Method,
2422
Path: c.FullPath(),
2523
})

0 commit comments

Comments
 (0)