Compare commits

...
3 Commits
Author SHA1 Message Date
sneak 510cda0ac0 Move internal/log from apex/log to log/slog (closes #77)
check / check (push) Failing after 2s
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
2026-10-04 13:51:28 +00:00
clawbot 82b9434444 fetch: client timeout, retry with backoff, url.JoinPath (closes #63)
check / check (push) Failing after 2s
fetch now makes every request through an http.Client with a time
limit, ten minutes by default and set with --timeout, which must be
greater than zero. A connection error, a timeout, or a 5xx or 429
response is retried, up to five tries in all, after a random wait
whose limit doubles from one second, or after the wait the server's
Retry-After asks for, up to one minute. Each try of a file starts a
new temp file, so a retry never keeps a partial file; the size and
hash checks are unchanged. Manifest and file URLs are built with
URL.JoinPath, so trailing slashes, query strings and names that need
escaping all work.

Model: opus-5-5
2026-10-04 15:48:55 +02:00
clawbot 6a2307a82b check waits for its progress output before the summary (closes #140)
check / check (push) Failing after 1s
With --progress, runCheck started the progress goroutine but waited
only for the results goroutine, so check could log its summary, or
return, before the last progress line was written and cleared. The
progress goroutine now signals a sync.WaitGroup when it finishes, and
runCheck waits on it as soon as Check returns, as generate does.

The new test sends stdout and stderr to one buffer and slows down
stdout writes, so without the wait the progress output lands after
the summary.

Model: opus-5-5
2026-10-04 15:31:57 +02:00
10 changed files with 1037 additions and 215 deletions
+3 -12
View File
@@ -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
)
-77
View File
@@ -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=
+15 -3
View File
@@ -11,6 +11,7 @@ import (
"path/filepath"
"strconv"
"strings"
"sync"
"time"
"github.com/dustin/go-humanize"
@@ -163,7 +164,9 @@ func verifyRequiredSigner(
}
// reportCheckProgress renders progress updates until the channel closes.
func reportCheckProgress(progress <-chan mfer.CheckStatus) {
func reportCheckProgress(progress <-chan mfer.CheckStatus, wg *sync.WaitGroup) {
defer wg.Done()
for status := range progress {
if status.ETA > 0 {
log.Progressf("Checking: %d/%d files, %s/s, ETA %s, %d failures",
@@ -235,11 +238,17 @@ func runCheck(ctx *cli.Context, chk *mfer.Checker, showProgress bool) (int64, er
results := make(chan mfer.Result, 1)
// Set up progress channel
var progress chan mfer.CheckStatus
var (
progress chan mfer.CheckStatus
progressWg sync.WaitGroup
)
if showProgress {
progress = make(chan mfer.CheckStatus, 1)
go reportCheckProgress(progress)
progressWg.Add(1)
go reportCheckProgress(progress, &progressWg)
}
// Process results in a goroutine
@@ -251,6 +260,9 @@ func runCheck(ctx *cli.Context, chk *mfer.Checker, showProgress bool) (int64, er
// Run check
err := chk.Check(ctx.Context, results, progress)
progressWg.Wait()
if err != nil {
return 0, fmt.Errorf("check failed: %w", err)
}
+69
View File
@@ -13,6 +13,7 @@ import (
"strings"
"sync"
"testing"
"time"
"github.com/spf13/afero"
"github.com/stretchr/testify/assert"
@@ -393,6 +394,74 @@ func TestGenerateAndCheckCommand(t *testing.T) {
assert.Equal(t, 0, exitCode, "check failed: %s", testStderr(t, opts))
}
// sharedWriter appends to a buffer shared with other sharedWriters, so
// output written to stdout and stderr is kept in the order it was written.
// Each write first waits for delay.
type sharedWriter struct {
mu *sync.Mutex
buf *bytes.Buffer
delay time.Duration
}
func (w sharedWriter) Write(p []byte) (int, error) {
time.Sleep(w.delay)
w.mu.Lock()
defer w.mu.Unlock()
return w.buf.Write(p)
}
// TestCheckClearsProgressBeforeSummary asserts that check --progress writes
// 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()
fs := afero.NewMemMapFs()
require.NoError(t, fs.MkdirAll(testDir, 0o755))
writeTestFile(t, fs, testFile1, "hello world")
opts := testOpts([]string{testApp, cmdGenerate, "-q", "-o", testMF, testDir}, fs)
require.Equal(t, 0, runCLI(opts), "generate failed: %s", testStderr(t, opts))
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))
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")
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) {
t.Parallel()
+12 -4
View File
@@ -272,10 +272,15 @@ func TestFetchManifestHTTPStatusMessage(t *testing.T) {
}))
defer server.Close()
set := flag.NewFlagSet("fetch", flag.ContinueOnError)
mfa := &CLIApp{Fs: afero.NewMemMapFs()}
set := flag.NewFlagSet(cmdFetch, flag.ContinueOnError)
for _, f := range mfa.fetchCommand().Flags {
require.NoError(t, f.Apply(set))
}
require.NoError(t, set.Parse([]string{server.URL}))
mfa := &CLIApp{Fs: afero.NewMemMapFs()}
ctx := urfcli.NewContext(nil, set, nil)
// fetchManifestOperation logs to the process-global logger.
@@ -293,8 +298,11 @@ func TestFetchFileHTTPStatusMessage(t *testing.T) {
}))
defer server.Close()
err := downloadFile(context.Background(), server.URL+"/x", "x",
&mfer.MFFilePath{}, nil)
// downloadFile logs each retry of the 500 to the process-global logger.
err := runLocked(func() error {
return downloadFile(context.Background(), testClient(), server.URL+"/x", "x",
&mfer.MFFilePath{}, nil)
})
require.ErrorIs(t, err, errHTTPStatus)
assert.EqualError(t, err, "HTTP 500")
}
+172 -56
View File
@@ -7,11 +7,13 @@ import (
"errors"
"fmt"
"io"
"math/rand/v2"
"net"
"net/http"
"net/url"
"os"
"path"
"path/filepath"
"strconv"
"strings"
"time"
@@ -45,12 +47,33 @@ const (
bpsPerGbps = 1e9
bpsPerMbps = 1e6
bpsPerKbps = 1e3
// httpTimeout is the default time limit for one HTTP request, from
// connecting to reading the last byte of the body. It also bounds how
// long one file may take to download; fetch's --timeout changes it.
httpTimeout = 10 * time.Minute
// fetchAttempts is how many times fetch tries a request before it
// gives up on a transient failure.
fetchAttempts = 5
// firstRetryDelay is the longest fetch waits before its first retry.
// The limit doubles for each retry after that; the wait itself is
// random up to the limit.
firstRetryDelay = time.Second
// maxRetryAfter is the longest wait a server's Retry-After header can
// ask for. A server asking for longer fails the request at once.
maxRetryAfter = time.Minute
)
var (
// errURLRequired indicates the fetch command was run without a URL
// argument.
errURLRequired = errors.New("URL argument required")
// errInvalidTimeout indicates a fetch --timeout of zero or less, which
// http.Client would take as no time limit at all.
errInvalidTimeout = errors.New("--timeout must be greater than zero")
// errEmptyPath indicates an empty file path in the manifest.
errEmptyPath = errors.New("empty path")
// errAbsolutePath indicates an absolute file path in the manifest.
@@ -78,24 +101,109 @@ type DownloadProgress struct {
ETA time.Duration // Estimated time to completion
}
// httpGet issues a GET request for the given URL using the provided
// context and returns the response. The caller must close the body.
// retryingClient is the HTTP client fetch makes every request with. It
// waits up to firstDelay, which must be positive, before its first retry
// of a transient failure. Tests shorten both the client's timeout and
// firstDelay.
type retryingClient struct {
client *http.Client
firstDelay time.Duration
}
// get issues a GET for rawURL and passes a 200 OK response to use.
//
// Errors are returned unwrapped: this helper replaced direct http.Get
// calls, and each caller already supplies its own context string, so
// adding one here would change user-visible messages.
func httpGet(ctx context.Context, fileURL string) (*http.Response, error) {
req, err := http.NewRequestWithContext(ctx, http.MethodGet, fileURL, nil)
// A connection error, a timeout, or a 5xx or 429 status is retried, up to
// fetchAttempts tries in all. Before each retry it waits a random time up
// to a limit that doubles each time, unless the server's Retry-After
// header says how long to wait. Any other failure, an error from use
// included, is returned at once and unwrapped; a non-OK status is
// returned as errHTTPStatus. use must start over each time it is called,
// since a retry calls it again with a new response.
func (c retryingClient) get(
ctx context.Context, rawURL string, use func(*http.Response) error,
) error {
req, err := http.NewRequestWithContext(ctx, http.MethodGet, rawURL, nil)
if err != nil {
return nil, err
return err
}
resp, err := http.DefaultClient.Do(req)
if err != nil {
return nil, err
delay := c.firstDelay
for attempt := 1; ; attempt++ {
// Wait a random time up to delay, so that clients that failed
// together do not all retry together.
wait := rand.N(delay) //nolint:gosec // G404: jitter, not a secret
var retry bool
resp, err := c.client.Do(req)
switch {
case err != nil:
retry = isConnectionError(err)
case resp.StatusCode == http.StatusOK:
err = use(resp)
retry = isConnectionError(err)
_ = resp.Body.Close()
default:
_ = resp.Body.Close()
err = fmt.Errorf("%w %d", errHTTPStatus, resp.StatusCode)
retry = resp.StatusCode >= http.StatusInternalServerError ||
resp.StatusCode == http.StatusTooManyRequests
after, ok := retryAfter(resp.Header.Get("Retry-After"))
if ok {
wait = after
retry = retry && after <= maxRetryAfter
}
}
if !retry || attempt == fetchAttempts || ctx.Err() != nil {
return err
}
log.Warnf("%s: %s, retrying in %s", rawURL, err, wait.Round(time.Millisecond))
select {
case <-ctx.Done():
return ctx.Err()
case <-time.After(wait):
}
delay *= 2
}
}
// isConnectionError reports whether err is a connection error or a
// timeout: a connection that could not be made, was reset, or closed
// early, or a request that ran out of time.
func isConnectionError(err error) bool {
var (
opErr *net.OpError
netErr net.Error
)
return errors.As(err, &opErr) ||
(errors.As(err, &netErr) && netErr.Timeout()) ||
errors.Is(err, io.EOF) || errors.Is(err, io.ErrUnexpectedEOF)
}
// retryAfter returns the wait a Retry-After header value asks for, given
// either in seconds or as an HTTP date. ok is false if there is none.
func retryAfter(value string) (time.Duration, bool) {
seconds, err := strconv.Atoi(value)
if err == nil {
return time.Duration(seconds) * time.Second, true
}
return resp, nil
when, err := http.ParseTime(value)
if err == nil {
return time.Until(when), true
}
return 0, false
}
// reportDownloadProgress renders download progress until the channel
@@ -119,25 +227,23 @@ func reportDownloadProgress(progress <-chan DownloadProgress, done chan<- struct
}
// manifestBaseURL returns the URL of the directory containing the
// manifest, with a trailing slash.
// manifest.
func manifestBaseURL(manifestURL string) (*url.URL, error) {
baseURL, err := url.Parse(manifestURL)
parsed, err := url.Parse(manifestURL)
if err != nil {
return nil, fmt.Errorf("fetch: invalid manifest URL: %w", err)
}
baseURL.Path = path.Dir(baseURL.Path)
if !strings.HasSuffix(baseURL.Path, "/") {
baseURL.Path += "/"
}
return baseURL, nil
// JoinPath cleans the path it builds, so ".." drops the manifest's
// file name.
return parsed.JoinPath(".."), nil
}
// downloadManifestFiles downloads every file in the manifest, reporting
// progress on the progress channel.
func downloadManifestFiles(
ctx context.Context,
client retryingClient,
baseURL *url.URL,
files []*mfer.MFFilePath,
progress chan<- DownloadProgress,
@@ -149,10 +255,12 @@ func downloadManifestFiles(
return fmt.Errorf("invalid path in manifest: %w", err)
}
fileURL := baseURL.String() + encodeFilePath(f.GetPath())
// JoinPath takes escaped path text, so a name such as "100%.txt"
// must be escaped first.
fileURL := baseURL.JoinPath(encodeFilePath(f.GetPath())).String()
log.Infof("fetching %s", f.GetPath())
err = downloadFile(ctx, fileURL, localPath, f, progress)
err = downloadFile(ctx, client, fileURL, localPath, f, progress)
if err != nil {
return fmt.Errorf("failed to download %s: %w", f.GetPath(), err)
}
@@ -168,30 +276,41 @@ func (mfa *CLIApp) fetchManifestOperation(ctx *cli.Context) error {
return errURLRequired
}
inputURL := ctx.Args().Get(0)
timeout := ctx.Duration(flagTimeout)
if timeout <= 0 {
return errInvalidTimeout
}
manifestURL, err := resolveManifestURL(inputURL)
manifestURL, err := resolveManifestURL(ctx.Args().Get(0))
if err != nil {
return fmt.Errorf("invalid URL: %w", err)
}
client := retryingClient{
client: &http.Client{Timeout: timeout},
firstDelay: firstRetryDelay,
}
log.Infof("fetching manifest from %s", manifestURL)
// Fetch manifest
resp, err := httpGet(ctx.Context, manifestURL)
// Read the whole manifest before parsing it, so that a connection
// lost partway through is retried rather than reported as a bad
// manifest.
var manifestData []byte
err = client.get(ctx.Context, manifestURL, func(resp *http.Response) error {
var readErr error
manifestData, readErr = io.ReadAll(resp.Body)
return readErr
})
if err != nil {
return fmt.Errorf("failed to fetch manifest: %w", err)
}
defer func() { _ = resp.Body.Close() }()
if resp.StatusCode != http.StatusOK {
return fmt.Errorf("failed to fetch manifest: %w %d",
errHTTPStatus, resp.StatusCode)
}
// Parse manifest
manifest, err := mfer.NewManifestFromReader(resp.Body)
manifest, err := mfer.NewManifestFromReader(bytes.NewReader(manifestData))
if err != nil {
return fmt.Errorf("failed to parse manifest: %w", err)
}
@@ -221,7 +340,7 @@ func (mfa *CLIApp) fetchManifestOperation(ctx *cli.Context) error {
startTime := time.Now()
// Download each file
dlErr := downloadManifestFiles(ctx.Context, baseURL, files, progress)
dlErr := downloadManifestFiles(ctx.Context, client, baseURL, files, progress)
close(progress)
<-done
@@ -325,14 +444,7 @@ func resolveManifestURL(inputURL string) (string, error) {
return inputURL, nil
}
// Ensure path ends with /
if !strings.HasSuffix(parsed.Path, "/") {
parsed.Path += "/"
}
parsed.Path += defaultManifestName
return parsed.String(), nil
return parsed.JoinPath(defaultManifestName).String(), nil
}
// progressWriter wraps an io.Writer and reports progress to a channel.
@@ -441,6 +553,7 @@ func verifyDownloadedHash(digest []byte, entry *mfer.MFFilePath) error {
// Progress is reported via the progress channel.
func downloadFile(
ctx context.Context,
client retryingClient,
fileURL, localPath string,
entry *mfer.MFFilePath,
progress chan<- DownloadProgress,
@@ -468,18 +581,21 @@ func downloadFile(
tmpPath := tempPathFor(localPath)
// Fetch file
resp, err := httpGet(ctx, fileURL)
if err != nil {
return fmt.Errorf("HTTP request failed: %w", err)
}
defer func() { _ = resp.Body.Close() }()
if resp.StatusCode != http.StatusOK {
return fmt.Errorf("%w %d", errHTTPStatus, resp.StatusCode)
}
return client.get(ctx, fileURL, func(resp *http.Response) error {
return saveResponse(resp, tmpPath, localPath, entry, progress)
})
}
// saveResponse writes resp's body to tmpPath, verifies it against entry,
// and renames it to localPath. It starts a new temp file each time and
// removes it on failure, so a retry after a failed try never appends to
// or keeps a partial file.
func saveResponse(
resp *http.Response,
tmpPath, localPath string,
entry *mfer.MFFilePath,
progress chan<- DownloadProgress,
) error {
// Determine expected size
expectedSize := entry.GetSize()
@@ -488,7 +604,7 @@ func downloadFile(
totalBytes = expectedSize
}
err = checkNoSymlinks(tmpPath)
err := checkNoSymlinks(tmpPath)
if err != nil {
return err
}
+388 -4
View File
@@ -4,16 +4,24 @@ package cli
import (
"bytes"
"context"
"flag"
"fmt"
"io"
"net"
"net/http"
"net/http/httptest"
"os"
"path/filepath"
"strconv"
"sync"
"sync/atomic"
"testing"
"time"
"github.com/spf13/afero"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
urfcli "github.com/urfave/cli/v2"
"sneak.berlin/go/mfer/mfer"
)
@@ -214,6 +222,41 @@ func fetchTestHandler(
}
}
// manifestOf scans a tree holding files and returns its manifest bytes.
func manifestOf(t *testing.T, files map[string][]byte) []byte {
t.Helper()
sourceFs := afero.NewMemMapFs()
for p, content := range files {
require.NoError(t, sourceFs.MkdirAll(filepath.Dir("/"+p), 0o755))
require.NoError(t, afero.WriteFile(sourceFs, "/"+p, content, 0o644))
}
return scanToManifest(t, sourceFs)
}
// testClient returns the client tests download with. Its retries wait
// milliseconds rather than seconds.
func testClient() retryingClient {
return retryingClient{
client: &http.Client{Timeout: 10 * time.Second},
firstDelay: time.Millisecond,
}
}
// getNothing calls client.get for rawURL with a use that reads nothing,
// under a context that expires after timeout. It holds runMu, since get
// logs each retry to the process-global logger, and starts the timeout
// only once it has the lock.
func getNothing(client retryingClient, rawURL string, timeout time.Duration) error {
return runLocked(func() error {
ctx, cancel := context.WithTimeout(context.Background(), timeout)
defer cancel()
return client.get(ctx, rawURL, func(*http.Response) error { return nil })
})
}
//nolint:paralleltest // changes the process-global working directory
func TestFetchFromHTTP(t *testing.T) {
// Create source filesystem with test files
@@ -266,7 +309,8 @@ func TestFetchFromHTTP(t *testing.T) {
require.NoError(t, err)
fileURL := baseURL + f.GetPath()
err = downloadFile(context.Background(), fileURL, localPath, f, progress)
err = downloadFile(context.Background(), testClient(),
fileURL, localPath, f, progress)
require.NoError(t, err, "failed to download %s", f.GetPath())
}
@@ -313,7 +357,7 @@ func TestFetchHashMismatch(t *testing.T) {
chdirTemp(t)
// Try to download - should fail with hash mismatch
err = downloadFile(context.Background(),
err = downloadFile(context.Background(), testClient(),
server.URL+"/file.txt", testFileTxt, files[0], nil)
require.Error(t, err)
assert.Contains(t, err.Error(), "mismatch")
@@ -359,7 +403,7 @@ func TestFetchSizeMismatch(t *testing.T) {
chdirTemp(t)
// Try to download - should fail with size mismatch
err = downloadFile(context.Background(),
err = downloadFile(context.Background(), testClient(),
server.URL+"/file.txt", testFileTxt, files[0], nil)
require.Error(t, err)
assert.Contains(t, err.Error(), "size mismatch")
@@ -417,7 +461,7 @@ func TestFetchProgress(t *testing.T) {
}()
// Download
err = downloadFile(context.Background(),
err = downloadFile(context.Background(), testClient(),
server.URL+"/large.txt", "large.txt", files[0], progress)
close(progress)
<-done
@@ -523,3 +567,343 @@ func TestFetchReplacesHardLinkAtTempName(t *testing.T) {
require.NoError(t, err)
assert.Equal(t, "outside", string(outside), "fetch wrote outside the destination")
}
// TestGetRetriesTransientStatusesOnly answers every request with one
// status and counts the requests: a 5xx or 429 is retried until
// fetchAttempts runs out, and any other status fails at once.
func TestGetRetriesTransientStatusesOnly(t *testing.T) {
t.Parallel()
tests := []struct {
status int
requests int32
}{
{http.StatusNotFound, 1},
{http.StatusForbidden, 1},
{http.StatusInternalServerError, fetchAttempts},
{http.StatusServiceUnavailable, fetchAttempts},
{http.StatusTooManyRequests, fetchAttempts},
}
for _, tt := range tests {
t.Run(http.StatusText(tt.status), func(t *testing.T) {
t.Parallel()
var requests atomic.Int32
server := httptest.NewServer(
http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
requests.Add(1)
w.WriteHeader(tt.status)
}))
defer server.Close()
err := getNothing(testClient(), server.URL, 10*time.Second)
require.ErrorIs(t, err, errHTTPStatus)
require.EqualError(t, err, fmt.Sprintf("HTTP %d", tt.status))
assert.Equal(t, tt.requests, requests.Load())
})
}
}
// TestGetTimesOutOnStalledServer points get at a server that takes a
// request and never answers it. The try must give up at the client's
// timeout and be retried; when every try stalls, get must return a
// timeout error rather than hang.
func TestGetTimesOutOnStalledServer(t *testing.T) {
t.Parallel()
tests := []struct {
name string
stallEvery bool
}{
{"first request stalls", false},
{"every request stalls", true},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()
var requests atomic.Int32
stop := make(chan struct{})
server := httptest.NewServer(
http.HandlerFunc(func(_ http.ResponseWriter, r *http.Request) {
if requests.Add(1) == 1 || tt.stallEvery {
select {
case <-r.Context().Done():
case <-stop:
}
}
}))
defer server.Close()
defer close(stop)
client := testClient()
client.client.Timeout = 50 * time.Millisecond
err := getNothing(client, server.URL, 10*time.Second)
if !tt.stallEvery {
require.NoError(t, err)
return
}
var netErr net.Error
require.ErrorAs(t, err, &netErr)
assert.True(t, netErr.Timeout(), "want a timeout, got %v", err)
})
}
}
// TestGetHonorsRetryAfter answers the first request with a 503 and a
// Retry-After header, and any later one with 200 OK. The client's own
// wait before a retry is an hour, so get finishes in time only if it
// waits as long as Retry-After says instead. A Retry-After longer than
// maxRetryAfter must fail at once.
func TestGetHonorsRetryAfter(t *testing.T) {
t.Parallel()
tests := []struct {
name string
value string
requests int32
wantErr bool
}{
{"seconds", "0", 2, false},
{"HTTP date", time.Now().Add(-time.Minute).UTC().Format(http.TimeFormat), 2, false},
{"too long", strconv.Itoa(int((maxRetryAfter + time.Second).Seconds())), 1, true},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()
var requests atomic.Int32
server := httptest.NewServer(
http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
if requests.Add(1) == 1 {
w.Header().Set("Retry-After", tt.value)
w.WriteHeader(http.StatusServiceUnavailable)
}
}))
defer server.Close()
client := testClient()
client.firstDelay = time.Hour
err := getNothing(client, server.URL, 10*time.Second)
if tt.wantErr {
require.ErrorIs(t, err, errHTTPStatus)
} else {
require.NoError(t, err)
}
assert.Equal(t, tt.requests, requests.Load())
})
}
}
// TestGetStopsWaitingWhenCanceled gives get a server that always answers
// 503 and an hour's wait before each retry, then lets the context expire
// during that wait. get returning at all shows it stopped waiting.
func TestGetStopsWaitingWhenCanceled(t *testing.T) {
t.Parallel()
server := httptest.NewServer(
http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusServiceUnavailable)
}))
defer server.Close()
client := testClient()
client.firstDelay = time.Hour
err := getNothing(client, server.URL, 50*time.Millisecond)
require.ErrorIs(t, err, context.DeadlineExceeded)
}
// TestDownloadFileRetriesToSuccess serves a file that fails twice before
// it succeeds: first with a 503, then with a body cut off halfway. The
// download must end with the whole, verified file and no temp file.
//
//nolint:paralleltest // changes the process-global working directory
func TestDownloadFileRetriesToSuccess(t *testing.T) {
content := []byte("the whole file, every byte of it")
manifest, err := mfer.NewManifestFromReader(bytes.NewReader(
manifestOf(t, map[string][]byte{testFileTxt: content})))
require.NoError(t, err)
var requests atomic.Int32
server := httptest.NewServer(
http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
switch requests.Add(1) {
case 1:
w.WriteHeader(http.StatusServiceUnavailable)
case 2:
// Promise the whole file but send half of it; the server
// then closes the connection.
w.Header().Set("Content-Length", strconv.Itoa(len(content)))
_, _ = w.Write(content[:len(content)/2])
default:
_, _ = w.Write(content)
}
}))
defer server.Close()
chdirTemp(t)
err = downloadFile(context.Background(), testClient(),
server.URL+"/"+testFileTxt, testFileTxt, manifest.Files()[0], nil)
require.NoError(t, err)
assert.Equal(t, int32(3), requests.Load())
fetched, err := os.ReadFile(testFileTxt)
require.NoError(t, err)
assert.Equal(t, content, fetched)
_, err = os.Stat(".file.txt.tmp")
assert.True(t, os.IsNotExist(err), "temp file left behind")
}
// TestFetchBaseURLForms fetches one tree by its directory URL with and
// without a trailing slash, with a query string, and by its manifest URL.
// Each must request the same manifest and file paths.
//
//nolint:paralleltest // changes the process-global working directory
func TestFetchBaseURLForms(t *testing.T) {
files := map[string][]byte{"one.txt": []byte("1"), "sub/two.txt": []byte("2")}
tree := http.StripPrefix("/tree", fetchTestHandler(manifestOf(t, files), files))
var (
mu sync.Mutex
requested []string
)
server := httptest.NewServer(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
mu.Lock()
requested = append(requested, r.URL.Path)
mu.Unlock()
tree.ServeHTTP(w, r)
}))
defer server.Close()
inputs := []string{"/tree", "/tree/", "/tree?key=value", "/tree/index.mf"}
for _, input := range inputs {
t.Run(input, func(t *testing.T) {
mu.Lock()
requested = nil
mu.Unlock()
chdirTemp(t)
opts := testOpts([]string{testApp, cmdFetch, "-q", server.URL + input},
afero.NewOsFs())
require.Equal(t, 0, runCLI(opts), testStderr(t, opts))
mu.Lock()
defer mu.Unlock()
assert.ElementsMatch(t,
[]string{"/tree/index.mf", "/tree/one.txt", "/tree/sub/two.txt"}, requested)
})
}
}
// TestFetchEscapedPaths fetches files whose names need escaping in a URL,
// one of them a name that is itself an escape sequence. Each must arrive
// under its own name with its own content.
//
//nolint:paralleltest // changes the process-global working directory
func TestFetchEscapedPaths(t *testing.T) {
files := map[string][]byte{
"a b.txt": []byte("space"),
"a%20b.txt": []byte("percent sign, two, zero"),
"100%.txt": []byte("percent sign"),
"q?x=1#frag.txt": []byte("question mark and hash"),
"dir with space/sub.txt": []byte("directory with a space"),
}
server := httptest.NewServer(fetchTestHandler(manifestOf(t, files), files))
defer server.Close()
chdirTemp(t)
opts := testOpts([]string{testApp, cmdFetch, "-q", server.URL}, afero.NewOsFs())
require.Equal(t, 0, runCLI(opts), testStderr(t, opts))
for name, content := range files {
fetched, err := os.ReadFile(name) //nolint:gosec // test-controlled path
require.NoError(t, err)
assert.Equal(t, content, fetched, name)
}
}
// TestFetchTimeoutFlag runs fetch with --timeout against a server that
// never answers. Without the flag's limit the request would wait forever;
// once fetch gives up on it, the server cancels fetch's context so that
// fetch returns instead of retrying.
func TestFetchTimeoutFlag(t *testing.T) {
t.Parallel()
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
server := httptest.NewServer(
http.HandlerFunc(func(_ http.ResponseWriter, r *http.Request) {
<-r.Context().Done() // fetch gave up on this request
cancel()
}))
defer server.Close()
mfa := &CLIApp{Fs: afero.NewMemMapFs()}
set := flag.NewFlagSet(cmdFetch, flag.ContinueOnError)
for _, f := range mfa.fetchCommand().Flags {
require.NoError(t, f.Apply(set))
}
require.NoError(t, set.Parse([]string{"--" + flagTimeout, "100ms", server.URL}))
cliCtx := urfcli.NewContext(nil, set, nil)
cliCtx.Context = ctx
// fetchManifestOperation logs to the process-global logger.
err := runLocked(func() error { return mfa.fetchManifestOperation(cliCtx) })
require.Error(t, err)
}
// TestFetchRejectsTimeoutOfZeroOrLess runs fetch with a --timeout of zero
// and of less than zero. http.Client takes either as no time limit at all,
// so fetch must refuse it before making any request.
func TestFetchRejectsTimeoutOfZeroOrLess(t *testing.T) {
t.Parallel()
var requests atomic.Int32
server := httptest.NewServer(
http.HandlerFunc(func(http.ResponseWriter, *http.Request) {
requests.Add(1)
}))
defer server.Close()
for _, timeout := range []string{"0", "-1s"} {
opts := testOpts(
[]string{testApp, cmdFetch, "--" + flagTimeout + "=" + timeout, server.URL},
afero.NewMemMapFs())
assert.Equal(t, 1, runCLI(opts), timeout)
assert.Contains(t, testStderr(t, opts), errInvalidTimeout.Error(), timeout)
}
assert.Zero(t, requests.Load(), "fetch made a request")
}
+9 -1
View File
@@ -23,6 +23,7 @@ const (
cmdVersion = "version"
flagProgress = "progress"
flagTimeout = "timeout"
manifestArgsUsage = "[manifest file]"
@@ -346,7 +347,14 @@ func (mfa *CLIApp) fetchCommand() *cli.Command {
return mfa.fetchManifestOperation(c)
},
Flags: commonFlags(),
Flags: append(commonFlags(),
&cli.DurationFlag{
Name: flagTimeout,
Value: httpTimeout,
Usage: "Time limit for each HTTP request, including the download " +
"of its body",
},
),
}
}
+149 -55
View File
@@ -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")
}
+220 -3
View File
@@ -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())
}