Skip to content

Introduce log levels with slog #65

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
Copilot wants to merge 3 commits into
base: main
Choose a base branch
from
Draft

Introduce log levels with slog #65

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
af946e6
Initial plan
Copilot Nov 12, 2025
a125952
Implement slog-based logging with DEBUG environment variable support
Copilot Nov 12, 2025
99697ac
Add logging tests and documentation
Copilot Nov 12, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
73 changes: 73 additions & 0 deletions docs/logging.md
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,73 @@
# Logging in Model Runner

Model Runner uses Go's standard library `log/slog` for structured logging with configurable log levels.

## Log Levels

The application supports the following log levels:
- **Debug**: Detailed diagnostic information (only shown when debug mode is enabled)
- **Info**: General informational messages (default)
- **Warn**: Warning messages for potentially problematic situations
- **Error**: Error messages for failures that don't stop the application
- **Fatal**: Critical errors that cause the application to exit

## Enabling Debug Logging

### For the Main Server

Set the `DEBUG` environment variable to `1` to enable debug-level logging:

```bash
DEBUG=1 ./model-runner
```

Or in Docker:

```bash
docker run -e DEBUG=1 docker/model-runner:latest
```

### For CLI Commands

The `docker model run` command supports a `--debug` flag:

```bash
docker model run --debug <model-name>
```

## Structured Logging

The logger supports structured logging with fields:

```go
// Add a single field
log.WithField("component", "scheduler").Info("Starting scheduler")

// Add multiple fields
log.WithFields(map[string]interface{}{
"component": "backend",
"model": "llama-3",
}).Info("Loading model")

// Add error context
log.WithError(err).Error("Failed to load model")
```

## Log Output Format

Logs are output in slog's text format:

```
time=2025-11-12T15:55:44.435Z level=INFO msg="Successfully initialized store" component=model-manager
time=2025-11-12T15:55:44.435Z level=DEBUG msg="Loading model from cache" model=llama-3 component=loader
time=2025-11-12T15:55:44.436Z level=WARN msg="Model cache miss, pulling from registry" model=llama-3
time=2025-11-12T15:55:44.437Z level=ERROR msg="Failed to connect to registry" error="connection timeout"
```

## Implementation Details

- The logging implementation is in `pkg/logging/`
- `SlogLogger` wraps `log/slog` and provides compatibility with the existing logging interface
- `LogrusAdapter` provides backward compatibility for code still using logrus
- The log level is set at startup based on the `DEBUG` environment variable
- Tests are available in `pkg/logging/slog_test.go`
23 changes: 18 additions & 5 deletions main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package main

