Send fx's own events through the service's logger (closes #183) #443
@@ -557,8 +557,8 @@ If it is lost, run `webhooker resetpw admin` on a stopped deployment.
|
||||
```
|
||||
|
||||
It is a banner rather than a log line because that is the only time it
|
||||
is ever shown: as one `INFO` record it sat among the roughly 45 fx
|
||||
`PROVIDE`/`RUN`/`HOOK` lines a boot writes, and under `docker run -d`
|
||||
is ever shown: as one `INFO` record it would sit among the records fx
|
||||
writes as each start hook runs, and under `docker run -d`
|
||||
it is one line in a log subject to rotation. The database stores only
|
||||
its Argon2id hash. There is no second account and no forgot-password
|
||||
flow, so the banner and the reset command below are the only two ways
|
||||
@@ -628,7 +628,8 @@ Changing a password you still know needs none of this — use
|
||||
|
||||
`DEBUG=true` lowers the log level to `DEBUG`, which turns on every
|
||||
statement GORM runs, the two by-design lookup misses on the
|
||||
unauthenticated routes, and the rate limiter's own rejections. It is
|
||||
unauthenticated routes, the rate limiter's own rejections, and fx's
|
||||
records of building the dependency graph at startup. It is
|
||||
meant to be safe to turn on while diagnosing a live service and safe to
|
||||
paste the output of into a bug report.
|
||||
|
||||
@@ -2637,16 +2638,20 @@ read as more than it is:
|
||||
that type on a specific webhook, and each line it writes is bounded
|
||||
per event by the 1 MB receiver body cap. Adding one is a decision to
|
||||
spend log volume on that webhook's payloads.
|
||||
- **Two writers that do not go through `internal/logger` at all**, both
|
||||
on standard error. `fx` prints the dependency graph and the lifecycle
|
||||
hooks through its default console logger at startup and shutdown —
|
||||
nothing calls `fx.WithLogger`, and `fx.New` builds that logger over
|
||||
`os.Stderr`. The Go runtime writes a panic or a fatal error itself; a
|
||||
panic in a background worker rather than in a request handler is the
|
||||
case that reaches it, since nothing recovers those. Neither carries a
|
||||
client-chosen value at a client-chosen length: the five `panic` calls
|
||||
in this service are invariant guards over constants and over
|
||||
`crypto/rand`.
|
||||
- **The Go runtime**, which does not go through `internal/logger`. The
|
||||
runtime writes an unrecovered panic or a fatal error itself, as plain
|
||||
text on standard error, and that output cannot be redirected. A panic
|
||||
in a background worker rather than in a request handler is the case
|
||||
that reaches it, since nothing recovers those. It carries no
|
||||
client-chosen value at a client-chosen length: the service's own
|
||||
`panic` calls are invariant guards over constants and over
|
||||
`crypto/rand`, apart from the one that hands `http.ErrAbortHandler`
|
||||
back to `net/http`, described below.
|
||||
- **A failure before fx's logger is built**, such as an invalid
|
||||
configuration value. fx's logger takes the configuration, so when
|
||||
that fails fx's own console logger still prints the failure as plain
|
||||
text on standard error. Its values come from the operator's
|
||||
environment, not from a client.
|
||||
- **`net/http`'s own faults**, which are _not_ a separate writer.
|
||||
`internal/server/http.go` builds its server with a nil `ErrorLog`, so
|
||||
`net/http` falls back to the `log` package's default logger — and
|
||||
@@ -2996,7 +3001,7 @@ webhooker/
|
||||
│ ├── lifecycle/
|
||||
│ │ └── lifecycle.go # Shared stop-hook waiter, bounded by the stop context
|
||||
│ ├── logger/
|
||||
│ │ └── logger.go # slog setup with TTY detection
|
||||
│ │ └── logger.go # slog setup with TTY detection; fx's event logger
|
||||
│ ├── metrics/
|
||||
│ │ └── metrics.go # Delivery Prometheus collectors, labelled by target type
|
||||
│ ├── middleware/
|
||||
|
||||
@@ -8,6 +8,7 @@ import (
|
||||
"time"
|
||||
|
||||
"go.uber.org/fx"
|
||||
"go.uber.org/fx/fxevent"
|
||||
"sneak.berlin/go/webhooker/internal/config"
|
||||
"sneak.berlin/go/webhooker/internal/database"
|
||||
"sneak.berlin/go/webhooker/internal/datadir"
|
||||
@@ -168,6 +169,19 @@ func run(stderr io.Writer) int {
|
||||
func newApp() *fx.App {
|
||||
return fx.New(
|
||||
fx.StopTimeout(stopTimeout),
|
||||
// fx's own events go through the service's logger, not fx's
|
||||
// console logger on standard error. The exception is a failure
|
||||
// before this logger is built, such as an invalid configuration
|
||||
// value, which fx's console logger still prints there. fx holds
|
||||
// its events back until this logger is built and then replays
|
||||
// them, so it takes the configuration, which sets the level
|
||||
// DEBUG=true asks for: without it the replay would run at INFO
|
||||
// and drop every record of how the graph was built.
|
||||
fx.WithLogger(
|
||||
func(l *logger.Logger, _ *config.Config) fxevent.Logger {
|
||||
return logger.NewFxLogger(l.Get())
|
||||
},
|
||||
),
|
||||
fx.Provide(
|
||||
globals.New,
|
||||
logger.New,
|
||||
|
||||
@@ -2,6 +2,12 @@ package main
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"encoding/json"
|
||||
"io"
|
||||
"log/slog"
|
||||
"net"
|
||||
"os"
|
||||
"strconv"
|
||||
"strings"
|
||||
"testing"
|
||||
"time"
|
||||
@@ -38,6 +44,99 @@ func TestNewApp_StopTimeout(t *testing.T) {
|
||||
require.Less(t, got, dockerStopGrace)
|
||||
}
|
||||
|
||||
// freePort returns a loopback TCP port that was free a moment ago, by
|
||||
// taking one and releasing it.
|
||||
func freePort(t *testing.T) int {
|
||||
t.Helper()
|
||||
|
||||
var listenCfg net.ListenConfig
|
||||
|
||||
l, err := listenCfg.Listen(t.Context(), "tcp", "127.0.0.1:0")
|
||||
require.NoError(t, err)
|
||||
|
||||
addr, ok := l.Addr().(*net.TCPAddr)
|
||||
require.True(t, ok, "listener is not TCP")
|
||||
require.NoError(t, l.Close())
|
||||
|
||||
return addr.Port
|
||||
}
|
||||
|
||||
// TestNewApp_SendsFxEventsToTheLogger starts and stops the app main
|
||||
// runs, with DEBUG=true, and reads back what reached the service's
|
||||
// logger. fx's own events must arrive there as structured records:
|
||||
// the start at INFO, and at DEBUG the records of how the graph was
|
||||
// built.
|
||||
//
|
||||
// fx holds its events back until its logger is built and then replays
|
||||
// them all at once, so the earliest of them arriving shows the replay
|
||||
// ran at DEBUG: that globals.New was provided, which fx records before
|
||||
// anything is built, and the run of logger.New, which happens before
|
||||
// the configuration sets the level.
|
||||
func TestNewApp_SendsFxEventsToTheLogger(t *testing.T) {
|
||||
t.Setenv("DATA_DIR", t.TempDir())
|
||||
t.Setenv("PORT", strconv.Itoa(freePort(t)))
|
||||
t.Setenv("DEBUG", "true")
|
||||
|
||||
// internal/logger writes to whatever os.Stdout is when it builds
|
||||
// its handler. A file is not a terminal, so that handler is the
|
||||
// JSON one the service uses in production.
|
||||
out, err := os.CreateTemp(t.TempDir(), "stdout")
|
||||
require.NoError(t, err)
|
||||
|
||||
stdout := os.Stdout
|
||||
os.Stdout = out
|
||||
|
||||
t.Cleanup(func() {
|
||||
os.Stdout = stdout
|
||||
_ = out.Close()
|
||||
})
|
||||
|
||||
app := newApp()
|
||||
require.NoError(t, app.Start(t.Context()))
|
||||
require.NoError(t, app.Stop(t.Context()))
|
||||
|
||||
_, err = out.Seek(0, io.SeekStart)
|
||||
require.NoError(t, err)
|
||||
|
||||
written, err := io.ReadAll(out)
|
||||
require.NoError(t, err)
|
||||
|
||||
type record struct {
|
||||
Level string `json:"level"`
|
||||
Msg string `json:"msg"`
|
||||
Name string `json:"name"`
|
||||
Constructor string `json:"constructor"`
|
||||
}
|
||||
|
||||
var records []record
|
||||
|
||||
for line := range strings.Lines(string(written)) {
|
||||
var r record
|
||||
|
||||
// The first-boot banner is plain text, not a record.
|
||||
if json.Unmarshal([]byte(line), &r) == nil {
|
||||
records = append(records, r)
|
||||
}
|
||||
}
|
||||
|
||||
const pkg = "sneak.berlin/go/webhooker/internal/"
|
||||
|
||||
info := slog.LevelInfo.String()
|
||||
debug := slog.LevelDebug.String()
|
||||
|
||||
assert.Contains(t, records, record{Level: info, Msg: "started"})
|
||||
assert.Contains(t, records, record{
|
||||
Level: debug, Msg: "provided", Constructor: pkg + "globals.New()",
|
||||
})
|
||||
assert.Contains(t, records, record{
|
||||
Level: debug, Msg: "run", Name: pkg + "logger.New()",
|
||||
})
|
||||
assert.Contains(t, records, record{Level: debug, Msg: "invoking"})
|
||||
assert.Contains(t, records, record{
|
||||
Level: debug, Msg: "initialized custom fxevent.Logger",
|
||||
})
|
||||
}
|
||||
|
||||
// TestRunRefusesLockedDataDir pins what an operator's second start
|
||||
// does. The entry point must refuse before it builds the fx graph —
|
||||
// nothing may open a database in a DATA_DIR another process holds —
|
||||
|
||||
@@ -20,7 +20,7 @@ require (
|
||||
github.com/prometheus/client_model v0.5.0
|
||||
github.com/slok/go-http-metrics v0.11.0
|
||||
github.com/stretchr/testify v1.11.1
|
||||
go.uber.org/fx v1.20.1
|
||||
go.uber.org/fx v1.24.0
|
||||
golang.org/x/crypto v0.38.0
|
||||
gopkg.in/yaml.v3 v3.0.1
|
||||
gorm.io/driver/sqlite v1.5.4
|
||||
@@ -42,7 +42,6 @@ require (
|
||||
github.com/jinzhu/now v1.1.5 // indirect
|
||||
github.com/kballard/go-shellquote v0.0.0-20180428030007-95032a82bc51 // indirect
|
||||
github.com/klauspost/cpuid/v2 v2.2.10 // indirect
|
||||
github.com/kr/text v0.2.0 // indirect
|
||||
github.com/mattn/go-isatty v0.0.20 // indirect
|
||||
github.com/mattn/go-sqlite3 v1.14.17 // indirect
|
||||
github.com/matttproud/golang_protobuf_extensions/v2 v2.0.0 // indirect
|
||||
@@ -51,10 +50,9 @@ require (
|
||||
github.com/prometheus/procfs v0.12.0 // indirect
|
||||
github.com/remyoudompheng/bigfft v0.0.0-20230129092748-24d4a6f8daec // indirect
|
||||
github.com/zeebo/xxh3 v1.0.2 // indirect
|
||||
go.uber.org/atomic v1.9.0 // indirect
|
||||
go.uber.org/dig v1.17.0 // indirect
|
||||
go.uber.org/multierr v1.9.0 // indirect
|
||||
go.uber.org/zap v1.23.0 // indirect
|
||||
go.uber.org/dig v1.19.0 // indirect
|
||||
go.uber.org/multierr v1.10.0 // indirect
|
||||
go.uber.org/zap v1.26.0 // indirect
|
||||
golang.org/x/mod v0.17.0 // indirect
|
||||
golang.org/x/sync v0.14.0 // indirect
|
||||
golang.org/x/sys v0.47.0 // indirect
|
||||
|
||||
@@ -1,7 +1,5 @@
|
||||
github.com/99designs/basicauth-go v0.0.0-20230316000542-bf6f9cbbf0f8 h1:nMpu1t4amK3vJWBibQ5X/Nv0aXL+b69TQf2uK5PH7Go=
|
||||
github.com/99designs/basicauth-go v0.0.0-20230316000542-bf6f9cbbf0f8/go.mod h1:3cARGAK9CfW3HoxCy1a0G4TKrdiKke8ftOMEOHyySYs=
|
||||
github.com/benbjohnson/clock v1.3.0 h1:ip6w0uFQkncKQ979AypyG0ER7mqUSBdKLOgAle/AT8A=
|
||||
github.com/benbjohnson/clock v1.3.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA=
|
||||
github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
|
||||
github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
|
||||
github.com/cespare/xxhash/v2 v2.2.0 h1:DC2CZ1Ep5Y4k3ZQ899DldepgrayRUGE6BBZ/cd9Cj44=
|
||||
@@ -12,9 +10,6 @@ github.com/chromedp/chromedp v0.16.0 h1:rOO4deOm4CbZgBCa8mD9g2rDyIoNs0BkgvNrlbp5
|
||||
github.com/chromedp/chromedp v0.16.0/go.mod h1:rbuGKFT1vMcFcFqKfPIO1GpX/N+2s8onm2qMxZLbU5U=
|
||||
github.com/chromedp/sysutil v1.1.0 h1:PUFNv5EcprjqXZD9nJb9b/c9ibAbxiYo4exNWZyipwM=
|
||||
github.com/chromedp/sysutil v1.1.0/go.mod h1:WiThHUdltqCNKGc4gaU50XgYjwjYIhKWoHGPTUfWTJ8=
|
||||
github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
|
||||
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
|
||||
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
|
||||
github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc h1:U9qPSI2PIWSS1VwoXQT9A3Wy9MM3WgvqSxFWenqJduM=
|
||||
github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
|
||||
github.com/dustin/go-humanize v1.0.1 h1:GzkhY7T5VNhEkwH0PVJgjz+fX1rhBrR7pRT3mDkpeCY=
|
||||
@@ -83,7 +78,6 @@ github.com/pingcap/errors v0.11.4 h1:lFuQV/oaUMGcD2tqt+01ROSmJs75VG1ToEOkZIZ4nE4
|
||||
github.com/pingcap/errors v0.11.4/go.mod h1:Oi8TUi2kEtXXLMJk9l1cGmz20kV3TaQ0usTwv5KuLY8=
|
||||
github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
|
||||
github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
|
||||
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
|
||||
github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 h1:Jamvg5psRIccs7FGNTlIRMkT8wgtp5eCXdBlqhYGL6U=
|
||||
github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
|
||||
github.com/prometheus/client_golang v1.18.0 h1:HzFfmkOzH5Q8L8G+kSJKUx5dtG87sewO+FoDDqP5Tbk=
|
||||
@@ -100,28 +94,24 @@ github.com/rogpeppe/go-internal v1.10.0 h1:TMyTOH3F/DB16zRVcYyreMH6GnZZrwQVAoYjR
|
||||
github.com/rogpeppe/go-internal v1.10.0/go.mod h1:UQnix2H7Ngw/k4C5ijL5+65zddjncjaFoBhdsK/akog=
|
||||
github.com/slok/go-http-metrics v0.11.0 h1:ABJUpekCZSkQT1wQrFvS4kGbhea/w6ndFJaWJeh3zL0=
|
||||
github.com/slok/go-http-metrics v0.11.0/go.mod h1:ZGKeYG1ET6TEJpQx18BqAJAvxw9jBAZXCHU7bWQqqAc=
|
||||
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
|
||||
github.com/stretchr/objx v0.5.2 h1:xuMeJ0Sdp5ZMRXx/aWO6RZxdr3beISkG5/G/aIRr3pY=
|
||||
github.com/stretchr/objx v0.5.2/go.mod h1:FRsXN1f5AsAjCGJKqEizvkpNtU+EGNCLh3NxZ/8L+MA=
|
||||
github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
|
||||
github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U=
|
||||
github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U=
|
||||
github.com/zeebo/assert v1.3.0 h1:g7C04CbJuIDKNPFHmsk4hwZDO5O+kntRxzaUoNXj+IQ=
|
||||
github.com/zeebo/assert v1.3.0/go.mod h1:Pq9JiuJQpG8JLJdtkwrJESF0Foym2/D9XMU5ciN/wJ0=
|
||||
github.com/zeebo/xxh3 v1.0.2 h1:xZmwmqxHZA8AI603jOQ0tMqmBr9lPeFwGg6d+xy9DC0=
|
||||
github.com/zeebo/xxh3 v1.0.2/go.mod h1:5NWz9Sef7zIDm2JHfFlcQvNekmcEl9ekUZQQKCYaDcA=
|
||||
go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE=
|
||||
go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
|
||||
go.uber.org/dig v1.17.0 h1:5Chju+tUvcC+N7N6EV08BJz41UZuO3BmHcN4A287ZLI=
|
||||
go.uber.org/dig v1.17.0/go.mod h1:rTxpf7l5I0eBTlE6/9RL+lDybC7WFwY2QH55ZSjy1mU=
|
||||
go.uber.org/fx v1.20.1 h1:zVwVQGS8zYvhh9Xxcu4w1M6ESyeMzebzj2NbSayZ4Mk=
|
||||
go.uber.org/fx v1.20.1/go.mod h1:iSYNbHf2y55acNCwCXKx7LbWb5WG1Bnue5RDXz1OREg=
|
||||
go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI=
|
||||
go.uber.org/goleak v1.1.11/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ=
|
||||
go.uber.org/multierr v1.9.0 h1:7fIwc/ZtS0q++VgcfqFDxSBZVv/Xo49/SYnDFupUwlI=
|
||||
go.uber.org/multierr v1.9.0/go.mod h1:X2jQV1h+kxSjClGpnseKVIxpmcjrj7MNnI0bnlfKTVQ=
|
||||
go.uber.org/zap v1.23.0 h1:OjGQ5KQDEUawVHxNwQgPpiypGHOxo2mNZsOqTak4fFY=
|
||||
go.uber.org/zap v1.23.0/go.mod h1:D+nX8jyLsMHMYrln8A0rJjFt/T/9/bGgIhAqxv5URuY=
|
||||
go.uber.org/dig v1.19.0 h1:BACLhebsYdpQ7IROQ1AGPjrXcP5dF80U3gKoFzbaq/4=
|
||||
go.uber.org/dig v1.19.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE=
|
||||
go.uber.org/fx v1.24.0 h1:wE8mruvpg2kiiL1Vqd0CC+tr0/24XIB10Iwp2lLWzkg=
|
||||
go.uber.org/fx v1.24.0/go.mod h1:AmDeGyS+ZARGKM4tlH4FY2Jr63VjbEDJHtqXTGP5hbo=
|
||||
go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk=
|
||||
go.uber.org/goleak v1.2.0/go.mod h1:XJYK+MuIchqpmGmUSAzotztawfKvYLUIgg7guXrwVUo=
|
||||
go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
|
||||
go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
|
||||
go.uber.org/zap v1.26.0 h1:sI7k6L95XOKS281NhVKOFCUNIvv9e0w4BF8N3u+tCRo=
|
||||
go.uber.org/zap v1.26.0/go.mod h1:dtElttAiwGvoJ/vj4IwHBS/gXsEu/pZ50mUIRWuG0so=
|
||||
golang.org/x/crypto v0.38.0 h1:jt+WWG8IZlBnVbomuhg2Mdq0+BBQaHbtqHEFEigjUV8=
|
||||
golang.org/x/crypto v0.38.0/go.mod h1:MvrbAqul58NNYPKnOra203SB9vpuZW0e+RRZV+Ggqjw=
|
||||
golang.org/x/mod v0.17.0 h1:zY54UmvipHiNd+pm+m0x9KhZ9hl1/7QNMyxXbc6ICqA=
|
||||
|
||||
@@ -9,6 +9,7 @@ import (
|
||||
"time"
|
||||
|
||||
"go.uber.org/fx"
|
||||
"go.uber.org/fx/fxevent"
|
||||
"sneak.berlin/go/webhooker/internal/globals"
|
||||
)
|
||||
|
||||
@@ -106,3 +107,40 @@ func (l *Logger) Identify() {
|
||||
func (l *Logger) Writer() io.Writer {
|
||||
return os.Stdout
|
||||
}
|
||||
|
||||
// FxLogger writes fx's own events through a slog logger: how the
|
||||
// dependency graph was built at DEBUG, since it repeats on every
|
||||
// start; the start and stop hooks, the start itself and the signal
|
||||
// that stops the service at INFO; every failure at ERROR.
|
||||
//
|
||||
// The formatting is fx's own fxevent.SlogLogger. That logger takes a
|
||||
// single level for every event that is not a failure, so FxLogger
|
||||
// holds one at each level and picks between them.
|
||||
type FxLogger struct {
|
||||
graph *fxevent.SlogLogger
|
||||
lifecycle *fxevent.SlogLogger
|
||||
}
|
||||
|
||||
// NewFxLogger returns an FxLogger that writes through log.
|
||||
func NewFxLogger(log *slog.Logger) *FxLogger {
|
||||
graph := &fxevent.SlogLogger{Logger: log}
|
||||
graph.UseLogLevel(slog.LevelDebug)
|
||||
|
||||
lifecycle := &fxevent.SlogLogger{Logger: log}
|
||||
lifecycle.UseLogLevel(slog.LevelInfo)
|
||||
|
||||
return &FxLogger{graph: graph, lifecycle: lifecycle}
|
||||
}
|
||||
|
||||
// LogEvent implements fxevent.Logger.
|
||||
func (f *FxLogger) LogEvent(event fxevent.Event) {
|
||||
switch event.(type) {
|
||||
case *fxevent.Supplied, *fxevent.Provided, *fxevent.Replaced,
|
||||
*fxevent.Decorated, *fxevent.BeforeRun, *fxevent.Run,
|
||||
*fxevent.Invoking, *fxevent.Invoked,
|
||||
*fxevent.LoggerInitialized:
|
||||
f.graph.LogEvent(event)
|
||||
default:
|
||||
f.lifecycle.LogEvent(event)
|
||||
}
|
||||
}
|
||||
|
||||
@@ -1,13 +1,23 @@
|
||||
package logger_test
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"encoding/json"
|
||||
"errors"
|
||||
"log/slog"
|
||||
"testing"
|
||||
|
||||
"github.com/stretchr/testify/assert"
|
||||
"github.com/stretchr/testify/require"
|
||||
"go.uber.org/fx"
|
||||
"go.uber.org/fx/fxevent"
|
||||
"go.uber.org/fx/fxtest"
|
||||
"sneak.berlin/go/webhooker/internal/globals"
|
||||
"sneak.berlin/go/webhooker/internal/logger"
|
||||
)
|
||||
|
||||
var errStopHook = errors.New("stop hook failed on purpose")
|
||||
|
||||
func testGlobals() *globals.Globals {
|
||||
return &globals.Globals{
|
||||
Appname: "test-app",
|
||||
@@ -57,3 +67,47 @@ func TestEnableDebugLogging(t *testing.T) {
|
||||
// Test debug logging
|
||||
l.Get().Debug("debug message", "test", true)
|
||||
}
|
||||
|
||||
// TestFxLogger_Levels starts and stops an fx app that reports its own
|
||||
// events through NewFxLogger, as cmd/webhooker does, and reads back
|
||||
// what reached the handler: the graph at DEBUG, the start at INFO and
|
||||
// a failed stop hook at ERROR, each as a structured record.
|
||||
func TestFxLogger_Levels(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
var out bytes.Buffer
|
||||
|
||||
log := slog.New(slog.NewJSONHandler(
|
||||
&out, &slog.HandlerOptions{Level: slog.LevelDebug},
|
||||
))
|
||||
|
||||
app := fx.New(
|
||||
fx.WithLogger(func() fxevent.Logger {
|
||||
return logger.NewFxLogger(log)
|
||||
}),
|
||||
fx.Invoke(func(lc fx.Lifecycle) {
|
||||
lc.Append(fx.StopHook(func() error { return errStopHook }))
|
||||
}),
|
||||
)
|
||||
|
||||
require.NoError(t, app.Start(t.Context()))
|
||||
require.ErrorIs(t, app.Stop(t.Context()), errStopHook)
|
||||
|
||||
levels := map[string]string{}
|
||||
|
||||
decoder := json.NewDecoder(&out)
|
||||
for decoder.More() {
|
||||
var record struct {
|
||||
Level string `json:"level"`
|
||||
Msg string `json:"msg"`
|
||||
}
|
||||
|
||||
require.NoError(t, decoder.Decode(&record))
|
||||
|
||||
levels[record.Msg] = record.Level
|
||||
}
|
||||
|
||||
assert.Equal(t, "DEBUG", levels["provided"])
|
||||
assert.Equal(t, "INFO", levels["started"])
|
||||
assert.Equal(t, "ERROR", levels["OnStop hook failed"])
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user