diff --git a/.github/workflows/testing.yml b/.github/workflows/testing.yml new file mode 100644 index 0000000..e0f299d --- /dev/null +++ b/.github/workflows/testing.yml @@ -0,0 +1,51 @@ +name: testing + +on: + push: + branches: [ master ] + pull_request: + branches: [ '**' ] + workflow_dispatch: + +jobs: + test: + name: Go tests + runs-on: ubuntu-latest + steps: + - name: Checkout + uses: actions/checkout@v4 + + - name: Set up Go + uses: actions/setup-go@v5 + with: + go-version: '1.24.x' + check-latest: true + + - name: Download deps + run: go mod download + + - name: Run tests + run: make test + + - name: Run tests with race-detector + run: make test-race + + golangci-lint: + runs-on: ubuntu-24.04 + steps: + - uses: actions/setup-go@v5 + - uses: actions/checkout@v5 + + - name: golangci-lint + uses: golangci/golangci-lint-action@v3 + continue-on-error: true + with: + # The first run is for GitHub Actions error format. + args: --config=.golangci.yaml + + - name: golangci-lint + uses: golangci/golangci-lint-action@v3 + with: + # The second run is for human-readable error format with a file name + # and a line number. + args: --out-${NO_FUTURE}format colored-line-number --config=.golangci.yaml diff --git a/.gitignore b/.gitignore new file mode 100644 index 0000000..0f4010c --- /dev/null +++ b/.gitignore @@ -0,0 +1,4 @@ +# IDE +.idea + +coverage.out \ No newline at end of file diff --git a/.golangci.yaml b/.golangci.yaml new file mode 100644 index 0000000..ae427a3 --- /dev/null +++ b/.golangci.yaml @@ -0,0 +1,48 @@ +run: + timeout: 5m + modules-download-mode: readonly + +issues: + exclude-use-default: false + max-same-issues: 0 + max-issues-per-linter: 0 + +linters: + enable: + - govet + - staticcheck + - revive + - errcheck + - gosimple + - ineffassign + - unused + - typecheck + - gofmt + - goimports + - misspell + - gocritic + +linters-settings: + revive: + severity: warning + rules: + - name: unused-parameter + - name: unreachable-code + - name: indent-error-flow + - name: exported + - name: blank-imports + - name: var-declaration + - name: if-return + + misspell: + locale: US + + goimports: + local-prefixes: github.com/tarantool/go-tlog + +# Skip linters on example files and any generated code +exclude-rules: + - path: ^_examples/ + linters: [revive, staticcheck, govet, gocritic] + - path: \.pb\.go$|_gen\.go$ + linters: [all] diff --git a/CHANGELOG.md b/CHANGELOG.md new file mode 100644 index 0000000..28a0851 --- /dev/null +++ b/CHANGELOG.md @@ -0,0 +1,24 @@ +# Changelog + +All notable changes to this project will be documented in this file. + +The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/) +and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.html). + +## [Unreleased] + +### Added + +- Core structured logging library for Go. +- Support for log levels: Trace, Debug, Info, Warn, Error. +- Text and JSON output formats. +- Multiple output destinations: stdout, stderr, file paths, multi-target. +- Automatic timestamp, source file and line number. +- Stacktrace collection for error-level messages. +- Test suite for core functionality. +- Idiomatic Go examples (testable examples). +- Makefile, GitHub Actions CI workflow, README, LICENSE, lint configuration. + +### Changed + +### Fixed \ No newline at end of file diff --git a/LICENCE b/LICENCE new file mode 100644 index 0000000..0e5bc0d --- /dev/null +++ b/LICENCE @@ -0,0 +1,29 @@ +BSD 2-Clause License + +Copyright (c) 2025, Tarantool AUTHORS +All rights reserved. + +Redistribution and use in source and binary forms, with or without +modification, are permitted provided that the following conditions are met: + +* Redistributions of source code must retain the above copyright notice, this + list of conditions and the following disclaimer. + +* Redistributions in binary form must reproduce the above copyright notice, + this list of conditions and the following disclaimer in the documentation + and/or other materials provided with the distribution. + +THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" +AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE +IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE +DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE +FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL +DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR +SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER +CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, +OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE +OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + +Portions of this software are derived from the Go standard library, +Copyright (c) The Go Authors, +and are used under the terms of the BSD-style license. \ No newline at end of file diff --git a/Makefile b/Makefile new file mode 100644 index 0000000..bfc4754 --- /dev/null +++ b/Makefile @@ -0,0 +1,42 @@ +# Default Go toolchain +GO ?= go +GOLANGCI_LINT ?= golangci-lint +PKG := github.com/tarantool/go-tlog + +.PHONY: all test test-race test-coverage lint fmt tidy help + +all: test + +## Run tests. +test: + $(GO) test ./... + +## Run tests with race detector. +test-race: + $(GO) test -race ./... + +## Run tests with coverage. +test-coverage: + $(GO) test -covermode=atomic -coverprofile=coverage.out ./... + +## Run golangci-lint. +lint: + $(GOLANGCI_LINT) run ./... --config=.golangci.yaml + +## Format source code. +fmt: + $(GO) fmt ./... + +## Tidy go.mod / go.sum. +tidy: + $(GO) mod tidy + +## Show available targets. +help: + @echo "Available targets:" + @echo " make test - run tests" + @echo " make test-race - run tests with -race" + @echo " make test-coverage - run tests with coverage" + @echo " make lint - run golangci-lint" + @echo " make fmt - format sources (gofmt)" + @echo " make tidy - go mod tidy" diff --git a/README.md b/README.md index 0b86c80..e62b6af 100644 --- a/README.md +++ b/README.md @@ -1 +1,179 @@ + + + + +[![Actions Status][actions-badge]][actions-url] +[![Telegram EN][telegram-badge]][telegram-en-url] +[![Telegram RU][telegram-badge]][telegram-ru-url] + +## Table of contents + +- [go-tlog](#go-tlog) + - [Features](#features) + - [Installation](#installation) + - [Quick start](#quick-start) + - [Configuration](#configuration) + - [type Opts](#type-opts) + - [Main API](#main-api) + - [Log levels](#log-levels) + - [Output formats](#output-formats) + - [Output destinations](#output-destinations) + - [Examples](#examples) + - [Testing](#testing) + - [License](#license) + # go-tlog + +`go-tlog` is a lightweight and configurable logging library for Go applications. +It provides structured logging with multiple output destinations, flexible formatting, +and fine-grained log-level control. + +--- + +## Features + +- Simple setup via configuration struct +- Text or JSON output formats +- Multiple output targets: **stdout**, **stderr**, **files** +- Log levels: `Trace`, `Debug`, `Info`, `Warn`, `Error` +- Automatic timestamp, source file, and line number +- Stacktrace for errors + +--- + +## Installation + +```bash +go get github.com/tarantool/go-tlog@latest +``` + +Then import: + +```go +import "github.com/tarantool/go-tlog" +``` + +--- + +## Quick start + +```go +package main + +import "github.com/tarantool/go-tlog" + +func main() { + log, err := tlog.New(tlog.Opts{ + Level: tlog.LevelInfo, + Format: tlog.FormatText, + Path: "stdout", + }) + if err != nil { + panic(err) + } + defer log.Close() + + logger := log.Logger().With(tlog.String("component", "demo")) + logger.Info("service started", "port", 8080) + logger.Error("failed to connect", "err", "timeout") +} +``` + +Output: + +``` +2025-11-10T13:30:01+05:00 INFO service started component=demo port=8080 +2025-11-10T13:30:01+05:00 ERROR failed to connect err=timeout component=demo stacktrace="..." +``` + +--- + +## Configuration + +### `type Opts` + +```go +type Opts struct { + Level Level // minimal log level + Format Format // FormatText or FormatJSON + Path string // comma-separated outputs: "stdout,/var/log/app.log" +} +``` + +### Main API + +| Function | Description | +|------------------|------------------------------------------| +| `tlog.New(opts)` | Create a new logger | +| `Logger()` | Return the underlying logger for use | +| `Close()` | Flush buffers and close file descriptors | + +--- + +## Log levels + +| Level | When to use | +|---------|---------------------------------------------| +| `Trace` | Low-level tracing | +| `Debug` | Debugging information | +| `Info` | Normal operational messages | +| `Warn` | Non-fatal warnings | +| `Error` | Errors and exceptions (includes stacktrace) | + +--- + +## Output formats + +| Format | Example | +|--------------|---------------------------------------------------------------| +| `FormatText` | `2025-11-10T13:31:45+05:00 INFO message key=value` | +| `FormatJSON` | `{"time":"...","level":"INFO","msg":"message","key":"value"}` | + +--- + +## Output destinations + +You can specify multiple targets separated by commas: + +```go +Path: "stdout,/tmp/app.log" +``` + +Supported targets: + +- `stdout` +- `stderr` +- File paths (created automatically if not present) + +--- + +## Examples + +Included examples: + +- **ExampleNew_text** — basic text logger writing to stdout +- **ExampleNew_json** — JSON logging +- **ExampleNew_multi** — logging to multiple destinations (`stdout,/tmp/...`) + +Each example demonstrates different combinations of Path, Format, and Level, +including how to log to multiple outputs at the same time. + +--- + +## Testing + +```bash +make test +``` + +--- + +## License + +BSD 2-Clause License — see [LICENSE](LICENSE) + +[actions-badge]: https://github.com/tarantool/go-tlog/actions/workflows/testing.yml/badge.svg +[actions-url]: https://github.com/tarantool/go-tlog/actions/workflows/testing.yml +[telegram-badge]: https://img.shields.io/badge/Telegram-join%20chat-blue.svg +[telegram-en-url]: http://telegram.me/tarantool +[telegram-ru-url]: http://telegram.me/tarantoolru diff --git a/example_test.go b/example_test.go new file mode 100644 index 0000000..442e075 --- /dev/null +++ b/example_test.go @@ -0,0 +1,58 @@ +package tlog_test + +import ( + "log/slog" + + "github.com/tarantool/go-tlog" +) + +// ExampleNew_text shows how to create a text logger that writes to stdout. +func ExampleNew_text() { + log, err := tlog.New(tlog.Opts{ + Level: tlog.LevelInfo, + Format: tlog.FormatText, + Path: "stdout", + }) + if err != nil { + panic(err) + } + defer func() { _ = log.Close() }() + + logger := log.Logger().With(slog.String("component", "example_text")) + logger.Info("service started") +} + +// ExampleNew_json shows how to create a JSON logger that writes to stdout. +func ExampleNew_json() { + log, err := tlog.New(tlog.Opts{ + Level: tlog.LevelInfo, + Format: tlog.FormatJSON, + Path: "stdout", + }) + if err != nil { + panic(err) + } + defer func() { _ = log.Close() }() + + logger := log.Logger().With( + slog.String("component", "example_json"), + slog.String("request_id", "abc-123"), + ) + logger.Error("request failed") +} + +// ExampleNew_multi shows how to log to multiple destinations at once. +func ExampleNew_multi() { + log, err := tlog.New(tlog.Opts{ + Level: tlog.LevelInfo, + Format: tlog.FormatText, + Path: "stdout,/tmp/tlog_example_multi.log", + }) + if err != nil { + panic(err) + } + defer func() { _ = log.Close() }() + + logger := log.Logger().With(slog.String("component", "example_multi")) + logger.Info("message written to stdout and file") +} diff --git a/format.go b/format.go new file mode 100644 index 0000000..4fc88ac --- /dev/null +++ b/format.go @@ -0,0 +1,13 @@ +package tlog + +// Format represents logger format. +type Format int + +const ( + // FormatDefault is the default format. Logger uses FormatText as a default one. + FormatDefault Format = iota + // FormatText prints messages as a human-readable text string. + FormatText Format = iota + // FormatJSON prints each message as a JSON object. + FormatJSON +) diff --git a/go.mod b/go.mod new file mode 100644 index 0000000..0dd7688 --- /dev/null +++ b/go.mod @@ -0,0 +1,11 @@ +module github.com/tarantool/go-tlog + +go 1.24 + +require github.com/stretchr/testify v1.11.1 + +require ( + github.com/davecgh/go-spew v1.1.1 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..c4c1710 --- /dev/null +++ b/go.sum @@ -0,0 +1,10 @@ +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U= +github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/internal/outputs/outputs.go b/internal/outputs/outputs.go new file mode 100644 index 0000000..7d65765 --- /dev/null +++ b/internal/outputs/outputs.go @@ -0,0 +1,104 @@ +package outputs + +import ( + "errors" + "fmt" + "io" + "io/fs" + "os" + "strings" +) + +// Outputs is io.WriteCloser for multiple output paths. +type Outputs struct { + files []*os.File + w io.Writer +} + +// New creates Outputs from comma-separated string of paths. +// Use "stdout" and "stderr" for os streams and file paths for files. +func New(paths string) (*Outputs, error) { + if paths == "" { + return nil, errors.New("empty paths") + } + + slice := splitPaths(paths) + + files := make([]*os.File, 0, len(slice)) + writers := make([]io.Writer, 0, len(slice)) + + for _, path := range slice { + file, err := openFile(path) + if err != nil { + _ = multiClose(files) + + return nil, fmt.Errorf("failed to open path %q: %w", path, err) + } + + files = append(files, file) + writers = append(writers, file) + } + + return &Outputs{ + files: files, + w: io.MultiWriter(writers...), + }, nil +} + +func splitPaths(paths string) []string { + if paths == "" { + return []string{} + } + + split := strings.Split(paths, ",") + + for i, path := range split { + split[i] = strings.TrimSpace(path) + } + + return split +} + +// https://github.com/uber-go/zap/blob/6d482535bdd97f4d97b2f9573ac308f1cf9b574e/sink.go#L158 +var defaultFilePerms uint32 = 0o666 + +func openFile(path string) (*os.File, error) { + switch path { + case "stdout": + // https://github.com/uber-go/zap/blob/6d482535bdd97f4d97b2f9573ac308f1cf9b574e/sink.go#L153-L154 + return os.Stdout, nil + // https://github.com/uber-go/zap/blob/6d482535bdd97f4d97b2f9573ac308f1cf9b574e/sink.go#L155-L156 + case "stderr": + return os.Stderr, nil + case "": + return nil, errors.New("empty path") + default: + return os.OpenFile(path, os.O_WRONLY|os.O_APPEND|os.O_CREATE, fs.FileMode(defaultFilePerms)) + } +} + +func multiClose(files []*os.File) error { + errs := make([]error, 0, len(files)) + + for _, file := range files { + switch file { + case os.Stdout, os.Stderr, nil: + continue + default: + errs = append(errs, file.Close()) + } + } + + return errors.Join(errs...) +} + +// Write writes p to all configured output destinations. +// It implements io.Writer and is used by slog handlers. +func (o *Outputs) Write(p []byte) (int, error) { + return o.w.Write(p) +} + +// Close closes all file outputs except stdout and stderr. +func (o *Outputs) Close() error { + return multiClose(o.files) +} diff --git a/internal/outputs/outputs_test.go b/internal/outputs/outputs_test.go new file mode 100644 index 0000000..f411d0d --- /dev/null +++ b/internal/outputs/outputs_test.go @@ -0,0 +1,150 @@ +package outputs_test + +import ( + "io" + "os" + "path/filepath" + "testing" + + "github.com/stretchr/testify/require" + + "github.com/tarantool/go-tlog/internal/outputs" +) + +// Assert *outputs.Outputs implements io.WriteCloser. +var _ io.WriteCloser = (*outputs.Outputs)(nil) + +func Test_New_BadPath(t *testing.T) { + require := require.New(t) + + _, err := outputs.New("/not/exist") + require.ErrorContains(err, "open /not/exist: no such file or directory") +} + +func Test_New_MultipleWithBadPath(t *testing.T) { + require := require.New(t) + + _, err := outputs.New("/dev/null,/not/exist") + require.ErrorContains(err, "open /not/exist: no such file or directory") +} + +func Test_New_EmptyPaths(t *testing.T) { + require := require.New(t) + + _, err := outputs.New("") + require.ErrorContains(err, "empty paths") +} + +func Test_New_MultipleWithEmptyPath(t *testing.T) { + require := require.New(t) + + _, err := outputs.New("/dev/null,") + require.ErrorContains(err, "empty path") +} + +func Test_Outputs_Std(t *testing.T) { + for _, tc := range []string{"stdout", "stderr"} { + t.Run(tc, func(t *testing.T) { + require := require.New(t) + + r, w, _ := os.Pipe() + + switch tc { + case "stdout": + orig := os.Stdout + os.Stdout = w + + defer func() { + os.Stdout = orig + }() + case "stderr": + orig := os.Stderr + os.Stderr = w + + defer func() { + os.Stderr = orig + }() + } + + outputs, err := outputs.New(tc) + require.NoError(err) + + _, err = outputs.Write([]byte("log_message")) + require.NoError(err) + + _ = w.Close() + + out, err := io.ReadAll(r) + require.NoError(err) + require.Contains(string(out), "log_message") + }) + } +} + +func Test_Outputs_File(t *testing.T) { + require := require.New(t) + + filename := filepath.Join(os.TempDir(), "Test_Outputs_File.log") + defer func(name string) { + _ = os.Remove(name) + }(filename) + + outputs, err := outputs.New(filename) + require.NoError(err) + + _, err = outputs.Write([]byte("log_message")) + require.NoError(err) + + out, err := os.ReadFile(filename) + require.NoError(err) + require.Contains(string(out), "log_message") +} + +func Test_Outputs_Multiple(t *testing.T) { + require := require.New(t) + + // Prepare file 1. + filename1 := filepath.Join(os.TempDir(), "Test_Outputs_Multiple1.log") + defer func(name string) { + _ = os.Remove(name) + }(filename1) + + // Prepare stdout. + r, w, _ := os.Pipe() + + origStdout := os.Stdout + os.Stdout = w + + defer func() { + os.Stdout = origStdout + }() + + // Prepare file 2. + filename2 := filepath.Join(os.TempDir(), "Test_Outputs_Multiple2.log") + defer func(name string) { + _ = os.Remove(name) + }(filename2) + + outputs, err := outputs.New(filename1 + ",stdout," + filename2) + require.NoError(err) + + _, err = outputs.Write([]byte("log_message")) + require.NoError(err) + + // Assert file 1 contents. + file1Out, err := os.ReadFile(filename1) + require.NoError(err) + require.Contains(string(file1Out), "log_message") + + // Assert stdout contents. + _ = w.Close() + + stdOut, err := io.ReadAll(r) + require.NoError(err) + require.Contains(string(stdOut), "log_message") + + // Assert file 2 contents. + file2Out, err := os.ReadFile(filename2) + require.NoError(err) + require.Contains(string(file2Out), "log_message") +} diff --git a/internal/slog/attr.go b/internal/slog/attr.go new file mode 100644 index 0000000..2046901 --- /dev/null +++ b/internal/slog/attr.go @@ -0,0 +1,14 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import ( + "log/slog" +) + +func attrIsEmpty(a slog.Attr) bool { + return a.Key == "" && a.Value.Uint64() == 0 && a.Value.Any() == nil +} diff --git a/internal/slog/buffer.go b/internal/slog/buffer.go new file mode 100644 index 0000000..3ff5d81 --- /dev/null +++ b/internal/slog/buffer.go @@ -0,0 +1,74 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import "sync" + +// buffer is a byte buffer. +// +// This implementation is adapted from the unexported type buffer +// in go/src/fmt/print.go. +type buffer []byte + +// Having an initial size gives a dramatic speedup. +var bufPool = sync.Pool{ + New: func() any { + b := make([]byte, 0, 1024) + return (*buffer)(&b) + }, +} + +func newBuffer() *buffer { + return bufPool.Get().(*buffer) +} + +// Free releases the buffer back to the pool. +func (b *buffer) Free() { + // To reduce peak allocation, return only smaller buffers to the pool. + const maxBufferSize = 16 << 10 + if cap(*b) <= maxBufferSize { + *b = (*b)[:0] + bufPool.Put(b) + } +} + +// Reset clears the buffer contents by setting its length to zero. +func (b *buffer) Reset() { + b.SetLen(0) +} + +// Write appends the provided bytes to the buffer. +func (b *buffer) Write(p []byte) (int, error) { + *b = append(*b, p...) + return len(p), nil +} + +// WriteString appends the provided string to the buffer. +func (b *buffer) WriteString(s string) (int, error) { + *b = append(*b, s...) + return len(s), nil +} + +// WriteByte appends a single byte to the buffer. +func (b *buffer) WriteByte(c byte) error { + *b = append(*b, c) + return nil +} + +// String returns the contents of the buffer as a string. +func (b *buffer) String() string { + return string(*b) +} + +// Len returns the number of bytes currently stored in the buffer. +func (b *buffer) Len() int { + return len(*b) +} + +// SetLen reslices the buffer to the specified length. +func (b *buffer) SetLen(n int) { + *b = (*b)[:n] +} diff --git a/internal/slog/handler.go b/internal/slog/handler.go new file mode 100644 index 0000000..3a11ac5 --- /dev/null +++ b/internal/slog/handler.go @@ -0,0 +1,402 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import ( + "fmt" + "io" + "log/slog" + "reflect" + "slices" + "strconv" + "sync" + "time" +) + +// HandlerOptions are options for a [TextHandler] or [JSONHandler]. +// A zero HandlerOptions consists entirely of default values. +type HandlerOptions struct { + slog.HandlerOptions + + // OmitBuiltinKeys removes "key=" parts of output for + // time, source, level and message. + OmitBuiltinKeys bool +} + +type commonHandler struct { + opts HandlerOptions + preformattedAttrs []byte + // groupPrefix is for the text handler only. + // It holds the prefix for groups that were already pre-formatted. + // A group will appear here when a call to WithGroup is followed by + // a call to WithAttrs. + groupPrefix string + groups []string // all groups started from WithGroup + nOpenGroups int // the number of groups opened in preformattedAttrs + mu *sync.Mutex + w io.Writer +} + +func (h *commonHandler) clone() *commonHandler { + // We can't use assignment because we can't copy the mutex. + return &commonHandler{ + opts: h.opts, + preformattedAttrs: slices.Clip(h.preformattedAttrs), + groupPrefix: h.groupPrefix, + groups: slices.Clip(h.groups), + nOpenGroups: h.nOpenGroups, + w: h.w, + mu: h.mu, // mutex shared among all clones of this handler + } +} + +// enabled reports whether l is greater than or equal to the +// minimum level. +func (h *commonHandler) enabled(l slog.Level) bool { + minLevel := slog.LevelInfo + if h.opts.Level != nil { + minLevel = h.opts.Level.Level() + } + return l >= minLevel +} + +func (h *commonHandler) withAttrs(as []slog.Attr) *commonHandler { + // We are going to ignore empty groups, so if the entire slice consists of + // them, there is nothing to do. + if countEmptyGroups(as) == len(as) { + return h + } + h2 := h.clone() + // Pre-format the attributes as an optimization. + state := h2.newHandleState((*buffer)(&h2.preformattedAttrs), false, "") + defer state.free() + state.prefix.WriteString(h.groupPrefix) + if pfa := h2.preformattedAttrs; len(pfa) > 0 { + state.sep = h.attrSep() + } + // Remember the position in the buffer, in case all attrs are empty. + pos := state.buf.Len() + state.openGroups() + if !state.appendAttrs(as) { + state.buf.SetLen(pos) + } else { + // Remember the new prefix for later keys. + h2.groupPrefix = state.prefix.String() + // Remember how many opened groups are in preformattedAttrs, + // so we don't open them again when we handle a Record. + h2.nOpenGroups = len(h2.groups) + } + return h2 +} + +func (h *commonHandler) withGroup(name string) *commonHandler { + h2 := h.clone() + h2.groups = append(h2.groups, name) + return h2 +} + +// handle is the internal implementation of Handler.Handle +// used by TextHandler and JSONHandler. +func (h *commonHandler) handle(r slog.Record) error { + state := h.newHandleState(newBuffer(), true, "") + defer state.free() + // Built-in attributes. They are not in a group. + stateGroups := state.groups + state.groups = nil // So ReplaceAttrs sees no groups instead of the pre groups. + rep := h.opts.ReplaceAttr + // time + if !r.Time.IsZero() { + key := slog.TimeKey + val := r.Time.Round(0) // strip monotonic to match Attr behavior + if rep == nil { + state.appendKey(key) + state.appendTime(val) + } else { + state.appendAttr(slog.Time(key, val)) + } + } + // level + key := slog.LevelKey + val := r.Level + if rep == nil { + state.appendKey(key) + state.appendString(val.String()) + } else { + state.appendAttr(slog.Any(key, val)) + } + // source + if h.opts.AddSource { + state.appendAttr(slog.Any(slog.SourceKey, source(r))) + } + key = slog.MessageKey + msg := r.Message + if rep == nil { + state.appendKey(key) + state.appendString(msg) + } else { + state.appendAttr(slog.String(key, msg)) + } + state.groups = stateGroups // Restore groups passed to ReplaceAttrs. + state.appendNonBuiltIns(r) + state.buf.WriteByte('\n') + + h.mu.Lock() + defer h.mu.Unlock() + _, err := h.w.Write(*state.buf) + return err +} + +func (s *handleState) appendNonBuiltIns(r slog.Record) { + // preformatted Attrs + if pfa := s.h.preformattedAttrs; len(pfa) > 0 { + s.buf.WriteString(s.sep) + s.buf.Write(pfa) + s.sep = s.h.attrSep() + } + // Attrs in Record -- unlike the built-in ones, they are in groups started + // from WithGroup. + // If the record has no Attrs, don't output any groups. + if r.NumAttrs() > 0 { + s.prefix.WriteString(s.h.groupPrefix) + // The group may turn out to be empty even though it has attrs (for + // example, ReplaceAttr may delete all the attrs). + // So remember where we are in the buffer, to restore the position + // later if necessary. + pos := s.buf.Len() + s.openGroups() + empty := true + r.Attrs(func(a slog.Attr) bool { + if s.appendAttr(a) { + empty = false + } + return true + }) + if empty { + s.buf.SetLen(pos) + } + } +} + +// attrSep returns the separator between attributes. +func (h *commonHandler) attrSep() string { + return " " +} + +// handleState holds state for a single call to commonHandler.handle. +// The initial value of sep determines whether to emit a separator +// before the next key, after which it stays true. +type handleState struct { + h *commonHandler + buf *buffer + freeBuf bool // should buf be freed? + sep string // separator to write before next key + prefix *buffer // for text: key prefix + groups *[]string // pool-allocated slice of active groups, for ReplaceAttr +} + +var groupPool = sync.Pool{New: func() any { + s := make([]string, 0, 10) + return &s +}} + +func (h *commonHandler) newHandleState(buf *buffer, freeBuf bool, sep string) handleState { + s := handleState{ + h: h, + buf: buf, + freeBuf: freeBuf, + sep: sep, + prefix: newBuffer(), + } + if h.opts.ReplaceAttr != nil { + s.groups = groupPool.Get().(*[]string) + *s.groups = append(*s.groups, h.groups[:h.nOpenGroups]...) + } + return s +} + +func (s *handleState) free() { + if s.freeBuf { + s.buf.Free() + } + if gs := s.groups; gs != nil { + *gs = (*gs)[:0] + groupPool.Put(gs) + } + s.prefix.Free() +} + +func (s *handleState) openGroups() { + for _, n := range s.h.groups[s.h.nOpenGroups:] { + s.openGroup(n) + } +} + +// Separator for group names and keys. +const keyComponentSep = '.' + +// openGroup starts a new group of attributes +// with the given name. +func (s *handleState) openGroup(name string) { + s.prefix.WriteString(name) + s.prefix.WriteByte(keyComponentSep) + // Collect group names for ReplaceAttr. + if s.groups != nil { + *s.groups = append(*s.groups, name) + } +} + +// closeGroup ends the group with the given name. +func (s *handleState) closeGroup(name string) { + (*s.prefix) = (*s.prefix)[:len(*s.prefix)-len(name)-1 /* for keyComponentSep */] + s.sep = s.h.attrSep() + if s.groups != nil { + *s.groups = (*s.groups)[:len(*s.groups)-1] + } +} + +// appendAttrs appends the slice of Attrs. +// It reports whether something was appended. +func (s *handleState) appendAttrs(as []slog.Attr) bool { + nonEmpty := false + for _, a := range as { + if s.appendAttr(a) { + nonEmpty = true + } + } + return nonEmpty +} + +// appendAttr appends the Attr's key and value. +// It handles replacement and checking for an empty key. +// It reports whether something was appended. +func (s *handleState) appendAttr(a slog.Attr) bool { + a.Value = a.Value.Resolve() + if rep := s.h.opts.ReplaceAttr; rep != nil && a.Value.Kind() != slog.KindGroup { + var gs []string + if s.groups != nil { + gs = *s.groups + } + // a.Value is resolved before calling ReplaceAttr, so the user doesn't have to. + a = rep(gs, a) + // The ReplaceAttr function may return an unresolved Attr. + a.Value = a.Value.Resolve() + } + // Elide empty Attrs. + if attrIsEmpty(a) { + return false + } + // Special case: Source. + if v := a.Value; v.Kind() == slog.KindAny { + if src, ok := v.Any().(*slog.Source); ok { + a.Value = slog.StringValue(fmt.Sprintf("%s:%d", src.File, src.Line)) + } + } + if a.Value.Kind() == slog.KindGroup { + attrs := a.Value.Group() + // Output only non-empty groups. + if len(attrs) > 0 { + // The group may turn out to be empty even though it has attrs (for + // example, ReplaceAttr may delete all the attrs). + // So remember where we are in the buffer, to restore the position + // later if necessary. + pos := s.buf.Len() + // Inline a group with an empty key. + if a.Key != "" { + s.openGroup(a.Key) + } + if !s.appendAttrs(attrs) { + s.buf.SetLen(pos) + return false + } + if a.Key != "" { + s.closeGroup(a.Key) + } + } + } else { + s.appendKey(a.Key) + s.appendValue(a.Value) + } + return true +} + +func (s *handleState) appendError(err error) { + s.appendString(fmt.Sprintf("!ERROR:%v", err)) +} + +func (s *handleState) appendKey(key string) { + s.buf.WriteString(s.sep) + s.writeKey(key) + s.sep = s.h.attrSep() +} + +func (s *handleState) writeKey(key string) { + if s.h.opts.OmitBuiltinKeys && isBuiltinKey(key) { + return + } + + if s.prefix != nil && len(*s.prefix) > 0 { + // TODO: optimize by avoiding allocation. + s.appendString(string(*s.prefix) + key) + } else { + s.appendString(key) + } + s.buf.WriteByte('=') +} + +func isBuiltinKey(key string) bool { + return (key == slog.TimeKey) || (key == slog.LevelKey) || + (key == slog.SourceKey) || (key == slog.MessageKey) +} + +func (s *handleState) appendString(str string) { + if needsQuoting(str) { + *s.buf = strconv.AppendQuote(*s.buf, str) + } else { + s.buf.WriteString(str) + } +} + +func (s *handleState) appendValue(v slog.Value) { + defer func() { + if r := recover(); r != nil { + // If it panics with a nil pointer, the most likely cases are + // an encoding.TextMarshaler or error fails to guard against nil, + // in which case "" seems to be the feasible choice. + // + // Adapted from the code in fmt/print.go. + if v := reflect.ValueOf(v.Any()); v.Kind() == reflect.Pointer && v.IsNil() { + s.appendString("") + return + } + + // Otherwise just print the original panic message. + s.appendString(fmt.Sprintf("!PANIC: %v", r)) + } + }() + + var err error + err = appendTextValue(s, v) + if err != nil { + s.appendError(err) + } +} + +func (s *handleState) appendTime(t time.Time) { + *s.buf = appendRFC3339Millis(*s.buf, t) +} + +func appendRFC3339Millis(b []byte, t time.Time) []byte { + // Format according to time.RFC3339Nano since it is highly optimized, + // but truncate it to use millisecond resolution. + // Unfortunately, that format trims trailing 0s, so add 1/10 millisecond + // to guarantee that there are exactly 4 digits after the period. + const prefixLen = len("2006-01-02T15:04:05.000") + n := len(b) + t = t.Truncate(time.Millisecond).Add(time.Millisecond / 10) + b = t.AppendFormat(b, time.RFC3339Nano) + b = append(b[:n+prefixLen], b[n+prefixLen+1:]...) // drop the 4th digit + return b +} diff --git a/internal/slog/json_handler.go b/internal/slog/json_handler.go new file mode 100644 index 0000000..010daa6 --- /dev/null +++ b/internal/slog/json_handler.go @@ -0,0 +1,109 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import ( + "unicode/utf8" +) + +var safeSet = [utf8.RuneSelf]bool{ + ' ': true, + '!': true, + '"': false, + '#': true, + '$': true, + '%': true, + '&': true, + '\'': true, + '(': true, + ')': true, + '*': true, + '+': true, + ',': true, + '-': true, + '.': true, + '/': true, + '0': true, + '1': true, + '2': true, + '3': true, + '4': true, + '5': true, + '6': true, + '7': true, + '8': true, + '9': true, + ':': true, + ';': true, + '<': true, + '=': true, + '>': true, + '?': true, + '@': true, + 'A': true, + 'B': true, + 'C': true, + 'D': true, + 'E': true, + 'F': true, + 'G': true, + 'H': true, + 'I': true, + 'J': true, + 'K': true, + 'L': true, + 'M': true, + 'N': true, + 'O': true, + 'P': true, + 'Q': true, + 'R': true, + 'S': true, + 'T': true, + 'U': true, + 'V': true, + 'W': true, + 'X': true, + 'Y': true, + 'Z': true, + '[': true, + '\\': false, + ']': true, + '^': true, + '_': true, + '`': true, + 'a': true, + 'b': true, + 'c': true, + 'd': true, + 'e': true, + 'f': true, + 'g': true, + 'h': true, + 'i': true, + 'j': true, + 'k': true, + 'l': true, + 'm': true, + 'n': true, + 'o': true, + 'p': true, + 'q': true, + 'r': true, + 's': true, + 't': true, + 'u': true, + 'v': true, + 'w': true, + 'x': true, + 'y': true, + 'z': true, + '{': true, + '|': true, + '}': true, + '~': true, + '\u007f': true, +} diff --git a/internal/slog/record.go b/internal/slog/record.go new file mode 100644 index 0000000..fe55d48 --- /dev/null +++ b/internal/slog/record.go @@ -0,0 +1,25 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import ( + "log/slog" + "runtime" +) + +// source returns a Source for the log event. +// If the Record was created without the necessary information, +// or if the location is unavailable, it returns a non-nil *Source +// with zero fields. +func source(r slog.Record) *slog.Source { + fs := runtime.CallersFrames([]uintptr{r.PC}) + f, _ := fs.Next() + return &slog.Source{ + Function: f.Function, + File: f.File, + Line: f.Line, + } +} diff --git a/internal/slog/text_handler.go b/internal/slog/text_handler.go new file mode 100644 index 0000000..3aeb0c7 --- /dev/null +++ b/internal/slog/text_handler.go @@ -0,0 +1,164 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import ( + "context" + "encoding" + "fmt" + "io" + "log/slog" + "reflect" + "strconv" + "sync" + "unicode" + "unicode/utf8" +) + +// TextHandler is a [Handler] that writes Records to an [io.Writer] as a +// sequence of key=value pairs separated by spaces and followed by a newline. +type TextHandler struct { + *commonHandler +} + +// NewTextHandler creates a [TextHandler] that writes to w, +// using the given options. +// If opts is nil, the default options are used. +func NewTextHandler(w io.Writer, opts *HandlerOptions) *TextHandler { + if opts == nil { + opts = &HandlerOptions{} + } + return &TextHandler{ + &commonHandler{ + w: w, + opts: *opts, + mu: &sync.Mutex{}, + }, + } +} + +// Enabled reports whether the handler handles records at the given level. +// The handler ignores records whose level is lower. +func (h *TextHandler) Enabled(_ context.Context, level slog.Level) bool { + return h.commonHandler.enabled(level) +} + +// WithAttrs returns a new [TextHandler] whose attributes consists +// of h's attributes followed by attrs. +func (h *TextHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + return &TextHandler{commonHandler: h.commonHandler.withAttrs(attrs)} +} + +func (h *TextHandler) WithGroup(name string) slog.Handler { + return &TextHandler{commonHandler: h.commonHandler.withGroup(name)} +} + +// Handle formats its argument [Record] as a single line of space-separated +// key=value items. +// +// If the Record's time is zero, the time is omitted. +// Otherwise, the key is "time" +// and the value is output in RFC3339 format with millisecond precision. +// +// If the Record's level is zero, the level is omitted. +// Otherwise, the key is "level" +// and the value of [Level.String] is output. +// +// If the AddSource option is set and source information is available, +// the key is "source" and the value is output as FILE:LINE. +// +// The message's key is "msg". +// +// To modify these or other attributes, or remove them from the output, use +// [HandlerOptions.ReplaceAttr]. +// +// If a value implements [encoding.TextMarshaler], the result of MarshalText is +// written. Otherwise, the result of [fmt.Sprint] is written. +// +// Keys and values are quoted with [strconv.Quote] if they contain Unicode space +// characters, non-printing characters, '"' or '='. +// +// Keys inside groups consist of components (keys or group names) separated by +// dots. No further escaping is performed. +// Thus there is no way to determine from the key "a.b.c" whether there +// are two groups "a" and "b" and a key "c", or a single group "a.b" and a key "c", +// or single group "a" and a key "b.c". +// If it is necessary to reconstruct the group structure of a key +// even in the presence of dots inside components, use +// [HandlerOptions.ReplaceAttr] to encode that information in the key. +// +// Each call to Handle results in a single serialized call to +// io.Writer.Write. +func (h *TextHandler) Handle(_ context.Context, r slog.Record) error { + return h.commonHandler.handle(r) +} + +func appendTextValue(s *handleState, v slog.Value) error { + switch v.Kind() { + case slog.KindString: + s.appendString(v.String()) + case slog.KindTime: + s.appendTime(v.Time()) + case slog.KindAny: + if tm, ok := v.Any().(encoding.TextMarshaler); ok { + data, err := tm.MarshalText() + if err != nil { + return err + } + // TODO: avoid the conversion to string. + s.appendString(string(data)) + return nil + } + if bs, ok := byteSlice(v.Any()); ok { + // As of Go 1.19, this only allocates for strings longer than 32 bytes. + s.buf.WriteString(strconv.Quote(string(bs))) + return nil + } + s.appendString(fmt.Sprintf("%+v", v.Any())) + default: + *s.buf = appendValue(v, *s.buf) + } + return nil +} + +// byteSlice returns its argument as a []byte if the argument's +// underlying type is []byte, along with a second return value of true. +// Otherwise it returns nil, false. +func byteSlice(a any) ([]byte, bool) { + if bs, ok := a.([]byte); ok { + return bs, true + } + // Like Printf's %s, we allow both the slice type and the byte element type to be named. + t := reflect.TypeOf(a) + if t != nil && t.Kind() == reflect.Slice && t.Elem().Kind() == reflect.Uint8 { + return reflect.ValueOf(a).Bytes(), true + } + return nil, false +} + +func needsQuoting(s string) bool { + if len(s) == 0 { + return true + } + for i := 0; i < len(s); { + b := s[i] + if b < utf8.RuneSelf { + // Quote anything except a backslash that would need quoting in a + // JSON string, as well as space and '=' + if b != '\\' && (b == ' ' || b == '=' || !safeSet[b]) { + return true + } + i++ + continue + } + r, size := utf8.DecodeRuneInString(s[i:]) + if r == utf8.RuneError || unicode.IsSpace(r) || !unicode.IsPrint(r) { + return true + } + i += size + } + return false +} diff --git a/internal/slog/text_handler_test.go b/internal/slog/text_handler_test.go new file mode 100644 index 0000000..a07be13 --- /dev/null +++ b/internal/slog/text_handler_test.go @@ -0,0 +1,40 @@ +package slog_test + +import ( + "bytes" + "log/slog" + "strings" + "testing" + + "github.com/stretchr/testify/require" + + slogcustom "github.com/tarantool/go-tlog/internal/slog" +) + +func Test_TextHandler_OmitBuiltinKeys(t *testing.T) { + require := require.New(t) + + var b bytes.Buffer + + handler := slogcustom.NewTextHandler(&b, &slogcustom.HandlerOptions{ + HandlerOptions: slog.HandlerOptions{AddSource: true}, + OmitBuiltinKeys: true, + }) + l := slog.New(handler) + + l.Info("my message") + + out := strings.TrimSpace(b.String()) + + require.NotContains(out, "time=") + require.Regexp(`^20\d\d\-\d\d\-\d\dT\d\d:\d\d:\d\d.*$`, out) + + require.NotContains(out, "level=") + require.Contains(out, "INFO") + + require.NotContains(out, "source=") + require.Contains(out, "internal/slog/text_handler_test.go:25") + + require.NotContains(out, "msg=") + require.Contains(out, "my message") +} diff --git a/internal/slog/value.go b/internal/slog/value.go new file mode 100644 index 0000000..7e3a29f --- /dev/null +++ b/internal/slog/value.go @@ -0,0 +1,61 @@ +// Copyright 2022 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// nolint +package slog + +import ( + "fmt" + "log/slog" + "strconv" +) + +// countEmptyGroups returns the number of empty group values in its argument. +func countEmptyGroups(as []slog.Attr) int { + n := 0 + for _, a := range as { + if isEmptyGroup(a.Value) { + n++ + } + } + return n +} + +// isEmptyGroup reports whether v is a group that has no attributes. +func isEmptyGroup(v slog.Value) bool { + if v.Kind() != slog.KindGroup { + return false + } + // We do not need to recursively examine the group's Attrs for emptiness, + // because GroupValue removed them when the group was constructed, and + // groups are immutable. + return len(v.Group()) == 0 +} + +// appendValue appends a text representation of v to dst. +// v is formatted as with fmt.Sprint. +func appendValue(v slog.Value, dst []byte) []byte { + switch v.Kind() { + case slog.KindString: + return append(dst, v.String()...) + case slog.KindInt64: + return strconv.AppendInt(dst, v.Int64(), 10) + case slog.KindUint64: + return strconv.AppendUint(dst, v.Uint64(), 10) + case slog.KindFloat64: + return strconv.AppendFloat(dst, v.Float64(), 'g', -1, 64) + case slog.KindBool: + return strconv.AppendBool(dst, v.Bool()) + case slog.KindDuration: + return append(dst, v.Duration().String()...) + case slog.KindTime: + return append(dst, v.Time().String()...) + case slog.KindGroup: + return fmt.Append(dst, v.Group()) + case slog.KindAny, slog.KindLogValuer: + return fmt.Append(dst, v.Any()) + default: + panic(fmt.Sprintf("bad kind: %s", v.Kind())) + } +} diff --git a/internal/stacktrace/stacktrace.go b/internal/stacktrace/stacktrace.go new file mode 100644 index 0000000..f8937a0 --- /dev/null +++ b/internal/stacktrace/stacktrace.go @@ -0,0 +1,63 @@ +package stacktrace + +import ( + "runtime" + "strconv" + "strings" +) + +// Get returns a formatted stacktrace starting from the specified number of frames to skip. +func Get(skip int) string { + frames := getFrames(skip) + + var b strings.Builder + + for { + frame, more := frames.Next() + + writeFrame(&b, frame) + + if !more { + break + } + + b.WriteByte('\n') + } + + return b.String() +} + +const ( + defaultProgramCounters = 64 + + // runtime.Counters, Get and getFrames. + baseNestingLevel = 3 + + pcsExtendFactor = 2 +) + +func getFrames(skip int) *runtime.Frames { + pcs := make([]uintptr, defaultProgramCounters) + + for { + n := runtime.Callers(baseNestingLevel+skip, pcs) + if n < cap(pcs) { + pcs = pcs[:n] + + break + } + + pcs = make([]uintptr, len(pcs)*pcsExtendFactor) + } + + return runtime.CallersFrames(pcs) +} + +func writeFrame(b *strings.Builder, frame runtime.Frame) { + b.WriteString(frame.Function) + b.WriteByte('\n') + b.WriteByte('\t') + b.WriteString(frame.File) + b.WriteByte(':') + b.WriteString(strconv.Itoa(frame.Line)) +} diff --git a/internal/stacktrace/stacktrace_test.go b/internal/stacktrace/stacktrace_test.go new file mode 100644 index 0000000..a5505c4 --- /dev/null +++ b/internal/stacktrace/stacktrace_test.go @@ -0,0 +1,30 @@ +package stacktrace_test + +import ( + "testing" + + "github.com/stretchr/testify/require" + + "github.com/tarantool/go-tlog/internal/stacktrace" +) + +func funcNested() string { + // Skip funcNested, include funcWrapper. + return stacktrace.Get(1) +} + +func funcWrapper() string { + return funcNested() +} + +func Test_Get(t *testing.T) { + require := require.New(t) + + stack := funcWrapper() + + require.Contains(stack, "internal/stacktrace/stacktrace_test.go:17") + require.Contains(stack, "funcWrapper") + + require.NotContains(stack, "internal/stacktrace/stacktrace_test.go:12") + require.NotContains(stack, "funcNested") +} diff --git a/level.go b/level.go new file mode 100644 index 0000000..c6ef86c --- /dev/null +++ b/level.go @@ -0,0 +1,19 @@ +package tlog + +// Level represents logger level. +type Level int + +const ( + // LevelDefault is the default level. Logger uses LevelInfo as a default one. + LevelDefault Level = iota + // LevelTrace prints messages up to Debug. Messages up to Debug have stacktraces. + LevelTrace + // LevelDebug prints messages up to Debug. Messages up to Error have stacktraces. + LevelDebug + // LevelInfo prints messages up to Info. Messages up to Error have stacktraces. + LevelInfo + // LevelWarn prints messages up to Warn. Messages up to Error have stacktraces. + LevelWarn + // LevelError prints messages up to Error. Messages up to Error have stacktraces. + LevelError +) diff --git a/logger.go b/logger.go new file mode 100644 index 0000000..a2ad7fc --- /dev/null +++ b/logger.go @@ -0,0 +1,125 @@ +package tlog + +import ( + "fmt" + "log/slog" + "time" + + "github.com/tarantool/go-tlog/internal/outputs" + slogcustom "github.com/tarantool/go-tlog/internal/slog" +) + +// Logger contains slog.Logger for several outputs +// and method to close these outputs. +type Logger struct { + outputs *outputs.Outputs + logger *slog.Logger +} + +// Opts are New options. +type Opts struct { + // Level sets minimum level for the logger. + Level Level + // Format sets log format. + Format Format + // Path is comma-separated list of log outputs. + // Use "stdout" and "stderr" for os streams and file paths for files. + // Default is "stderr". + Path string +} + +// New creates a new Logger with the given options. +// It configures level, format and output destinations and returns +// a ready-to-use logger instance. +func New(opts Opts) (*Logger, error) { + var ( + logLevel slog.Level + traceLevel slog.Level + ) + + switch opts.Level { + case LevelTrace: + traceLevel = slog.LevelDebug + logLevel = slog.LevelDebug + case LevelDebug: + traceLevel = slog.LevelError + logLevel = slog.LevelDebug + case LevelDefault: + fallthrough + case LevelInfo: + traceLevel = slog.LevelError + logLevel = slog.LevelInfo + case LevelWarn: + traceLevel = slog.LevelError + logLevel = slog.LevelWarn + case LevelError: + traceLevel = slog.LevelError + logLevel = slog.LevelError + } + + if opts.Path == "" { + // https://github.com/uber-go/zap/blob/6d482535bdd97f4d97b2f9573ac308f1cf9b574e/config.go#L167C31-L167C37 + opts.Path = "stderr" + } + + outs, err := outputs.New(opts.Path) + if err != nil { + return nil, fmt.Errorf("failed to create outputs: %w", err) + } + + handlerOpts := slog.HandlerOptions{ + Level: logLevel, + ReplaceAttr: replaceAttr, + AddSource: true, + } + + var baseHandler slog.Handler + + switch opts.Format { + case FormatDefault: + fallthrough + case FormatText: + baseHandler = slogcustom.NewTextHandler(outs, &slogcustom.HandlerOptions{ + HandlerOptions: handlerOpts, + OmitBuiltinKeys: true, + }) + case FormatJSON: + baseHandler = slog.NewJSONHandler(outs, &handlerOpts) + } + + handler := newStacktraceHandler(baseHandler, traceLevel) + l := slog.New(handler) + + return &Logger{ + outputs: outs, + logger: l, + }, nil +} + +func replaceAttr(group []string, a slog.Attr) slog.Attr { + switch a.Key { + case slog.TimeKey: + return replaceTime(group, a) + default: + return a + } +} + +func replaceTime(_ []string, a slog.Attr) slog.Attr { + t := a.Value.Time() + + a.Value = slog.StringValue(t.Format(time.RFC3339)) + + return a +} + +// Logger returns the underlying slog.Logger instance. +// It can be used directly to log messages with additional attributes. +func (l *Logger) Logger() *slog.Logger { + return l.logger +} + +// Close flushes all pending log entries and closes all opened outputs. +func (l *Logger) Close() error { + return l.outputs.Close() +} diff --git a/logger_test.go b/logger_test.go new file mode 100644 index 0000000..b42724e --- /dev/null +++ b/logger_test.go @@ -0,0 +1,207 @@ +package tlog_test + +import ( + "log/slog" + "os" + "path/filepath" + "testing" + + "github.com/stretchr/testify/require" + + "github.com/tarantool/go-tlog" +) + +func Test_Logger(t *testing.T) { + t.Parallel() + + testCases := []struct { + name string + // Test assertions expect single file opts.Path. + opts tlog.Opts + log func(l *slog.Logger) + assert func(require *require.Assertions, logs string) + }{ + { + name: "InfoMessage_DebugTextLogger", + opts: tlog.Opts{ + Level: tlog.LevelDebug, + Format: tlog.FormatText, + Path: "InfoMessage_DebugPlainLogger.log", + }, + log: func(l *slog.Logger) { + l.Info("my info message") + // Example: + // 2025-02-19T13:51:31+03:00 INFO tlog_test.go: "my info message" + }, + assert: func(require *require.Assertions, logs string) { + require.Contains(logs, "my info message") + require.NotContains(logs, "stacktrace=") + }, + }, + { + name: "ErrorMessage_DebugTextLogger", + opts: tlog.Opts{ + Level: tlog.LevelDebug, + Format: tlog.FormatText, + Path: "ErrorMessage_DebugPlainLogger.log", + }, + log: func(l *slog.Logger) { + l.Error("my error message") + // 2025-02-19T13:52:11+03:00 ERROR logger_test.go:46 "my error message" + // stacktrace="github.com/tarantool/go-tlog_test.Test_Logger.funcY + // logger_test.go: + // logger_test.Test_Logger.funcX + // logger_test.go: + // testing.tRunner + // /usr/local/go/src/testing/testing.go: + // runtime.goexit + // /usr/local/go/src/runtime/asm_amd64.s:" + }, + assert: func(require *require.Assertions, logs string) { + require.Contains(logs, "my error message") + require.Contains(logs, "stacktrace=") + require.Contains(logs, "tlog_test.Test_Logger") + }, + }, + { + name: "InfoMessage_ErrorTextLogger", + opts: tlog.Opts{ + Level: tlog.LevelError, + Format: tlog.FormatText, + Path: "InfoMessage_ErrorPlainLogger.log", + }, + log: func(l *slog.Logger) { + l.Info("my info message") + }, + assert: func(require *require.Assertions, logs string) { + require.NotContains(logs, "my info message") + }, + }, + { + name: "InfoMessage_TraceTextLogger", + opts: tlog.Opts{ + Level: tlog.LevelTrace, + Format: tlog.FormatText, + Path: "InfoMessage_TraceTextLogger.log", + }, + log: func(l *slog.Logger) { + l.Info("my info message") + // Example (shortened): + // 2025-02-19T13:54:00+03:00 INFO tlog_test.go: "my info message" + // stacktrace="github.com/tarantool/go-tlog_test.Test_Logger.funcY + // logger_test.go: + // logger_test.Test_Logger.funcX + // logger_test.go: + // testing.tRunner + // /usr/local/go/src/testing/testing.go: + // runtime.goexit + // /usr/local/go/src/runtime/asm_amd64.s:" + }, + assert: func(require *require.Assertions, logs string) { + require.Contains(logs, "my info message") + require.Contains(logs, "stacktrace=") + require.Contains(logs, "tlog_test.Test_Logger") + }, + }, + { + name: "InfoMessage_DefaultLogger", + opts: tlog.Opts{ + // Level and Format will be defaulted by New. + Path: "InfoMessage_DefaultLogger.log", + }, + log: func(l *slog.Logger) { + l.Warn("my info message") + }, + assert: func(require *require.Assertions, logs string) { + require.Contains(logs, "my info message") + }, + }, + { + name: "InfoMessage_DebugJSONLogger", + opts: tlog.Opts{ + Level: tlog.LevelDebug, + Format: tlog.FormatJSON, + Path: "InfoMessage_DebugPlainLogger.json", + }, + log: func(l *slog.Logger) { + l.Info("my info message") + // Example (shortened): + // { + // "time":"2025-02-19T13:55:16+03:00", + // "level":"INFO", + // "source":{ + // "function":"github.com/tarantool/go-tlog_test.Test_Logger.funcZ", + // "file":"tlog_test.go", + // "line": + // }, + // "msg":"my info message" + // } + }, + assert: func(require *require.Assertions, logs string) { + require.Contains(logs, `"msg":"my info message"`) + require.NotContains(logs, `"stacktrace"`) + }, + }, + { + name: "ErrorMessage_DebugJSONLogger", + opts: tlog.Opts{ + Level: tlog.LevelDebug, + Format: tlog.FormatJSON, + Path: "ErrorMessage_DebugJSONLogger.json", + }, + log: func(l *slog.Logger) { + l.Error("my error message") + // Example (shortened): + // { + // "time":"2025-02-19T13:56:56+03:00", + // "level":"ERROR", + // "source":{ + // "function":"github.com/tarantool/go-tlog_test.Test_Logger.funcN", + // "file":"tlog_test.go", + // "line": + // }, + // "msg":"my error message", + // "stacktrace":"github.com/tarantool/go-tlog_test.Test_Logger.funcN\n + // \ttlog_test.go:\n + // testing.tRunner\n + // \truntime.goexit" + // } + }, + assert: func(require *require.Assertions, logs string) { + require.Contains(logs, `"msg":"my error message"`) + require.Contains(logs, `"stacktrace":"`) + require.Contains(logs, "tlog_test.Test_Logger") + }, + }, + } + + for _, tc := range testCases { + tc := tc + + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + + r := require.New(t) + + tmpDir := t.TempDir() + tc.opts.Path = filepath.Join(tmpDir, tc.opts.Path) + + l, err := tlog.New(tc.opts) + r.NoError(err) + + defer func() { + _ = l.Close() + }() + + tc.log(l.Logger()) + + logs, err := os.ReadFile(tc.opts.Path) + r.NoError(err) + + // If there are stacktraces, there are no redundant internal frames. + r.NotContains(string(logs), "slog.(*Logger).") + + tc.assert(r, string(logs)) + }) + } +} diff --git a/stacktrace.go b/stacktrace.go new file mode 100644 index 0000000..6e0e2c8 --- /dev/null +++ b/stacktrace.go @@ -0,0 +1,33 @@ +package tlog + +import ( + "context" + "log/slog" + + "github.com/tarantool/go-tlog/internal/stacktrace" +) + +type stacktraceHandler struct { + slog.Handler + + fromLevel slog.Level +} + +func newStacktraceHandler(h slog.Handler, fromLevel slog.Level) stacktraceHandler { + return stacktraceHandler{ + Handler: h, + fromLevel: fromLevel, + } +} + +// Strip stacktraceHandler.Handle, slog.(*Logger).log and +// slog.(*Logger).. +var internalsStripLevel = 3 + +func (h stacktraceHandler) Handle(ctx context.Context, record slog.Record) error { + if record.Level >= h.fromLevel { + record.Add("stacktrace", stacktrace.Get(internalsStripLevel)) + } + + return h.Handler.Handle(ctx, record) +}