import (
"context"
"log/slog"
"net"
"net/http"
"net/url"
Expand All @@ -20,12 +21,22 @@ import (
"github.com/docker/model-runner/pkg/inference/memory"
"github.com/docker/model-runner/pkg/inference/models"
"github.com/docker/model-runner/pkg/inference/scheduling"
"github.com/docker/model-runner/pkg/logging"
"github.com/docker/model-runner/pkg/metrics"
"github.com/docker/model-runner/pkg/routing"
"github.com/sirupsen/logrus"
)

var log = logrus.New()
var log logging.Logger

func initLogger() {
// Determine log level based on DEBUG environment variable
level := slog.LevelInfo
if os.Getenv("DEBUG") == "1" {
level = slog.LevelDebug
}

log = logging.NewSlogLogger(level, os.Stderr)
}

// V1AliasHandler provides an alias from /v1/ to /engines/v1/ paths
type V1AliasHandler struct {
Expand All @@ -49,6 +60,8 @@ func (h *V1AliasHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
}

func main() {
initLogger()

ctx, cancel := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM)
defer cancel()

Expand Down Expand Up @@ -107,7 +120,7 @@ func main() {
log,
models.ClientConfig{
StoreRootPath: modelPath,
Logger: log.WithFields(logrus.Fields{"component": "model-manager"}),
Logger: log.WithFields(map[string]interface{}{"component": "model-manager"}),
Transport: resumable.New(baseTransport),
},
nil,
Expand All @@ -122,7 +135,7 @@ func main() {
llamaCppBackend, err := llamacpp.New(
log,
modelManager,
log.WithFields(logrus.Fields{"component": llamacpp.Name}),
log.WithFields(map[string]interface{}{"component": llamacpp.Name}),
llamaServerPath,
func() string {
wd, _ := os.Getwd()
Expand All @@ -145,7 +158,7 @@ func main() {
vllmBackend, err := vllm.New(
log,
modelManager,
log.WithFields(logrus.Fields{"component": vllm.Name}),
log.WithFields(map[string]interface{}{"component": vllm.Name}),
nil,
)
if err != nil {
Expand Down
15 changes: 9 additions & 6 deletions main_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ import (
"testing"

"github.com/docker/model-runner/pkg/inference/backends/llamacpp"
"github.com/sirupsen/logrus"
"github.com/docker/model-runner/pkg/logging"
)

func TestCreateLlamaCppConfigFromEnv(t *testing.T) {
Expand Down Expand Up @@ -68,13 +68,16 @@ func TestCreateLlamaCppConfigFromEnv(t *testing.T) {
originalLog := log
defer func() { log = originalLog }()

// Create a new logger that will exit with a special exit code
testLog := logrus.New()
// Initialize logger for testing
initLogger()

// Set exit function to capture exit code
var exitCode int
testLog.ExitFunc = func(code int) {
exitCode = code
if slogLogger, ok := log.(*logging.SlogLogger); ok {
slogLogger.SetExitFunc(func(code int) {
exitCode = code
})
}
log = testLog

config := createLlamaCppConfigFromEnv()

Expand Down
11 changes: 6 additions & 5 deletions pkg/distribution/distribution/client.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,11 +5,12 @@ import (
"errors"
"fmt"
"io"
"log/slog"
"net/http"
"slices"

"github.com/docker/model-runner/pkg/internal/utils"
"github.com/sirupsen/logrus"
"github.com/docker/model-runner/pkg/logging"

"github.com/docker/model-runner/pkg/distribution/internal/progress"
"github.com/docker/model-runner/pkg/distribution/internal/store"
Expand All @@ -22,7 +23,7 @@ import (
// Client provides model distribution functionality
type Client struct {
store *store.LocalStore
log *logrus.Entry
log logging.Logger
registry *registry.Client
}

Expand All @@ -37,7 +38,7 @@ type Option func(*options)
// options holds the configuration for a new Client
type options struct {
storeRootPath string
logger *logrus.Entry
logger logging.Logger
transport http.RoundTripper
userAgent string
username string
Expand All @@ -54,7 +55,7 @@ func WithStoreRootPath(path string) Option {
}

// WithLogger sets the logger
func WithLogger(logger *logrus.Entry) Option {
func WithLogger(logger logging.Logger) Option {
return func(o *options) {
if logger != nil {
o.logger = logger
Expand Down Expand Up @@ -92,7 +93,7 @@ func WithRegistryAuth(username, password string) Option {

func defaultOptions() *options {
return &options{
logger: logrus.NewEntry(logrus.StandardLogger()),
logger: logging.NewSlogLogger(slog.LevelInfo, nil),
transport: registry.DefaultTransport,
userAgent: registry.DefaultUserAgent,
}
Expand Down
3 changes: 2 additions & 1 deletion pkg/distribution/distribution/client_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ import (
"github.com/docker/model-runner/pkg/distribution/internal/safetensors"
mdregistry "github.com/docker/model-runner/pkg/distribution/registry"
"github.com/docker/model-runner/pkg/inference/platform"
"github.com/docker/model-runner/pkg/logging"
)

var (
Expand Down Expand Up @@ -773,7 +774,7 @@ func TestClientDefaultLogger(t *testing.T) {
}

// Create client with custom logger
customLogger := logrus.NewEntry(logrus.New())
customLogger := logging.NewLogrusAdapter(logrus.New())
client, err = NewClient(
WithStoreRootPath(tempDir),
WithLogger(customLogger),
Expand Down
3 changes: 1 addition & 2 deletions pkg/inference/models/manager.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,6 @@ import (
"github.com/docker/model-runner/pkg/logging"
"github.com/docker/model-runner/pkg/middleware"
v1 "github.com/google/go-containerregistry/pkg/v1"
"github.com/sirupsen/logrus"
)

const (
Expand Down Expand Up @@ -59,7 +58,7 @@ type ClientConfig struct {
// StoreRootPath is the root path for the model store.
StoreRootPath string
// Logger is the logger to use.
Logger *logrus.Entry
Logger logging.Logger
// Transport is the HTTP transport to use.
Transport http.RoundTripper
// UserAgent is the user agent to use.
Expand Down
11 changes: 6 additions & 5 deletions pkg/inference/models/manager_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ import (
reg "github.com/docker/model-runner/pkg/distribution/registry"
"github.com/docker/model-runner/pkg/inference"
"github.com/docker/model-runner/pkg/inference/memory"
"github.com/docker/model-runner/pkg/logging"

"github.com/sirupsen/logrus"
)
Expand Down Expand Up @@ -122,11 +123,11 @@ func TestPullModel(t *testing.T) {

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
log := logrus.NewEntry(logrus.StandardLogger())
log := logging.NewLogrusAdapter(logrus.StandardLogger())
memEstimator := &mockMemoryEstimator{}
m := NewManager(log, ClientConfig{
StoreRootPath: tempDir,
Logger: log.WithFields(logrus.Fields{"component": "model-manager"}),
Logger: log.WithFields(map[string]interface{}{"component": "model-manager"}),
}, nil, memEstimator)

r := httptest.NewRequest("POST", "/models/create", strings.NewReader(`{"from": "`+tag+`"}`))
Expand Down Expand Up @@ -233,11 +234,11 @@ func TestHandleGetModel(t *testing.T) {

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
log := logrus.NewEntry(logrus.StandardLogger())
log := logging.NewLogrusAdapter(logrus.StandardLogger())
memEstimator := &mockMemoryEstimator{}
m := NewManager(log, ClientConfig{
StoreRootPath: tempDir,
Logger: log.WithFields(logrus.Fields{"component": "model-manager"}),
Logger: log.WithFields(map[string]interface{}{"component": "model-manager"}),
Transport: http.DefaultTransport,
UserAgent: "test-agent",
}, nil, memEstimator)
Expand Down Expand Up @@ -318,7 +319,7 @@ func TestCors(t *testing.T) {
memEstimator := &mockMemoryEstimator{}
discard := logrus.New()
discard.SetOutput(io.Discard)
log := logrus.NewEntry(discard)
log := logging.NewLogrusAdapter(discard)
m := NewManager(log, ClientConfig{}, []string{"*"}, memEstimator)
req := httptest.NewRequest(http.MethodOptions, "http://model-runner.docker.internal"+tt.path, nil)
req.Header.Set("Origin", "docker.com")
Expand Down
9 changes: 5 additions & 4 deletions pkg/inference/scheduling/loader_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import (
"time"

"github.com/docker/model-runner/pkg/inference"
"github.com/docker/model-runner/pkg/logging"
"github.com/sirupsen/logrus"
)

Expand Down Expand Up @@ -68,10 +69,10 @@ func (m *mockSystemMemoryInfo) GetTotalMemory() inference.RequiredMemory {
}

// createTestLogger creates a logger for testing
func createTestLogger() *logrus.Entry {
func createTestLogger() logging.Logger {
log := logrus.New()
log.SetOutput(io.Discard)
return logrus.NewEntry(log)
return logging.NewLogrusAdapter(log)
}

// Test memory size constants
Expand All @@ -81,7 +82,7 @@ const (

// createDefunctMockRunner creates a mock runner with a closed done channel,
// simulating a defunct (crashed/terminated) runner for testing
func createDefunctMockRunner(log *logrus.Entry, backend inference.Backend) *runner {
func createDefunctMockRunner(log logging.Logger, backend inference.Backend) *runner {
defunctRunnerDone := make(chan struct{})
_, defunctRunnerCancel := context.WithCancel(context.Background())

Expand Down Expand Up @@ -110,7 +111,7 @@ func createDefunctMockRunner(log *logrus.Entry, backend inference.Backend) *runn

// createAliveTerminableMockRunner creates a mock runner with an open done channel
// (i.e., not defunct) that will close when cancel is invoked, so terminate() returns.
func createAliveTerminableMockRunner(log *logrus.Entry, backend inference.Backend) *runner {
func createAliveTerminableMockRunner(log logging.Logger, backend inference.Backend) *runner {
runCtx, cancel := context.WithCancel(context.Background())
done := make(chan struct{})

Expand Down
3 changes: 2 additions & 1 deletion pkg/inference/scheduling/scheduler_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"testing"

"github.com/docker/model-runner/pkg/inference"
"github.com/docker/model-runner/pkg/logging"
"github.com/sirupsen/logrus"
)

Expand Down Expand Up @@ -43,7 +44,7 @@ func TestCors(t *testing.T) {
t.Parallel()
discard := logrus.New()
discard.SetOutput(io.Discard)
log := logrus.NewEntry(discard)
log := logging.NewLogrusAdapter(discard)
s := NewScheduler(log, nil, nil, nil, nil, []string{"*"}, nil, systemMemoryInfo{})
req := httptest.NewRequest(http.MethodOptions, "http://model-runner.docker.internal"+tt.path, nil)
req.Header.Set("Origin", "docker.com")
Expand Down
Loading