From dda9705ee63837268f64b872fe1354e55ac449ed Mon Sep 17 00:00:00 2001 From: Laurent Demailly Date: Tue, 21 Nov 2023 23:25:27 -0800 Subject: [PATCH] Switch to slog for go1.21 and use latest fortio log (#13) * Switch to slog for go1.21 and use latest fortio log * linter fix * go mod init + put back replace comments * codeql doesn't grok go 1.21.4 in go.mod * Add results --- .github/workflows/gochecks.yml | 2 +- README.md | 50 ++++++++++++++++++++++++++++++++++ go.mod | 9 +++--- go.sum | 14 +++++++--- slog.go | 2 +- 5 files changed, 66 insertions(+), 11 deletions(-) diff --git a/.github/workflows/gochecks.yml b/.github/workflows/gochecks.yml index d1f97eb..5b08f87 100644 --- a/.github/workflows/gochecks.yml +++ b/.github/workflows/gochecks.yml @@ -16,7 +16,7 @@ jobs: - name: Setup Go environment uses: actions/setup-go@v4 with: - go-version: '1.20' + go-version: '1.21' check-latest: true - name: Run golangci-lint uses: golangci/golangci-lint-action@v3 diff --git a/README.md b/README.md index 881472c..e1ccc00 100644 --- a/README.md +++ b/README.md @@ -20,3 +20,53 @@ Currently the output looks like this for each logger: {"ts":1692131243.359859,"level":"INFO","msg":"A visible log entry with 3 attributes","iteration":1,"id":"R3","logger":"sloggr"} {"ts":1692131314.582912,"level":"info","msg":"A visible log entry with 3 attributes","iteration":"1","id":"R3","logger":"fortio"} ``` + + +## Results + +For 1M logs logged and 10M logs issued: + +### Fortio +```bash +$ time go run . fortio -n 100000 2>&1 | head -2 +```json +{"ts":1700637382.217323,"level":"info","msg":"Starting","command":"logger-bench","version":"dev go1.21.4 arm64 darwin","go-max-procs":10} +{"ts":1700637382.217334,"level":"info","msg":"Testing","logger":"fortio","num-calls":100000,"num-extra":9,"num-goroutines":10,"gomaxprocs":10,"profile":""} +``` +```bash +real 0m0.515s +user 0m0.357s +sys 0m0.285s +``` + +### Slog + +```bash +$ time go run . slog -n 100000 2>&1 | head -2 +``` +```json +{"ts":1700637390.850496,"level":"info","msg":"Starting","command":"logger-bench","version":"dev go1.21.4 arm64 darwin","go-max-procs":10} +{"ts":1700637390.850510,"level":"info","msg":"Testing","logger":"slog","num-calls":100000,"num-extra":9,"num-goroutines":10,"gomaxprocs":10,"profile":""} +``` +```bash +real 0m0.548s +user 0m0.361s +sys 0m0.295s +``` + +### Zap +```bash +$ time go run . zap -n 100000 2>&1 | head -2 +```json +{"ts":1700637401.684503,"level":"info","msg":"Starting","command":"logger-bench","version":"dev go1.21.4 arm64 darwin","go-max-procs":10} +{"ts":1700637401.684517,"level":"info","msg":"Testing","logger":"zap","num-calls":100000,"num-extra":9,"num-goroutines":10,"gomaxprocs":10,"profile":""} +``` +```bash +real 0m0.513s +user 0m0.358s +sys 0m0.295s +``` + +## Conclusion + +All 3 are about the same performance, with zap marginally about 1% faster than fortio and slog slowest at about 6% slower than fortio. diff --git a/go.mod b/go.mod index d8a5d6c..0bed0fc 100644 --- a/go.mod +++ b/go.mod @@ -1,18 +1,16 @@ module github.com/fortio/logger-bench -go 1.20 +go 1.21 require ( - fortio.org/cli v1.5.0 + fortio.org/cli v1.5.1 fortio.org/log v1.12.0 - fortio.org/scli v1.13.0 + fortio.org/scli v1.13.1 fortio.org/sets v1.0.3 go.uber.org/zap v1.26.0 - golang.org/x/exp v0.0.0-20231110203233-9a3e6036ecaa ) // replace fortio.org/log => ../log - // replace fortio.org/cli => ../cli require ( @@ -21,5 +19,6 @@ require ( fortio.org/version v1.0.3 // indirect github.com/fsnotify/fsnotify v1.7.0 // indirect go.uber.org/multierr v1.10.0 // indirect + golang.org/x/exp v0.0.0-20231110203233-9a3e6036ecaa // indirect golang.org/x/sys v0.14.0 // indirect ) diff --git a/go.sum b/go.sum index ea7e984..6c1befd 100644 --- a/go.sum +++ b/go.sum @@ -1,12 +1,13 @@ fortio.org/assert v1.2.0 h1:XscfvR8yp4xW7OMCvNbCsieRFDxlwdEcb69+JZRp6LA= -fortio.org/cli v1.5.0 h1:hKiXZ6jWzLHCVInrRm8F3BI3nyj0EpM5rAYFUp/d8gs= -fortio.org/cli v1.5.0/go.mod h1:Tp7AypudP1mJomTUN/J/vlOTlZDWTMsok09MMyA99ow= +fortio.org/assert v1.2.0/go.mod h1:039mG+/iYDPO8Ibx8TrNuJCm2T2SuhwRI3uL9nHTTls= +fortio.org/cli v1.5.1 h1:lqPvkxRVSajsVwLfblaN62BPAICPp05Oab+yjRvI3DU= +fortio.org/cli v1.5.1/go.mod h1:Tp7AypudP1mJomTUN/J/vlOTlZDWTMsok09MMyA99ow= fortio.org/dflag v1.7.0 h1:4Vpo5hMly0rx9VMuyBaDGFK1Mx2S3qjxx1iAIA3KBgU= fortio.org/dflag v1.7.0/go.mod h1:FUxv/s3DXhCpy7GsuZa4FJWLR92gsYvG3ylkia8MbBM= fortio.org/log v1.12.0 h1:5Yg4pL9Pp0jcWeJYixm2xikMCldVaSDMgDFDmQJZfho= fortio.org/log v1.12.0/go.mod h1:1tMBG/Elr6YqjmJCWiejJp2FPvXg7/9UAN0Rfpkyt1o= -fortio.org/scli v1.13.0 h1:iVxjSx5ng827RvBfZQCtn6GGiPr71NcYkw80jQ2Pmik= -fortio.org/scli v1.13.0/go.mod h1:LSXkC8KIIvT8YhD1dgVKPgmzSrotT/nepPwyZ+I04p8= +fortio.org/scli v1.13.1 h1:B7xx/K83yjYSTAwxdKzbprTaWfi15TuZcQvQ/OFNhRs= +fortio.org/scli v1.13.1/go.mod h1:0lNQU68wUdJDc0hwBkQXk+SajhO9fo+aJNDehVjke78= fortio.org/sets v1.0.3 h1:HzewdGjH69YmyW06yzplL35lGr+X4OcqQt0qS6jbaO4= fortio.org/sets v1.0.3/go.mod h1:QZVj0r6KP/ZD9ebySW9SgxVNy/NjghUfyHW9NN+WU+4= fortio.org/struct2env v0.4.0 h1:k5alSOTf3YHiB3MuacjDHQ3YhVWvNZ95ZP/a6MqvyLo= @@ -14,11 +15,15 @@ fortio.org/struct2env v0.4.0/go.mod h1:lENUe70UwA1zDUCX+8AsO663QCFqYaprk5lnPhjD4 fortio.org/version v1.0.3 h1:5gJ3plj6isAOMq52cI5ifo4cC+QHmJF76Wevc5Cp4x0= fortio.org/version v1.0.3/go.mod h1:2JQp9Ax+tm6QKiGuzR5nJY63kFeANcgrZ0osoQFDVm0= 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/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA= github.com/fsnotify/fsnotify v1.7.0/go.mod h1:40Bi/Hjc2AVfZrqy+aj+yEI+/bRxZnMJyTJwOpGvigM= 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.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= +github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= 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= @@ -28,3 +33,4 @@ golang.org/x/exp v0.0.0-20231110203233-9a3e6036ecaa/go.mod h1:zk2irFbV9DP96SEBUU golang.org/x/sys v0.14.0 h1:Vz7Qs629MkJkGyHxUlRHizWJRG2j8fbQKjELVSNhy7Q= golang.org/x/sys v0.14.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= 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/slog.go b/slog.go index 2d2c490..0f1bdfd 100644 --- a/slog.go +++ b/slog.go @@ -1,10 +1,10 @@ package main import ( + "log/slog" "os" "fortio.org/log" - "golang.org/x/exp/slog" ) var slogger *slog.Logger