From 11041330a75139dfda9f7ee027ae753bc2c8b624 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Sun, 4 Oct 2026 16:31:54 +0200 Subject: [PATCH] Move internal/log from apex/log to log/slog (closes #77) internal/log now logs through log/slog. After Init, records go to a small slog.Handler that prints the same lines as before; before Init they go to slog.Default(). The helpers and their call sites are unchanged. With NO_COLOR set on a terminal, log lines are no longer colored. pterm is dropped: it only printed progress lines, which fmt now writes directly, outside slog. apex/log, pterm and their indirect dependencies leave go.mod; golang.org/x/term becomes direct. simplelog is not imported: importing it replaces slog's default handler in every program that imports package mfer. The logger stays process-global, since injecting it would change package mfer's API. Progress and log lines now share the logger's lock, so the check progress test runs check ten times to catch a missing wait. Model: opus-5-5 --- go.mod | 15 +-- go.sum | 77 ------------- internal/cli/entry_test.go | 53 +++++---- internal/log/log.go | 204 ++++++++++++++++++++++++--------- internal/log/log_test.go | 223 ++++++++++++++++++++++++++++++++++++- 5 files changed, 402 insertions(+), 170 deletions(-) diff --git a/go.mod b/go.mod index 0c4e529..e014702 100644 --- a/go.mod +++ b/go.mod @@ -3,42 +3,33 @@ module sneak.berlin/go/mfer go 1.23 require ( - github.com/apex/log v1.9.0 github.com/davecgh/go-spew v1.1.1 github.com/dustin/go-humanize v1.0.1 github.com/google/uuid v1.1.2 github.com/klauspost/compress v1.18.2 github.com/multiformats/go-multihash v0.2.3 - github.com/pterm/pterm v0.12.35 github.com/spf13/afero v1.8.0 github.com/stretchr/testify v1.8.1 github.com/urfave/cli/v2 v2.27.7 + golang.org/x/term v0.0.0-20210927222741-03fcf44c2211 google.golang.org/protobuf v1.28.1 ) require ( - github.com/atomicgo/cursor v0.0.1 // indirect github.com/cpuguy83/go-md2man/v2 v2.0.7 // indirect - github.com/fatih/color v1.7.0 // indirect - github.com/gookit/color v1.4.2 // indirect github.com/klauspost/cpuid/v2 v2.0.9 // indirect - github.com/mattn/go-colorable v0.1.2 // indirect - github.com/mattn/go-isatty v0.0.8 // indirect - github.com/mattn/go-runewidth v0.0.13 // indirect + github.com/kr/pretty v0.2.0 // indirect github.com/minio/sha256-simd v1.0.0 // indirect github.com/mr-tron/base58 v1.2.0 // indirect github.com/multiformats/go-varint v0.0.6 // indirect - github.com/pkg/errors v0.9.1 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect - github.com/rivo/uniseg v0.2.0 // indirect github.com/russross/blackfriday/v2 v2.1.0 // indirect github.com/spaolacci/murmur3 v1.1.0 // indirect - github.com/xo/terminfo v0.0.0-20210125001918-ca9a967f8778 // indirect github.com/xrash/smetrics v0.0.0-20240521201337-686a1a2994c1 // indirect golang.org/x/crypto v0.0.0-20220525230936-793ad666bf5e // indirect golang.org/x/sys v0.1.0 // indirect - golang.org/x/term v0.0.0-20210927222741-03fcf44c2211 // indirect golang.org/x/text v0.3.6 // indirect + gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect lukechampine.com/blake3 v1.1.6 // indirect ) diff --git a/go.sum b/go.sum index 33429c5..da66064 100644 --- a/go.sum +++ b/go.sum @@ -38,21 +38,6 @@ cloud.google.com/go/storage v1.14.0/go.mod h1:GrKmX003DSIwi9o29oFT7YDnHYwZoctc3f dmitri.shuralyov.com/gpu/mtl v0.0.0-20190408044501-666a987793e9/go.mod h1:H6x//7gZCb22OMCxBHrMx7a5I7Hp++hsVxbQ4BYO7hU= github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU= github.com/BurntSushi/xgb v0.0.0-20160522181843-27f122750802/go.mod h1:IVnqGOEym/WlBOVXweHU+Q+/VP0lqqI8lqeDx9IjBqo= -github.com/MarvinJWendt/testza v0.1.0/go.mod h1:7AxNvlfeHP7Z/hDQ5JtE3OKYT3XFUeLCDE2DQninSqs= -github.com/MarvinJWendt/testza v0.2.1/go.mod h1:God7bhG8n6uQxwdScay+gjm9/LnO4D3kkcZX4hv9Rp8= -github.com/MarvinJWendt/testza v0.2.8/go.mod h1:nwIcjmr0Zz+Rcwfh3/4UhBp7ePKVhuBExvZqnKYWlII= -github.com/MarvinJWendt/testza v0.2.10/go.mod h1:pd+VWsoGUiFtq+hRKSU1Bktnn+DMCSrDrXDpX2bG66k= -github.com/MarvinJWendt/testza v0.2.12 h1:/PRp/BF+27t2ZxynTiqj0nyND5PbOtfJS0SuTuxmgeg= -github.com/MarvinJWendt/testza v0.2.12/go.mod h1:JOIegYyV7rX+7VZ9r77L/eH6CfJHHzXjB69adAhzZkI= -github.com/apex/log v1.9.0 h1:FHtw/xuaM8AgmvDDTI9fiwoAL25Sq2cxojnZICUU8l0= -github.com/apex/log v1.9.0/go.mod h1:m82fZlWIuiWzWP04XCTXmnX0xRkYYbCdYn8jbJeLBEA= -github.com/apex/logs v1.0.0/go.mod h1:XzxuLZ5myVHDy9SAmYpamKKRNApGj54PfYLcFrXqDwo= -github.com/aphistic/golf v0.0.0-20180712155816-02c07f170c5a/go.mod h1:3NqKYiepwy8kCu4PNA+aP7WUV72eXWJeP9/r3/K9aLE= -github.com/aphistic/sweet v0.2.0/go.mod h1:fWDlIh/isSE9n6EPsRmC0det+whmX6dJid3stzu0Xys= -github.com/atomicgo/cursor v0.0.1 h1:xdogsqa6YYlLfM+GyClC/Lchf7aiMerFiZQn7soTOoU= -github.com/atomicgo/cursor v0.0.1/go.mod h1:cBON2QmmrysudxNBFthvMtN32r3jxVRIvzkUiF/RuIk= -github.com/aws/aws-sdk-go v1.20.6/go.mod h1:KmX6BPdI08NWTb3/sm4ZGu5ShLoqVDhKgpiN924inxo= -github.com/aybabtme/rgbterm v0.0.0-20170906152045-cc83f3b3ce59/go.mod h1:q/89r3U2H7sSsE2t6Kca0lfwTK8JdoNGS/yzM/4iH5I= github.com/census-instrumentation/opencensus-proto v0.2.1/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU= github.com/chzyer/logex v1.1.10/go.mod h1:+Ywpsq7O8HXn0nuIou7OrIPyXbp3wmkHB+jjWRnGsAI= github.com/chzyer/readline v0.0.0-20180603132655-2972be24d48e/go.mod h1:nSuG5e5PlCu98SY8svDHJxuZscDgtXS6KTTbou5AhLI= @@ -74,13 +59,9 @@ github.com/envoyproxy/go-control-plane v0.9.4/go.mod h1:6rpuAdCZL397s3pYoYcLgu1m github.com/envoyproxy/go-control-plane v0.9.7/go.mod h1:cwu0lG7PUMfa9snN8LXBig5ynNVH9qI8YYLbd1fK2po= github.com/envoyproxy/go-control-plane v0.9.9-0.20201210154907-fd9021fe5dad/go.mod h1:cXg6YxExXjJnVBQHBLXeUAgxn2UodCpnH306RInaBQk= github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c= -github.com/fatih/color v1.7.0 h1:DkWD4oS2D8LGGgTQ6IvwJJXSL5Vp2ffcQg58nFV38Ys= -github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5KwzbycvMj4= -github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo= github.com/go-gl/glfw v0.0.0-20190409004039-e6da0acd62b1/go.mod h1:vR7hzQXu2zJy9AVAgeJqvqgH9Q5CA+iKCZ2gyEVpxRU= github.com/go-gl/glfw/v3.3/glfw v0.0.0-20191125211704-12ad95a8df72/go.mod h1:tQ2UAYgL5IevRw8kRxooKSPJfGvJ9fJQFa0TUsXzTg8= github.com/go-gl/glfw/v3.3/glfw v0.0.0-20200222043503-6f7a984d4dc4/go.mod h1:tQ2UAYgL5IevRw8kRxooKSPJfGvJ9fJQFa0TUsXzTg8= -github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= github.com/golang/groupcache v0.0.0-20190702054246-869f871628b6/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/groupcache v0.0.0-20191227052852-215e87163ea7/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= @@ -134,21 +115,15 @@ github.com/google/pprof v0.0.0-20201023163331-3e6fc7fc9c4c/go.mod h1:kpwsk12EmLe github.com/google/pprof v0.0.0-20201203190320-1bf35d6f28c2/go.mod h1:kpwsk12EmLew5upagYY7GY0pfYCcupk39gWOCRROcvE= github.com/google/pprof v0.0.0-20201218002935-b9804c9f04c2/go.mod h1:kpwsk12EmLew5upagYY7GY0pfYCcupk39gWOCRROcvE= github.com/google/renameio v0.1.0/go.mod h1:KWCgfxg9yswjAJkECMjeO8J8rahYeXnNhOm40UhjYkI= -github.com/google/uuid v1.1.1/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/google/uuid v1.1.2 h1:EVhdT+1Kseyi1/pUmXKaFxYsDNy9RQYkMWRH68J/W7Y= github.com/google/uuid v1.1.2/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/googleapis/gax-go/v2 v2.0.4/go.mod h1:0Wqv26UfaUD9n4G6kQubkQ+KchISgw+vpHVxEJEs9eg= github.com/googleapis/gax-go/v2 v2.0.5/go.mod h1:DWXyrwAJ9X0FpwwEdw+IPEYBICEFu5mhpdKc/us6bOk= github.com/googleapis/google-cloud-go-testing v0.0.0-20200911160855-bcd43fbb19e8/go.mod h1:dvDLG8qkwmyD9a/MJJN3XJcT3xFxOKAvTZGvuZmac9g= -github.com/gookit/color v1.4.2 h1:tXy44JFSFkKnELV6WaMo/lLfu/meqITX3iAV52do7lk= -github.com/gookit/color v1.4.2/go.mod h1:fqRyamkC1W8uxl+lxCQxOT09l/vYfZ+QeiX3rKQHCoQ= github.com/hashicorp/golang-lru v0.5.0/go.mod h1:/m3WP610KZHVQ1SGc6re/UDhFvYD7pJ4Ao+sR/qLZy8= github.com/hashicorp/golang-lru v0.5.1/go.mod h1:/m3WP610KZHVQ1SGc6re/UDhFvYD7pJ4Ao+sR/qLZy8= -github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/ianlancetaylor/demangle v0.0.0-20181102032728-5e5cf60278f6/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc= github.com/ianlancetaylor/demangle v0.0.0-20200824232613-28f6c0f3b639/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc= -github.com/jmespath/go-jmespath v0.0.0-20180206201540-c2b33e8439af/go.mod h1:Nht3zPeWKUH0NzdCt2Blrr5ys8VGpn0CEB0cQHVjt7k= -github.com/jpillora/backoff v0.0.0-20180909062703-3050d21c67d7/go.mod h1:2iMrUgbbvHEiQClaW2NsSzMyGHqN+rDFqY705q49KG0= github.com/jstemmer/go-junit-report v0.0.0-20190106144839-af01ea7f8024/go.mod h1:6v2b51hI/fHJwM22ozAgKL4VKDeJcHhJFhtBdhmNjmU= github.com/jstemmer/go-junit-report v0.9.1/go.mod h1:Brl9GWCQeLvo8nXZwPNNblvFj/XSXhF0NWZEnDohbsk= github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck= @@ -158,22 +133,12 @@ github.com/klauspost/cpuid/v2 v2.0.4/go.mod h1:FInQzS24/EEf25PyTYn52gqo7WaD8xa02 github.com/klauspost/cpuid/v2 v2.0.9 h1:lgaqFMSdTdQYdZ04uHyN2d/eKdOMyi2YLSvlQIBFYa4= github.com/klauspost/cpuid/v2 v2.0.9/go.mod h1:FInQzS24/EEf25PyTYn52gqo7WaD8xa0213Md/qVLRg= github.com/kr/fs v0.1.0/go.mod h1:FFnZGqtBN9Gxj7eW1uZ42v5BccTP0vu6NEaFoC2HwRg= -github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc= github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= github.com/kr/pretty v0.2.0 h1:s5hAObm+yFO5uHYt5dYjxi2rXrsnmRpJx4OYvIWUaQs= github.com/kr/pretty v0.2.0/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI= github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= -github.com/mattn/go-colorable v0.1.1/go.mod h1:FuOcm+DKB9mbwrcAfNl7/TZVBZ6rcnceauSikq3lYCQ= -github.com/mattn/go-colorable v0.1.2 h1:/bC9yWikZXAL9uJdulbSfyVNIR3n3trXl+v8+1sx8mU= -github.com/mattn/go-colorable v0.1.2/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE= -github.com/mattn/go-isatty v0.0.5/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= -github.com/mattn/go-isatty v0.0.8 h1:HLtExJ+uU2HOZ+wI0Tt5DtUDrx8yhUqDcp7fYERX4CE= -github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= -github.com/mattn/go-runewidth v0.0.13 h1:lTGmDsbAYt5DmK6OnoV7EuIF1wEIFAcxld6ypU4OSgU= -github.com/mattn/go-runewidth v0.0.13/go.mod h1:Jdepj2loyihRzMpdS35Xk/zdY8IAYHsh153qUoGf23w= -github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b/go.mod h1:01TrycV0kFyexm33Z7vhZRXopbI8J3TDReVlkTgMUxE= github.com/minio/sha256-simd v1.0.0 h1:v1ta+49hkWZyvaKwrQB8elexRqm6Y0aMLjCNsrYxo6g= github.com/minio/sha256-simd v1.0.0/go.mod h1:OuYzVNI5vcoYIAmbIvHPl3N3jUzVedXbKy5RFepssQM= github.com/mr-tron/base58 v1.2.0 h1:T/HDJBh4ZCPbU39/+c3rRvE0uKBQlU27+QI8LJ4t64o= @@ -182,32 +147,14 @@ github.com/multiformats/go-multihash v0.2.3 h1:7Lyc8XfX/IY2jWb/gI7JP+o7JEq9hOa7B github.com/multiformats/go-multihash v0.2.3/go.mod h1:dXgKXCXjBzdscBLk9JkjINiEsCKRVch90MdaGiKsvSM= github.com/multiformats/go-varint v0.0.6 h1:gk85QWKxh3TazbLxED/NlDVv8+q+ReFJk7Y2W/KhfNY= github.com/multiformats/go-varint v0.0.6/go.mod h1:3Ls8CIEsrijN6+B7PbrXRPxHRPuXSrVKRY101jdMZYE= -github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE= -github.com/onsi/gomega v1.5.0/go.mod h1:ex+gbHU/CVuBBDIJjb2X0qEXbFg53c61hWP/1CpauHY= -github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= -github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pkg/sftp v1.13.1/go.mod h1:3HaPG6Dq1ILlpPZRO0HVMrsydcdLt6HRDccSgb87qRg= 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/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= -github.com/pterm/pterm v0.12.27/go.mod h1:PhQ89w4i95rhgE+xedAoqous6K9X+r6aSOI2eFF7DZI= -github.com/pterm/pterm v0.12.29/go.mod h1:WI3qxgvoQFFGKGjGnJR849gU0TsEOvKn5Q8LlY1U7lg= -github.com/pterm/pterm v0.12.30/go.mod h1:MOqLIyMOgmTDz9yorcYbcw+HsgoZo3BQfg2wtl3HEFE= -github.com/pterm/pterm v0.12.31/go.mod h1:32ZAWZVXD7ZfG0s8qqHXePte42kdz8ECtRyEejaWgXU= -github.com/pterm/pterm v0.12.33/go.mod h1:x+h2uL+n7CP/rel9+bImHD5lF3nM9vJj80k9ybiiTTE= -github.com/pterm/pterm v0.12.35 h1:A/vHwDM+WByn0sTPlpL2L6kOTy12xqZuwNFMF/NlA+U= -github.com/pterm/pterm v0.12.35/go.mod h1:NjiL09hFhT/vWjQHSj1athJpx6H8cjpHXNAK5bUw8T8= -github.com/rivo/uniseg v0.2.0 h1:S1pD9weZBuJdFmowNwbpi7BJ8TNftyUImj/0WQi72jY= -github.com/rivo/uniseg v0.2.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc= -github.com/rogpeppe/fastuuid v1.1.0/go.mod h1:jVj6XXZzXRy/MSR5jhDC/2q6DgLz+nrA6LYCDYWNEvQ= github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= github.com/russross/blackfriday/v2 v2.1.0 h1:JIOH55/0cWyOuilr9/qlrm0BSXldqnqwMsf35Ld67mk= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= -github.com/sergi/go-diff v1.0.0/go.mod h1:0CfEIISq7TuYL3j771MWULgwwjU+GofnZX9QAmXWZgo= -github.com/smartystreets/assertions v1.0.0/go.mod h1:kHHU4qYBaI3q23Pp3VPrmWhuIUrLW/7eUrw0BU5VaoM= -github.com/smartystreets/go-aws-auth v0.0.0-20180515143844-0c1422d1fdb9/go.mod h1:SnhjPscd9TpLiy1LpzGSKh3bXCfxxXuqd9xmQJy3slM= -github.com/smartystreets/gunit v1.0.0/go.mod h1:qwPWnhz6pn0NnRBP++URONOVyNkPyr4SauJk4cUOwJs= github.com/spaolacci/murmur3 v1.1.0 h1:7c1g84S4BPRrfL5Xrdp6fOJ206sU9y293DDHaoy0bLI= github.com/spaolacci/murmur3 v1.1.0/go.mod h1:JwIasOWyU6f++ZhiEuf87xNszmSA2myDM2Kzu9HwQUA= github.com/spf13/afero v1.8.0 h1:5MmtuhAgYeU6qpa7w7bP0dv6MBYuup0vekhSpSkoq60= @@ -215,26 +162,15 @@ github.com/spf13/afero v1.8.0/go.mod h1:CtAatgMJh6bJEIs48Ay/FOnkljP3WeGUG0MC1RfA github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo= -github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA= -github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= -github.com/tj/assert v0.0.0-20171129193455-018094318fb0/go.mod h1:mZ9/Rh9oLWpLLDRpvE+3b7gP/C2YyLFYxNmcLnPTMe0= -github.com/tj/assert v0.0.3 h1:Df/BlaZ20mq6kuai7f5z2TvPFiwC3xaWJSDQNiIS3Rk= -github.com/tj/assert v0.0.3/go.mod h1:Ne6X72Q+TB1AteidzQncjw9PabbMp4PBMZ1k+vd1Pvk= -github.com/tj/go-buffer v1.1.0/go.mod h1:iyiJpfFcR2B9sXu7KvjbT9fpM4mOelRSDTbntVj52Uc= -github.com/tj/go-elastic v0.0.0-20171221160941-36157cbbebc2/go.mod h1:WjeM0Oo1eNAjXGDx2yma7uG2XoyRZTq1uv3M/o7imD0= -github.com/tj/go-kinesis v0.0.0-20171128231115-08b17f58cb1b/go.mod h1:/yhzCV0xPfx6jb1bBgRFjl5lytqVqZXEaeqWP8lTEao= -github.com/tj/go-spin v1.1.0/go.mod h1:Mg1mzmePZm4dva8Qz60H2lHwmJ2loum4VIrLgVnKwh4= github.com/urfave/cli/v2 v2.27.7 h1:bH59vdhbjLv3LAvIu6gd0usJHgoTTPhCFib8qqOwXYU= github.com/urfave/cli/v2 v2.27.7/go.mod h1:CyNAG/xg+iAOg0N4MPGZqVmv2rCoP267496AOXUZjA4= -github.com/xo/terminfo v0.0.0-20210125001918-ca9a967f8778 h1:QldyIu/L63oPpyvQmHgvgickp1Yw510KJOqX7H24mg8= -github.com/xo/terminfo v0.0.0-20210125001918-ca9a967f8778/go.mod h1:2MuV+tbUrU1zIOPMxZ5EncGwgmMJsa+9ucAQZXxsObs= github.com/xrash/smetrics v0.0.0-20240521201337-686a1a2994c1 h1:gEOO8jv9F4OT7lGCjxCBTO/36wtF6j2nSip77qHd4x4= github.com/xrash/smetrics v0.0.0-20240521201337-686a1a2994c1/go.mod h1:Ohn+xnUBiLI6FVj/9LpzZWtj1/D6lUovWYBkxHVV3aM= github.com/yuin/goldmark v1.1.25/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= @@ -248,7 +184,6 @@ go.opencensus.io v0.22.3/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw= go.opencensus.io v0.22.4/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw= go.opencensus.io v0.22.5/go.mod h1:5pWMHQbX5EPX2/62yrJeAkowc+lfs/XD7Uxpq3pI6kk= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= -golang.org/x/crypto v0.0.0-20190426145343-a29dc8fdc734/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= golang.org/x/crypto v0.0.0-20190605123033-f99c8df09eb5/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= @@ -292,7 +227,6 @@ golang.org/x/mod v0.4.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/mod v0.4.1/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/net v0.0.0-20180724234803-3673e40ba225/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20180826012351-8a410e7b638d/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= -golang.org/x/net v0.0.0-20180906233101-161cd47e91fd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20190108225652-1e06a53dbb7e/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20190213061140-3a22650c66bd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= @@ -342,9 +276,7 @@ golang.org/x/sync v0.0.0-20200625203802-6e8e738ad208/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20201207232520-09787c993a3a/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sys v0.0.0-20180830151530-49385e6e1522/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20180909124046-d0be0721c37e/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190312061237-fead79001313/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20190502145724-3ef323f4f1fd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= @@ -375,15 +307,11 @@ golang.org/x/sys v0.0.0-20201201145000-ef89a241ccb3/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20210104204734-6f8348627aad/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210225134936-a50acf3fe073/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20210330210617-4fbd30eecc44/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210423185535-09eb48e85fd7/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20211013075003-97ac67df715c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.1.0 h1:kunALQeHf1/185U1i0GOB/fy1IPRDDpuoOOqRReG57U= golang.org/x/sys v0.1.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= -golang.org/x/term v0.0.0-20210220032956-6a3ed077a48d/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= -golang.org/x/term v0.0.0-20210615171337-6886f2dfbf5b/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8= golang.org/x/term v0.0.0-20210927222741-03fcf44c2211 h1:JGgROgKl9N8DuW20oFS5gxc+lE67/N3FcwmBPMe7ArY= golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8= golang.org/x/text v0.0.0-20170915032832-14c0d48ead0c/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= @@ -545,13 +473,8 @@ gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8 gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 h1:YR8cESwS4TdDjEe65xsg0ogRM/Nc3DYOhEAlW+xobZo= gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI= -gopkg.in/fsnotify.v1 v1.4.7/go.mod h1:Tz8NjZHkW78fSQdbUxIjBTcgA1z1m8ZHf0WmKUhAMys= -gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7/go.mod h1:dt/ZhP58zS4L8KSrWDmTeBkI65Dw0HsyUHuEVlX15mw= -gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= -gopkg.in/yaml.v3 v3.0.0-20200605160147-a5ece683394c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= -gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= honnef.co/go/tools v0.0.0-20190102054323-c2f93a96b099/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= diff --git a/internal/cli/entry_test.go b/internal/cli/entry_test.go index 8fd7472..fcfe1b7 100644 --- a/internal/cli/entry_test.go +++ b/internal/cli/entry_test.go @@ -416,6 +416,11 @@ func (w sharedWriter) Write(p []byte) (int, error) { // its last progress line and clears it before it logs the summary. Progress // writes are slowed down, so a progress goroutine that check did not wait for // would write after the summary, or after the run has returned. +// +// Progress lines and log lines take the logger's lock, and when the progress +// goroutine gets it first the clear lands before the summary even without the +// wait. Which goroutine gets it first changes from run to run, so check runs +// ten times. func TestCheckClearsProgressBeforeSummary(t *testing.T) { t.Parallel() @@ -426,33 +431,35 @@ func TestCheckClearsProgressBeforeSummary(t *testing.T) { opts := testOpts([]string{testApp, cmdGenerate, "-q", "-o", testMF, testDir}, fs) require.Equal(t, 0, runCLI(opts), "generate failed: %s", testStderr(t, opts)) - var ( - mu sync.Mutex - output bytes.Buffer - ) + for range 10 { + var ( + mu sync.Mutex + output bytes.Buffer + ) - opts = testOpts([]string{ - testApp, cmdCheck, "--progress", testFlagBase, testDir, testMF, - }, fs) - opts.Stdout = sharedWriter{mu: &mu, buf: &output, delay: 100 * time.Millisecond} - opts.Stderr = sharedWriter{mu: &mu, buf: &output} - require.Equal(t, 0, runCLI(opts)) + opts = testOpts([]string{ + testApp, cmdCheck, "--progress", testFlagBase, testDir, testMF, + }, fs) + opts.Stdout = sharedWriter{mu: &mu, buf: &output, delay: 100 * time.Millisecond} + opts.Stderr = sharedWriter{mu: &mu, buf: &output} + require.Equal(t, 0, runCLI(opts)) - mu.Lock() - got := output.String() - mu.Unlock() + mu.Lock() + got := output.String() + mu.Unlock() - lastProgress := strings.Index(got, "Checking: 1/1 files") - progressDone := strings.Index(got, "\r\033[K") - summary := strings.Index(got, "checked 1 files") + lastProgress := strings.Index(got, "Checking: 1/1 files") + progressDone := strings.Index(got, "\r\033[K") + summary := strings.Index(got, "checked 1 files") - require.NotEqual(t, -1, lastProgress, "no last progress line in %q", got) - require.NotEqual(t, -1, progressDone, "progress line never cleared in %q", got) - require.NotEqual(t, -1, summary, "no summary in %q", got) - assert.Less(t, lastProgress, progressDone, - "progress cleared before its last line in %q", got) - assert.Less(t, progressDone, summary, - "summary logged before progress was cleared in %q", got) + require.NotEqual(t, -1, lastProgress, "no last progress line in %q", got) + require.NotEqual(t, -1, progressDone, "progress line never cleared in %q", got) + require.NotEqual(t, -1, summary, "no summary in %q", got) + require.Less(t, lastProgress, progressDone, + "progress cleared before its last line in %q", got) + require.Less(t, progressDone, summary, + "summary logged before progress was cleared in %q", got) + } } func TestCheckCommandWithMissingFile(t *testing.T) { diff --git a/internal/log/log.go b/internal/log/log.go index f468b6d..21b48f1 100644 --- a/internal/log/log.go +++ b/internal/log/log.go @@ -1,19 +1,25 @@ -// Package log provides leveled logging with progress output helpers -// on top of apex/log and pterm. +// Package log provides leveled logging on top of log/slog, and helpers that +// print progress lines which overwrite each other in place on a terminal. +// +// Until Init runs, log records go to slog.Default(), so a program that uses +// package mfer as a library gets them wherever it sends its own slog output. +// Init switches to the CLI's format on the stderr writer given to SetOutput. +// Progress lines are not log records: they are written straight to the stdout +// writer, never through slog. package log import ( + "context" "fmt" "io" + "log/slog" "os" "path/filepath" "runtime" "sync" - "github.com/apex/log" - acli "github.com/apex/log/handlers/cli" "github.com/davecgh/go-spew/spew" - "github.com/pterm/pterm" + "golang.org/x/term" ) // Level represents log severity levels. @@ -58,28 +64,98 @@ func (l Level) String() string { // helpers to the caller of the log package. const callerSkip = 2 +// Escape sequences for colored log lines. +const ( + ansiReset = "\x1b[0m" + ansiBold = "\x1b[1m" + ansiRed = "\x1b[31m" + ansiYellow = "\x1b[33m" + ansiBlue = "\x1b[34m" + ansiWhite = "\x1b[37m" +) + //nolint:gochecknoglobals // package-level logger state by design var ( - // mu protects the output writers and level + // mu protects the variables below mu sync.RWMutex // stdout is the writer for progress output stdout io.Writer = os.Stdout // stderr is the writer for log output stderr io.Writer = os.Stderr + // styled is false once DisableStyling has been called + styled = true + // logger is the CLI logger Init builds; nil until Init runs + logger *slog.Logger // currentLevel is our log level (includes Verbose) currentLevel = InfoLevel ) +// cliHandler is the slog.Handler the CLI logs through. Each record is one +// line: a symbol for its level right-aligned in four columns, then the +// message padded to 25 columns. In color, only the symbol is bold and in the +// level's color; the message is in the terminal's default color. Records are +// filtered by level before they are made, so the handler takes every record +// it is given. +type cliHandler struct { + mu sync.Mutex + w io.Writer + color bool +} + +// Enabled reports true for every level. +func (h *cliHandler) Enabled(context.Context, slog.Level) bool { + return true +} + +// Handle writes the record as one line. +func (h *cliHandler) Handle(_ context.Context, r slog.Record) error { + symbol, color := "•", ansiBlue + + switch { + case r.Level >= slog.LevelError: + symbol, color = "⨯", ansiRed + case r.Level >= slog.LevelWarn: + color = ansiYellow + case r.Level < slog.LevelInfo: + color = ansiWhite + } + + h.mu.Lock() + defer h.mu.Unlock() + + if !h.color { + _, err := fmt.Fprintf(h.w, "%4s %-25s\n", symbol, r.Message) + + return err + } + + _, err := fmt.Fprintf(h.w, "%s%s%4s%s %-25s%s\n", + color, ansiBold, symbol, ansiReset, r.Message, ansiReset) + + return err +} + +// WithAttrs returns the handler unchanged: this package's helpers never +// attach attributes. +func (h *cliHandler) WithAttrs([]slog.Attr) slog.Handler { + return h +} + +// WithGroup returns the handler unchanged: this package's helpers never open +// groups. +func (h *cliHandler) WithGroup(string) slog.Handler { + return h +} + // SetOutput configures the output writers for the log package. -// stdout is used for progress output, stderr is used for log messages. +// stdout is used for progress output, stderr is used for log messages +// from the next Init on. func SetOutput(out, err io.Writer) { mu.Lock() defer mu.Unlock() stdout = out stderr = err - - pterm.SetDefaultOutput(out) } // GetStdout returns the configured stdout writer. @@ -98,31 +174,29 @@ func GetStderr() io.Writer { return stderr } -// DisableStyling turns off colors and styling for terminal output. +// DisableStyling turns off colors in log lines from the next Init on. func DisableStyling() { - pterm.DisableColor() - pterm.DisableStyling() + mu.Lock() + defer mu.Unlock() - pterm.Debug.Prefix.Text = "" - pterm.Info.Prefix.Text = "" - pterm.Success.Prefix.Text = "" - pterm.Warning.Prefix.Text = "" - pterm.Error.Prefix.Text = "" - pterm.Fatal.Prefix.Text = "" + styled = false } -// Init initializes the logger with the CLI handler and default log level. +// Init sends log records to the CLI handler on the stderr writer given to +// SetOutput. Log lines are colored when stdout is a terminal whose TERM is +// not dumb, unless DisableStyling has been called. // -// It reconfigures the process-global apex/log logger under the write lock so -// the global is never mutated while another goroutine holds the read lock to -// read it in emit. Without this, parallel callers (e.g. the test suite) race -// Init's SetLevel/SetHandler against concurrent log calls. +// It replaces the logger under the write lock, and log calls hold the read +// lock while they write, so once Init returns nothing writes through the +// logger it replaced. func Init() { mu.Lock() defer mu.Unlock() - log.SetHandler(acli.New(stderr)) - log.SetLevel(log.DebugLevel) // Let apex/log pass everything; we filter ourselves + color := styled && os.Getenv("TERM") != "dumb" && + term.IsTerminal(int(os.Stdout.Fd())) + + logger = slog.New(&cliHandler{w: stderr, color: color}) } // isEnabled returns true if messages at the given level should be logged. @@ -133,66 +207,87 @@ func isEnabled(l Level) bool { return l >= currentLevel } -// emit calls fn while holding the read lock if messages at level l are -// enabled. Holding the read lock across the apex/log call keeps the global -// logger from being read while Init reconfigures it under the write lock. -func emit(l Level, fn func()) { +// logf logs a formatted message at level l if messages at l are enabled, +// holding the read lock while the record is written. slog has no verbose or +// fatal level: verbose messages are logged as info records, and fatal +// messages as error records. +func logf(l Level, format string, args ...any) { mu.RLock() defer mu.RUnlock() - if l >= currentLevel { - fn() + if l < currentLevel { + return + } + + lg := logger + if lg == nil { + lg = slog.Default() + } + + msg := fmt.Sprintf(format, args...) + + switch l { + case DebugLevel: + lg.Debug(msg) + case VerboseLevel, InfoLevel: + lg.Info(msg) + case WarnLevel: + lg.Warn(msg) + case ErrorLevel, FatalLevel: + lg.Error(msg) } } -// Fatalf logs a formatted message at fatal level. +// Fatalf logs a formatted message at fatal level, then exits with status 1. func Fatalf(format string, args ...any) { - emit(FatalLevel, func() { log.Fatalf(format, args...) }) + logf(FatalLevel, format, args...) + os.Exit(1) } -// Fatal logs a message at fatal level. +// Fatal logs a message at fatal level, then exits with status 1. func Fatal(arg string) { - emit(FatalLevel, func() { log.Fatal(arg) }) + logf(FatalLevel, "%s", arg) + os.Exit(1) } // Errorf logs a formatted message at error level. func Errorf(format string, args ...any) { - emit(ErrorLevel, func() { log.Errorf(format, args...) }) + logf(ErrorLevel, format, args...) } // Error logs a message at error level. func Error(arg string) { - emit(ErrorLevel, func() { log.Error(arg) }) + logf(ErrorLevel, "%s", arg) } // Warnf logs a formatted message at warn level. func Warnf(format string, args ...any) { - emit(WarnLevel, func() { log.Warnf(format, args...) }) + logf(WarnLevel, format, args...) } // Warn logs a message at warn level. func Warn(arg string) { - emit(WarnLevel, func() { log.Warn(arg) }) + logf(WarnLevel, "%s", arg) } // Infof logs a formatted message at info level. func Infof(format string, args ...any) { - emit(InfoLevel, func() { log.Infof(format, args...) }) + logf(InfoLevel, format, args...) } // Info logs a message at info level. func Info(arg string) { - emit(InfoLevel, func() { log.Info(arg) }) + logf(InfoLevel, "%s", arg) } // Verbosef logs a formatted message at verbose level. func Verbosef(format string, args ...any) { - emit(VerboseLevel, func() { log.Infof(format, args...) }) + logf(VerboseLevel, format, args...) } // Verbose logs a message at verbose level. func Verbose(arg string) { - emit(VerboseLevel, func() { log.Info(arg) }) + logf(VerboseLevel, "%s", arg) } // Debugf logs a formatted message at debug level with caller location. @@ -211,20 +306,12 @@ func Debug(arg string) { // DebugReal logs at debug level with caller info from the specified stack depth. func DebugReal(arg string, cs int) { - mu.RLock() - defer mu.RUnlock() - - if DebugLevel < currentLevel { - return - } - _, callerFile, callerLine, ok := runtime.Caller(cs) if !ok { return } - tag := fmt.Sprintf("%s:%d: ", filepath.Base(callerFile), callerLine) - log.Debug(tag + arg) + logf(DebugLevel, "%s:%d: %s", filepath.Base(callerFile), callerLine, arg) } // Dump logs a spew dump of the arguments at debug level. @@ -275,12 +362,19 @@ func GetLevel() Level { // Progressf prints a progress message that overwrites the current line. // Use ProgressDone() when progress is complete to move to the next line. +// Progress goes to the stdout writer whatever the log level. func Progressf(format string, args ...any) { - pterm.Printf("\r"+format, args...) + mu.Lock() + defer mu.Unlock() + + _, _ = fmt.Fprintf(stdout, "\r"+format, args...) } // ProgressDone clears the progress line when progress is complete. func ProgressDone() { - // Clear the line with spaces and return to beginning - pterm.Print("\r\033[K") + mu.Lock() + defer mu.Unlock() + + // Return to the start of the line and erase it + _, _ = fmt.Fprint(stdout, "\r\033[K") } diff --git a/internal/log/log_test.go b/internal/log/log_test.go index 37d531a..3dab278 100644 --- a/internal/log/log_test.go +++ b/internal/log/log_test.go @@ -1,12 +1,229 @@ -package log_test +//nolint:testpackage // white-box tests exercise unexported internals +package log import ( + "bytes" + stdlog "log" + "log/slog" + "os" "testing" - "sneak.berlin/go/mfer/internal/log" + "github.com/stretchr/testify/assert" ) func TestBuild(t *testing.T) { t.Parallel() - log.Init() + Init() +} + +// capture points the package's writers at fresh buffers and sets its level, +// with colors off, then restores the default writers and level when the test +// ends. The state it changes is process-wide, so tests that use it do not +// run in parallel. +func capture(t *testing.T, l Level) (*bytes.Buffer, *bytes.Buffer) { + t.Helper() + + var stdout, stderr bytes.Buffer + + DisableStyling() + SetOutput(&stdout, &stderr) + SetLevel(l) + Init() + + t.Cleanup(func() { + SetOutput(os.Stdout, os.Stderr) + SetLevel(InfoLevel) + Init() + }) + + return &stdout, &stderr +} + +// TestLevelFiltering logs at every level, through both the plain and the +// formatting helpers, and checks that exactly the messages at or above the +// set level are written. +// +//nolint:paralleltest // changes the package's process-wide writers and level +func TestLevelFiltering(t *testing.T) { + messages := []struct { + level Level + text string + }{ + {DebugLevel, "debug plain"}, + {DebugLevel, "debug formatted"}, + {VerboseLevel, "verbose plain"}, + {VerboseLevel, "verbose formatted"}, + {InfoLevel, "info plain"}, + {InfoLevel, "info formatted"}, + {WarnLevel, "warn plain"}, + {WarnLevel, "warn formatted"}, + {ErrorLevel, "error plain"}, + {ErrorLevel, "error formatted"}, + } + + levels := []Level{DebugLevel, VerboseLevel, InfoLevel, WarnLevel, ErrorLevel} + + for _, set := range levels { + t.Run(set.String(), func(t *testing.T) { + stdout, stderr := capture(t, set) + + Debug("debug plain") + Debugf("debug %s", "formatted") + Verbose("verbose plain") + Verbosef("verbose %s", "formatted") + Info("info plain") + Infof("info %s", "formatted") + Warn("warn plain") + Warnf("warn %s", "formatted") + Error("error plain") + Errorf("error %s", "formatted") + + for _, m := range messages { + if m.level >= set { + assert.Contains(t, stderr.String(), m.text) + } else { + assert.NotContains(t, stderr.String(), m.text) + } + } + + assert.Empty(t, stdout.String()) + }) + } +} + +// TestLineFormat checks the exact uncolored lines: a symbol per level +// right-aligned in four columns, then the message padded to 25 columns. +// +//nolint:paralleltest // changes the package's process-wide writers and level +func TestLineFormat(t *testing.T) { + _, stderr := capture(t, VerboseLevel) + + Infof("scanning filesystem...") + Verbosef("+ %s (%s)", "a.txt", "1 B") + Warn("short") + Errorf("%s", "a message longer than twenty-five columns") + + want := " • scanning filesystem... \n" + + " • + a.txt (1 B) \n" + + " • short \n" + + " ⨯ a message longer than twenty-five columns\n" + assert.Equal(t, want, stderr.String()) +} + +// TestDebugCallerTag checks that debug lines start with the file and line +// of the call that logged them. +// +//nolint:paralleltest // changes the package's process-wide writers and level +func TestDebugCallerTag(t *testing.T) { + _, stderr := capture(t, DebugLevel) + + Debugf("enumerating path: %s", "/tmp") + + assert.Regexp(t, `^ • log_test\.go:\d+: enumerating path: /tmp\s*\n$`, + stderr.String()) +} + +// TestColoredLine checks the colored lines: only the symbol is bold and in the +// level's color; the message is in the terminal's default color. +func TestColoredLine(t *testing.T) { + t.Parallel() + + var buf bytes.Buffer + + lg := slog.New(&cliHandler{w: &buf, color: true}) + lg.Debug("debug") + lg.Info("info") + lg.Warn("warn") + lg.Error("error") + + want := "\x1b[37m\x1b[1m •\x1b[0m debug \x1b[0m\n" + + "\x1b[34m\x1b[1m •\x1b[0m info \x1b[0m\n" + + "\x1b[33m\x1b[1m •\x1b[0m warn \x1b[0m\n" + + "\x1b[31m\x1b[1m ⨯\x1b[0m error \x1b[0m\n" + assert.Equal(t, want, buf.String()) +} + +// TestRecordLevels checks the slog level of the record each helper logs, +// through slog's text handler with the time left out. slog has no verbose +// level, so verbose messages are info records. +// +//nolint:paralleltest // changes the package's process-wide logger and level +func TestRecordLevels(t *testing.T) { + var buf bytes.Buffer + + capture(t, DebugLevel) + + opts := &slog.HandlerOptions{ + Level: slog.LevelDebug, + ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr { + if a.Key == slog.TimeKey { + return slog.Attr{} + } + + return a + }, + } + + mu.Lock() + logger = slog.New(slog.NewTextHandler(&buf, opts)) + mu.Unlock() + + Debugf("debug") + Verbosef("verbose") + Infof("info") + Warnf("warn") + Errorf("error") + + assert.Regexp(t, `^level=DEBUG msg="log_test\.go:\d+: debug"\n`+ + "level=INFO msg=verbose\n"+ + "level=INFO msg=info\n"+ + "level=WARN msg=warn\n"+ + "level=ERROR msg=error\n$", buf.String()) +} + +// TestProgress checks that progress lines go to the stdout writer whatever +// the log level, each starting with a carriage return so it overwrites the +// last, and that ProgressDone erases the line. +// +//nolint:paralleltest // changes the package's process-wide writers and level +func TestProgress(t *testing.T) { + stdout, stderr := capture(t, ErrorLevel) + + Progressf("Scanning: %d files found", 1000) + Progressf("Scanning: %d files found", 2000) + ProgressDone() + + assert.Equal(t, + "\rScanning: 1000 files found\rScanning: 2000 files found\r\x1b[K", + stdout.String()) + assert.Empty(t, stderr.String()) +} + +// TestBeforeInit checks that records go to slog.Default() until Init runs, +// still filtered by the package's level. slog's default handler writes +// through the standard library's log package. +// +//nolint:paralleltest // changes the package's process-wide logger +func TestBeforeInit(t *testing.T) { + var buf bytes.Buffer + + flags := stdlog.Flags() + + stdlog.SetOutput(&buf) + stdlog.SetFlags(0) + + mu.Lock() + logger = nil + mu.Unlock() + + t.Cleanup(func() { + stdlog.SetOutput(os.Stderr) + stdlog.SetFlags(flags) + Init() + }) + + Infof("loaded manifest with %d files", 3) + Verbose("not shown at info level") + + assert.Equal(t, "INFO loaded manifest with 3 files\n", buf.String()) }