Skip to content

Commit 3561e79

Browse files
veeceeyclaude
andauthored
Replace logrus with stdlib log/slog (#655)
* Replace logrus with stdlib log/slog for structured logging Migrate the entire codebase from github.com/sirupsen/logrus to Go's standard library log/slog package. This introduces proper structured logging with key-value pairs and adds LOG_LEVEL environment variable support (debug, info, warn, error) for runtime log level configuration. Key changes: - Replace logging.Logger interface with type alias to *slog.Logger - Add ParseLevel() and NewLogger() helpers in pkg/logging - Add NewWriter() to replace logrus.Logger.Writer() for subprocess output capture - Update backends.Logger interface to use slog-compatible signatures - Convert all log calls from printf-style to structured key-value pairs - Remove direct logrus dependency (remains as indirect via transitive deps) Closes #384 * Convert all fmt.Sprintf log calls to slog structured key-value pairs Address review feedback: replace fmt.Sprintf anti-pattern across the entire codebase with proper slog structured key-value args so log aggregation tools can parse/filter/query individual fields. Also fixes: - t.Error(fmt.Sprintf(...)) -> t.Errorf(...) (staticcheck S1038) - Import ordering (gci: standard first, then third-party) - Race condition in testregistry (concurrent map access in handleBlobUpload) - Removed unused fmt imports * Fix lint: gci import ordering and staticcheck S1038 Sort stdlib imports alphabetically in main.go, remove unused fmt import and trailing blank line in scheduler_test.go, and replace t.Error(fmt.Sprintf(...)) with t.Errorf(...) in test files. * Address reviewer feedback: restore Fatal exit behavior, fix structured logging - Add os.Exit(1) after log.Error where log.Fatal was originally used (prevents app from continuing with nil backends/listeners) - Convert all remaining fmt.Sprintf log calls to proper slog key-value pairs for structured logging benefits - Restore createLlamaCppConfigFromEnv Fatal exit behavior via exitFunc - Fix test assertions: restore t.Fatalf for setup errors, use t.Errorf for assertion checks - Fix gci import ordering (log/slog in correct alphabetical position) - Remove trailing newlines from log messages * fix: resolve rebase conflicts - convert new upstream logrus calls to slog Convert new logrus-style logging calls (Infof, Errorf, Warnf, Infoln) added in upstream to slog structured logging pattern. Fix go.mod dependencies and test file imports after rebase onto latest main. * fix: resolve rebase conflicts, lint and test fixes after slog migration - Fixed import ordering (gci) in select_backend_test.go - Fixed tc.log -> c.log typo in client.go - Moved logrus from direct to indirect dependency in go.mod - All tests pass, go vet clean, golangci-lint passes Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.6 <noreply@anthropic.com>
1 parent c0d3c09 commit 3561e79

39 files changed

+436
-401
lines changed

go.mod

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,6 @@ require (
3030
github.com/pkg/errors v0.9.1
3131
github.com/prometheus/client_model v0.6.2
3232
github.com/prometheus/common v0.67.5
33-
github.com/sirupsen/logrus v1.9.4
3433
github.com/spf13/cobra v1.10.2
3534
github.com/spf13/pflag v1.0.10
3635
github.com/stretchr/testify v1.11.1
@@ -116,6 +115,7 @@ require (
116115
github.com/rivo/uniseg v0.4.7 // indirect
117116
github.com/russross/blackfriday/v2 v2.1.0 // indirect
118117
github.com/shirou/gopsutil/v4 v4.25.6 // indirect
118+
github.com/sirupsen/logrus v1.9.3 // indirect
119119
github.com/smallnest/ringbuffer v0.0.0-20241116012123-461381446e3d // indirect
120120
github.com/tklauser/go-sysconf v0.3.12 // indirect
121121
github.com/tklauser/numcpus v0.6.1 // indirect

go.sum

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -255,8 +255,8 @@ github.com/russross/blackfriday/v2 v2.1.0 h1:JIOH55/0cWyOuilr9/qlrm0BSXldqnqwMsf
255255
github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
256256
github.com/shirou/gopsutil/v4 v4.25.6 h1:kLysI2JsKorfaFPcYmcJqbzROzsBWEOAtw6A7dIfqXs=
257257
github.com/shirou/gopsutil/v4 v4.25.6/go.mod h1:PfybzyydfZcN+JMMjkF6Zb8Mq1A/VcogFFg7hj50W9c=
258-
github.com/sirupsen/logrus v1.9.4 h1:TsZE7l11zFCLZnZ+teH4Umoq5BhEIfIzfRDZ1Uzql2w=
259-
github.com/sirupsen/logrus v1.9.4/go.mod h1:ftWc9WdOfJ0a92nsE2jF5u5ZwH8Bv2zdeOC42RjbV2g=
258+
github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
259+
github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
260260
github.com/smallnest/ringbuffer v0.0.0-20241116012123-461381446e3d h1:3VwvTjiRPA7cqtgOWddEL+JrcijMlXUmj99c/6YyZoY=
261261
github.com/smallnest/ringbuffer v0.0.0-20241116012123-461381446e3d/go.mod h1:tAG61zBM1DYRaGIPloumExGvScf08oHuo0kFoOqdbT0=
262262
github.com/spf13/cobra v1.10.2 h1:DMTTonx5m65Ic0GOoRY2c16WCbHxOOw6xxezuLaBpcU=
@@ -268,6 +268,7 @@ github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+
268268
github.com/stretchr/objx v0.5.2 h1:xuMeJ0Sdp5ZMRXx/aWO6RZxdr3beISkG5/G/aIRr3pY=
269269
github.com/stretchr/objx v0.5.2/go.mod h1:FRsXN1f5AsAjCGJKqEizvkpNtU+EGNCLh3NxZ/8L+MA=
270270
github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
271+
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
271272
github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U=
272273
github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U=
273274
github.com/testcontainers/testcontainers-go v0.40.0 h1:pSdJYLOVgLE8YdUY2FHQ1Fxu+aMnb6JfVz1mxk7OeMU=
@@ -351,6 +352,7 @@ golang.org/x/sys v0.0.0-20190916202348-b4ddaad3f8a3/go.mod h1:h1NjWce9XRLGQEsW7w
351352
golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
352353
golang.org/x/sys v0.0.0-20201204225414-ed752295db88/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
353354
golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
355+
golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
354356
golang.org/x/sys v0.0.0-20220908164124-27713097b956/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
355357
golang.org/x/sys v0.1.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
356358
golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
@@ -391,6 +393,7 @@ gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntN
391393
gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q=
392394
gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7 h1:uRGJdciOHaEIrze2W8Q3AKkepLTh2hOroT7a+7czfdQ=
393395
gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7/go.mod h1:dt/ZhP58zS4L8KSrWDmTeBkI65Dw0HsyUHuEVlX15mw=
396+
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
394397
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
395398
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
396399
gotest.tools/v3 v3.5.2 h1:7koQfIKdy+I8UTetycgUqXWSDwpgv193Ka+qRsmBY8Q=

main.go

Lines changed: 58 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,8 @@ import (
44
"context"
55
"crypto/tls"
66
"encoding/json"
7+
"fmt"
8+
"log/slog"
79
"net"
810
"net/http"
911
"os"
@@ -19,25 +21,34 @@ import (
1921
"github.com/docker/model-runner/pkg/inference/backends/sglang"
2022
"github.com/docker/model-runner/pkg/inference/config"
2123
"github.com/docker/model-runner/pkg/inference/models"
24+
"github.com/docker/model-runner/pkg/logging"
2225
"github.com/docker/model-runner/pkg/metrics"
2326
"github.com/docker/model-runner/pkg/routing"
2427
modeltls "github.com/docker/model-runner/pkg/tls"
25-
"github.com/sirupsen/logrus"
2628
)
2729

2830
const (
2931
// DefaultTLSPort is the default TLS port for Moby
3032
DefaultTLSPort = "12444"
3133
)
3234

33-
var log = logrus.New()
35+
// initLogger creates the application logger based on LOG_LEVEL env var.
36+
func initLogger() *slog.Logger {
37+
level := logging.ParseLevel(os.Getenv("LOG_LEVEL"))
38+
return logging.NewLogger(level)
39+
}
40+
41+
var log = initLogger()
3442

3543
// Log is the logger used by the application, exported for testing purposes.
3644
var Log = log
3745

3846
// testLog is a test-override logger used by createLlamaCppConfigFromEnv.
3947
var testLog = log
4048

49+
// exitFunc is used for Fatal-like exits; overridden in tests.
50+
var exitFunc = func(code int) { os.Exit(code) }
51+
4152
func main() {
4253
ctx, cancel := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM)
4354
defer cancel()
@@ -49,7 +60,8 @@ func main() {
4960

5061
userHomeDir, err := os.UserHomeDir()
5162
if err != nil {
52-
log.Fatalf("Failed to get user home directory: %v", err)
63+
log.Error("Failed to get user home directory", "error", err)
64+
exitFunc(1)
5365
}
5466

5567
modelPath := os.Getenv("MODELS_PATH")
@@ -91,18 +103,18 @@ func main() {
91103
}
92104
baseTransport.Proxy = http.ProxyFromEnvironment
93105

94-
log.Infof("LLAMA_SERVER_PATH: %s", llamaServerPath)
106+
log.Info("LLAMA_SERVER_PATH", "path", llamaServerPath)
95107
if vllmServerPath != "" {
96-
log.Infof("VLLM_SERVER_PATH: %s", vllmServerPath)
108+
log.Info("VLLM_SERVER_PATH", "path", vllmServerPath)
97109
}
98110
if sglangServerPath != "" {
99-
log.Infof("SGLANG_SERVER_PATH: %s", sglangServerPath)
111+
log.Info("SGLANG_SERVER_PATH", "path", sglangServerPath)
100112
}
101113
if mlxServerPath != "" {
102-
log.Infof("MLX_SERVER_PATH: %s", mlxServerPath)
114+
log.Info("MLX_SERVER_PATH", "path", mlxServerPath)
103115
}
104116
if vllmMetalServerPath != "" {
105-
log.Infof("VLLM_METAL_SERVER_PATH: %s", vllmMetalServerPath)
117+
log.Info("VLLM_METAL_SERVER_PATH", "path", vllmMetalServerPath)
106118
}
107119

108120
// Create llama.cpp configuration from environment variables
@@ -119,7 +131,7 @@ func main() {
119131
Log: log,
120132
ClientConfig: models.ClientConfig{
121133
StoreRootPath: modelPath,
122-
Logger: log.WithFields(logrus.Fields{"component": "model-manager"}),
134+
Logger: log.With("component", "model-manager"),
123135
Transport: baseTransport,
124136
},
125137
Backends: append(
@@ -135,26 +147,27 @@ func main() {
135147
VLLMMetalPath: vllmMetalServerPath,
136148
}),
137149
routing.BackendDef{Name: sglang.Name, Init: func(mm *models.Manager) (inference.Backend, error) {
138-
return sglang.New(log, mm, log.WithFields(logrus.Fields{"component": sglang.Name}), nil, sglangServerPath)
150+
return sglang.New(log, mm, log.With("component", sglang.Name), nil, sglangServerPath)
139151
}},
140152
routing.BackendDef{Name: diffusers.Name, Init: func(mm *models.Manager) (inference.Backend, error) {
141-
return diffusers.New(log, mm, log.WithFields(logrus.Fields{"component": diffusers.Name}), nil, diffusersServerPath)
153+
return diffusers.New(log, mm, log.With("component", diffusers.Name), nil, diffusersServerPath)
142154
}},
143155
),
144156
OnBackendError: func(name string, err error) {
145-
log.Fatalf("unable to initialize %s backend: %v", name, err)
157+
log.Error("unable to initialize backend", "backend", name, "error", err)
158+
exitFunc(1)
146159
},
147160
DefaultBackendName: llamacpp.Name,
148161
HTTPClient: http.DefaultClient,
149162
MetricsTracker: metrics.NewTracker(
150163
http.DefaultClient,
151-
log.WithField("component", "metrics"),
164+
log.With("component", "metrics"),
152165
"",
153166
false,
154167
),
155168
IncludeResponsesAPI: true,
156169
ExtraRoutes: func(r *routing.NormalizedServeMux, s *routing.Service) {
157-
// Root handler only catches exact "/" requests
170+
// Root handler - only catches exact "/" requests
158171
r.HandleFunc("/", func(w http.ResponseWriter, req *http.Request) {
159172
if req.URL.Path != "/" {
160173
http.NotFound(w, req)
@@ -168,14 +181,14 @@ func main() {
168181
r.HandleFunc("/version", func(w http.ResponseWriter, req *http.Request) {
169182
w.Header().Set("Content-Type", "application/json")
170183
if err := json.NewEncoder(w).Encode(map[string]string{"version": Version}); err != nil {
171-
log.Warnf("failed to write version response: %v", err)
184+
log.Warn("failed to write version response", "error", err)
172185
}
173186
})
174187

175188
// Metrics endpoint
176189
if os.Getenv("DISABLE_METRICS") != "1" {
177190
metricsHandler := metrics.NewAggregatedMetricsHandler(
178-
log.WithField("component", "metrics"),
191+
log.With("component", "metrics"),
179192
s.SchedulerHTTP,
180193
)
181194
r.Handle("/metrics", metricsHandler)
@@ -186,7 +199,8 @@ func main() {
186199
},
187200
})
188201
if err != nil {
189-
log.Fatalf("failed to initialize service: %v", err)
202+
log.Error("failed to initialize service", "error", err)
203+
exitFunc(1)
190204
}
191205

192206
server := &http.Server{
@@ -204,7 +218,7 @@ func main() {
204218
if tcpPort != "" {
205219
// Use TCP port
206220
addr := ":" + tcpPort
207-
log.Infof("Listening on TCP port %s", tcpPort)
221+
log.Info("Listening on TCP port", "port", tcpPort)
208222
server.Addr = addr
209223
go func() {
210224
serverErrors <- server.ListenAndServe()
@@ -213,12 +227,14 @@ func main() {
213227
// Use Unix socket
214228
if err := os.Remove(sockName); err != nil {
215229
if !os.IsNotExist(err) {
216-
log.Fatalf("Failed to remove existing socket: %v", err)
230+
log.Error("Failed to remove existing socket", "error", err)
231+
exitFunc(1)
217232
}
218233
}
219234
ln, err := net.ListenUnix("unix", &net.UnixAddr{Name: sockName, Net: "unix"})
220235
if err != nil {
221-
log.Fatalf("Failed to listen on socket: %v", err)
236+
log.Error("Failed to listen on socket", "error", err)
237+
exitFunc(1)
222238
}
223239
go func() {
224240
serverErrors <- server.Serve(ln)
@@ -243,19 +259,22 @@ func main() {
243259
var err error
244260
certPath, keyPath, err = modeltls.EnsureCertificates("", "")
245261
if err != nil {
246-
log.Fatalf("Failed to ensure TLS certificates: %v", err)
262+
log.Error("Failed to ensure TLS certificates", "error", err)
263+
exitFunc(1)
247264
}
248-
log.Infof("Using TLS certificate: %s", certPath)
249-
log.Infof("Using TLS key: %s", keyPath)
265+
log.Info("Using TLS certificate", "cert", certPath)
266+
log.Info("Using TLS key", "key", keyPath)
250267
} else {
251-
log.Fatal("TLS enabled but no certificate provided and auto-cert is disabled")
268+
log.Error("TLS enabled but no certificate provided and auto-cert is disabled")
269+
exitFunc(1)
252270
}
253271
}
254272

255273
// Load TLS configuration
256274
tlsConfig, err := modeltls.LoadTLSConfig(certPath, keyPath)
257275
if err != nil {
258-
log.Fatalf("Failed to load TLS configuration: %v", err)
276+
log.Error("Failed to load TLS configuration", "error", err)
277+
exitFunc(1)
259278
}
260279

261280
tlsServer = &http.Server{
@@ -265,7 +284,7 @@ func main() {
265284
ReadHeaderTimeout: 10 * time.Second,
266285
}
267286

268-
log.Infof("Listening on TLS port %s", tlsPort)
287+
log.Info("Listening on TLS port", "port", tlsPort)
269288
go func() {
270289
// Use ListenAndServeTLS with empty strings since TLSConfig already has the certs
271290
ln, err := tls.Listen("tcp", tlsServer.Addr, tlsConfig)
@@ -293,30 +312,30 @@ func main() {
293312
select {
294313
case err := <-serverErrors:
295314
if err != nil {
296-
log.Errorf("Server error: %v", err)
315+
log.Error("Server error", "error", err)
297316
}
298317
case err := <-tlsServerErrorsChan:
299318
if err != nil {
300-
log.Errorf("TLS server error: %v", err)
319+
log.Error("TLS server error", "error", err)
301320
}
302321
case <-ctx.Done():
303-
log.Infoln("Shutdown signal received")
304-
log.Infoln("Shutting down the server")
322+
log.Info("Shutdown signal received")
323+
log.Info("Shutting down the server")
305324
if err := server.Close(); err != nil {
306-
log.Errorf("Server shutdown error: %v", err)
325+
log.Error("Server shutdown error", "error", err)
307326
}
308327
if tlsServer != nil {
309-
log.Infoln("Shutting down the TLS server")
328+
log.Info("Shutting down the TLS server")
310329
if err := tlsServer.Close(); err != nil {
311-
log.Errorf("TLS server shutdown error: %v", err)
330+
log.Error("TLS server shutdown error", "error", err)
312331
}
313332
}
314-
log.Infoln("Waiting for the scheduler to stop")
333+
log.Info("Waiting for the scheduler to stop")
315334
if err := <-schedulerErrors; err != nil {
316-
log.Errorf("Scheduler error: %v", err)
335+
log.Error("Scheduler error", "error", err)
317336
}
318337
}
319-
log.Infoln("Docker Model Runner stopped")
338+
log.Info("Docker Model Runner stopped")
320339
}
321340

322341
// createLlamaCppConfigFromEnv creates a LlamaCppConfig from environment variables
@@ -337,12 +356,13 @@ func createLlamaCppConfigFromEnv() config.BackendConfig {
337356
for _, arg := range args {
338357
for _, disallowed := range disallowedArgs {
339358
if arg == disallowed {
340-
testLog.Fatalf("LLAMA_ARGS cannot override the %s argument as it is controlled by the model runner", disallowed)
359+
testLog.Error(fmt.Sprintf("LLAMA_ARGS cannot override the %s argument as it is controlled by the model runner", disallowed))
360+
exitFunc(1)
341361
}
342362
}
343363
}
344364

345-
testLog.Infof("Using custom arguments: %v", args)
365+
testLog.Info("Using custom arguments", "args", fmt.Sprintf("%v", args))
346366
return &llamacpp.Config{
347367
Args: args,
348368
}

main_test.go

Lines changed: 4 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,6 @@ import (
44
"testing"
55

66
"github.com/docker/model-runner/pkg/inference/backends/llamacpp"
7-
"github.com/sirupsen/logrus"
87
)
98

109
func TestCreateLlamaCppConfigFromEnv(t *testing.T) {
@@ -61,17 +60,14 @@ func TestCreateLlamaCppConfigFromEnv(t *testing.T) {
6160
t.Setenv("LLAMA_ARGS", tt.llamaArgs)
6261
}
6362

64-
// Create a test logger that captures fatal errors
65-
originalLog := testLog
66-
defer func() { testLog = originalLog }()
63+
// Override exitFunc to capture exit calls instead of actually exiting
64+
originalExitFunc := exitFunc
65+
defer func() { exitFunc = originalExitFunc }()
6766

68-
// Create a new logger that will exit with a special exit code
69-
newTestLog := logrus.New()
7067
var exitCode int
71-
newTestLog.ExitFunc = func(code int) {
68+
exitFunc = func(code int) {
7269
exitCode = code
7370
}
74-
testLog = newTestLog
7571

7672
config := createLlamaCppConfigFromEnv()
7773

pkg/anthropic/handler.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -59,7 +59,7 @@ func NewHandler(log logging.Logger, schedulerHTTP *scheduling.HTTPHandler, allow
5959
func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
6060
safeMethod := utils.SanitizeForLog(r.Method, -1)
6161
safePath := utils.SanitizeForLog(r.URL.Path, -1)
62-
h.log.Infof("Anthropic API request: %s %s", safeMethod, safePath)
62+
h.log.Info("Anthropic API request", "method", safeMethod, "path", safePath)
6363
h.httpHandler.ServeHTTP(w, r)
6464
}
6565

@@ -169,6 +169,6 @@ func (h *Handler) writeAnthropicError(w http.ResponseWriter, statusCode int, err
169169
}
170170

171171
if err := json.NewEncoder(w).Encode(errResp); err != nil {
172-
h.log.Errorf("Failed to encode error response: %v", err)
172+
h.log.Error("Failed to encode error response", "error", err)
173173
}
174174
}

0 commit comments

Comments
 (0)