Return sink write errors from every handler (closes #22) #35

Merged
clawbot merged 1 commits from issue-22-handler-write-errors into next 2026-10-06 08:45:18 +02:00
7 changed files with 259 additions and 16 deletions
+25
View File
@@ -25,6 +25,9 @@ Released v1.0.0 2024-06-14. Works as intended. No known bugs.
in console output they are appended as `key=value` pairs, with grouped
keys written as `group.key=value`. See
[Attribute output](#attribute-output) for the details worth knowing
- reports a record that could not be delivered as an error from the
handler's `Handle` method. See
[When delivery fails](#when-delivery-fails) for how to receive it
## Planned Features
@@ -104,6 +107,28 @@ ignored, an empty group is elided along with its key, a group with an
empty key is inlined into its parent, and `WithGroup("")` returns the
handler unchanged.
## When delivery fails
Every handler returns an error from `Handle` when it could not deliver
the record:
- `ConsoleHandler` and `JSONHandler` return the error from their write to
stdout, wrapped, so `errors.Is` still matches the original
- `WebhookHandler` returns an error when the request fails, and also when
the server answers with a status outside 2xx, a redirect included,
since it does not follow redirects
- `MultiplexHandler`, which simplelog installs as the default, passes the
record to every handler it holds even after one of them fails, then
returns all their errors joined with `errors.Join` (nil if none failed)
`slog.Info`, `slog.Error` and the other `slog.Logger` methods throw that
error away. That is how `log/slog` works, and simplelog cannot change it.
To find out whether a record was delivered, build a `slog.Record` and pass
it to the handler yourself, for example
`slog.Default().Handler().Handle(ctx, record)`, then check the error it
returns. A record passed to `Handle` directly gets the wrong file and
line in console output.
## Entrypoints
This repository adheres to the
+4
View File
@@ -24,6 +24,10 @@ files it depends on: .golangci.yml, REPO_POLICIES.md, .editorconfig,
# Completed Steps
* 2026-10-06: every handler now returns a failed delivery from `Handle`
instead of discarding it: console and JSON return the stdout write
error, the webhook also fails on a non-2xx answer, and the multiplex
delivers to every handler and returns their errors joined
* 2026-08-10: fixed every handler discarding slog attributes: console,
JSON and webhook handlers now emit record attributes, accumulate
WithAttrs without mutating the receiver, and honour WithGroup;
+17 -5
View File
@@ -3,6 +3,7 @@ package simplelog
import (
"context"
"fmt"
"io"
"log/slog"
"os"
"runtime"
@@ -17,6 +18,9 @@ const callerSkipFrames = 4
// ConsoleHandler writes human-readable, colored log lines to stdout.
type ConsoleHandler struct {
// out is where records are written. Nil means os.Stdout, looked up on
// every write so that a reassigned os.Stdout is followed.
out io.Writer
attrs handlerAttrs
}
@@ -27,7 +31,7 @@ func NewConsoleHandler() *ConsoleHandler {
// Handle writes the record to stdout as a colored, timestamped line
// including the caller file and line, followed by the attributes as
// key=value pairs.
// key=value pairs. A failed write is returned as an error.
func (c *ConsoleHandler) Handle(
_ context.Context,
record slog.Record,
@@ -56,8 +60,13 @@ func (c *ConsoleHandler) Handle(
line = 0
}
_, _ = fmt.Fprintln(
os.Stdout,
out := c.out
if out == nil {
out = os.Stdout
}
_, err := fmt.Fprintln(
out,
colorFunc(
"%s [%s] %s:%d: %s%s",
timestamp,
@@ -68,6 +77,9 @@ func (c *ConsoleHandler) Handle(
attrsToText(c.attrs.forRecord(record)),
),
)
if err != nil {
return fmt.Errorf("error writing log record: %w", err)
}
return nil
}
@@ -88,7 +100,7 @@ func (c *ConsoleHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return c
}
return &ConsoleHandler{attrs: c.attrs.withAttrs(attrs)}
return &ConsoleHandler{out: c.out, attrs: c.attrs.withAttrs(attrs)}
}
// WithGroup returns a new handler that qualifies later attributes with
@@ -98,5 +110,5 @@ func (c *ConsoleHandler) WithGroup(name string) slog.Handler {
return c
}
return &ConsoleHandler{attrs: c.attrs.withGroup(name)}
return &ConsoleHandler{out: c.out, attrs: c.attrs.withGroup(name)}
}
+162
View File
@@ -0,0 +1,162 @@
package simplelog
import (
"bytes"
"context"
"errors"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"testing"
"time"
)
// These tests sit inside the package so they can point a handler at a sink
// that fails, which callers outside the package cannot do.
// errSinkFailed is what failingWriter returns from every write.
var errSinkFailed = errors.New("sink failed")
// failingWriter is a sink whose every write fails.
type failingWriter struct{}
func (failingWriter) Write(_ []byte) (int, error) {
return 0, errSinkFailed
}
func errorTestRecord() slog.Record {
return slog.NewRecord(time.Now(), slog.LevelInfo, "casting", 0)
}
// The handler is derived with WithAttrs and WithGroup, so the test also
// fails if either of them drops the sink.
func TestJSONHandlerReturnsWriteError(t *testing.T) {
t.Parallel()
handler := (&JSONHandler{out: failingWriter{}}).
WithAttrs([]slog.Attr{slog.String("service", "cattbox")}).
WithGroup("cast")
err := handler.Handle(context.Background(), errorTestRecord())
if !errors.Is(err, errSinkFailed) {
t.Fatalf("Handle returned %v, want the sink's error", err)
}
}
func TestConsoleHandlerReturnsWriteError(t *testing.T) {
t.Parallel()
handler := (&ConsoleHandler{out: failingWriter{}}).
WithAttrs([]slog.Attr{slog.String("service", "cattbox")}).
WithGroup("cast")
err := handler.Handle(context.Background(), errorTestRecord())
if !errors.Is(err, errSinkFailed) {
t.Fatalf("Handle returned %v, want the sink's error", err)
}
}
// A failing handler must not stop the record reaching the handlers after
// it, and its error must still reach the caller.
func TestMultiplexHandlerDeliversPastFailingHandler(t *testing.T) {
t.Parallel()
var delivered bytes.Buffer
handler := &MultiplexHandler{handlers: []ExtendedHandler{
&JSONHandler{out: failingWriter{}},
&JSONHandler{out: &delivered},
}}
err := handler.Handle(context.Background(), errorTestRecord())
if !errors.Is(err, errSinkFailed) {
t.Fatalf("Handle returned %v, want the failing handler's error", err)
}
if !strings.Contains(delivered.String(), `"Message":"casting"`) {
t.Fatalf(
"second handler did not receive the record: %q",
delivered.String(),
)
}
}
// When more than one handler fails, the caller gets every failure, not
// only the first.
func TestMultiplexHandlerReturnsEveryFailure(t *testing.T) {
t.Parallel()
server := httptest.NewServer(http.HandlerFunc(
func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusInternalServerError)
},
))
defer server.Close()
webhook, err := NewWebhookHandler(server.URL)
if err != nil {
t.Fatalf("NewWebhookHandler: %v", err)
}
handler := &MultiplexHandler{handlers: []ExtendedHandler{
&JSONHandler{out: failingWriter{}},
webhook,
}}
err = handler.Handle(context.Background(), errorTestRecord())
if !errors.Is(err, errSinkFailed) {
t.Fatalf("Handle returned %v, want the JSON handler's error", err)
}
if !errors.Is(err, errWebhookStatus) {
t.Fatalf("Handle returned %v, want the webhook's error", err)
}
}
func TestWebhookHandlerReturnsErrorOnServerError(t *testing.T) {
t.Parallel()
server := httptest.NewServer(http.HandlerFunc(
func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusInternalServerError)
},
))
defer server.Close()
handler, err := NewWebhookHandler(server.URL)
if err != nil {
t.Fatalf("NewWebhookHandler: %v", err)
}
err = handler.Handle(context.Background(), errorTestRecord())
if !errors.Is(err, errWebhookStatus) {
t.Fatalf("Handle returned %v, want an error for the 500 answer", err)
}
}
// Following the redirect would resend the request as a GET without the
// record, and the GET is answered with 200, so only an error for the
// redirect itself tells the caller the record was lost.
func TestWebhookHandlerReturnsErrorOnRedirect(t *testing.T) {
t.Parallel()
server := httptest.NewServer(http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
if r.URL.Path != "/moved" {
http.Redirect(w, r, "/moved", http.StatusFound)
}
},
))
defer server.Close()
handler, err := NewWebhookHandler(server.URL)
if err != nil {
t.Fatalf("NewWebhookHandler: %v", err)
}
err = handler.Handle(context.Background(), errorTestRecord())
if !errors.Is(err, errWebhookStatus) {
t.Fatalf("Handle returned %v, want an error for the redirect", err)
}
}
+16 -4
View File
@@ -4,12 +4,16 @@ import (
"context"
"encoding/json"
"fmt"
"io"
"log/slog"
"os"
)
// JSONHandler writes each log record to stdout as a JSON document.
type JSONHandler struct {
// out is where records are written. Nil means os.Stdout, looked up on
// every write so that a reassigned os.Stdout is followed.
out io.Writer
attrs handlerAttrs
}
@@ -19,14 +23,22 @@ func NewJSONHandler() *JSONHandler {
}
// Handle marshals the record, with its attributes, to one JSON object and
// writes it to stdout.
// writes it to stdout. A failed write is returned as an error.
func (j *JSONHandler) Handle(_ context.Context, record slog.Record) error {
jsonData, err := json.Marshal(recordToMap(record, j.attrs))
if err != nil {
return err
}
_, _ = fmt.Fprintln(os.Stdout, string(jsonData))
out := j.out
if out == nil {
out = os.Stdout
}
_, err = fmt.Fprintln(out, string(jsonData))
if err != nil {
return fmt.Errorf("error writing log record: %w", err)
}
return nil
}
@@ -44,7 +56,7 @@ func (j *JSONHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return j
}
return &JSONHandler{attrs: j.attrs.withAttrs(attrs)}
return &JSONHandler{out: j.out, attrs: j.attrs.withAttrs(attrs)}
}
// WithGroup returns a new handler that nests later attributes in an
@@ -54,5 +66,5 @@ func (j *JSONHandler) WithGroup(name string) slog.Handler {
return j
}
return &JSONHandler{attrs: j.attrs.withGroup(name)}
return &JSONHandler{out: j.out, attrs: j.attrs.withGroup(name)}
}
+8 -4
View File
@@ -7,6 +7,7 @@ package simplelog
import (
"context"
"encoding/json"
"errors"
"log"
"log/slog"
"os"
@@ -62,20 +63,23 @@ func NewMultiplexHandler() slog.Handler {
return cl
}
// Handle forwards the record to every underlying handler, stopping at
// the first error.
// Handle forwards the record to every underlying handler, including the
// ones after a handler that fails. It returns the failures joined with
// errors.Join, or nil when every handler succeeded.
func (cl *MultiplexHandler) Handle(
ctx context.Context,
record slog.Record,
) error {
var errs []error
for _, handler := range cl.handlers {
err := handler.Handle(ctx, record)
if err != nil {
return err
errs = append(errs, err)
}
}
return nil
return errors.Join(errs...)
}
// Enabled reports whether the handler processes records at the given
+27 -3
View File
@@ -4,16 +4,22 @@ import (
"bytes"
"context"
"encoding/json"
"errors"
"fmt"
"log/slog"
"net/http"
"net/url"
)
// errWebhookStatus is returned when the webhook answers with a status
// outside 2xx.
var errWebhookStatus = errors.New("webhook did not accept the record")
// WebhookHandler POSTs each log record as JSON to a configured webhook
// URL.
type WebhookHandler struct {
webhookURL string
client *http.Client
attrs handlerAttrs
}
@@ -25,7 +31,17 @@ func NewWebhookHandler(webhookURL string) (*WebhookHandler, error) {
return nil, fmt.Errorf("invalid webhook URL: %w", err)
}
return &WebhookHandler{webhookURL: webhookURL}, nil
return &WebhookHandler{
webhookURL: webhookURL,
client: &http.Client{
// Following a redirect can resend the request as a GET
// without the record, so Handle gets the redirect answer
// itself and returns it as an error.
CheckRedirect: func(*http.Request, []*http.Request) error {
return http.ErrUseLastResponse
},
},
}, nil
}
// Enabled reports whether the handler processes records at the given
@@ -43,6 +59,7 @@ func (w *WebhookHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return &WebhookHandler{
webhookURL: w.webhookURL,
client: w.client,
attrs: w.attrs.withAttrs(attrs),
}
}
@@ -56,12 +73,14 @@ func (w *WebhookHandler) WithGroup(name string) slog.Handler {
return &WebhookHandler{
webhookURL: w.webhookURL,
client: w.client,
attrs: w.attrs.withGroup(name),
}
}
// Handle marshals the record, with its attributes, to one JSON object and
// POSTs it to the webhook URL.
// POSTs it to the webhook URL. It returns an error when the request fails
// or the server answers with a status outside 2xx.
func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error {
jsonData, err := json.Marshal(recordToMap(record, w.attrs))
if err != nil {
@@ -80,12 +99,17 @@ func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error {
request.Header.Set("Content-Type", "application/json")
response, err := http.DefaultClient.Do(request)
response, err := w.client.Do(request)
if err != nil {
return err
}
defer func() { _ = response.Body.Close() }()
if response.StatusCode < http.StatusOK ||
response.StatusCode >= http.StatusMultipleChoices {
return fmt.Errorf("%w: %s", errWebhookStatus, response.Status)
}
return nil
}