Tidy up cmd/torrent cleanup and websocket trackers logging

diff --git a/client.go b/client.go
index 414a3dfd263eb4bb22dbb892c442e64950c68569..31a6d88c99ceaafe86e5cc38c55775289d79bbe7 100644 (file)
--- a/client.go
+++ b/client.go
@@ -316,7 +316,7 @@ func NewClient(cfg *ClientConfig) (cl *Client, err error) {
 
        cl.websocketTrackers = websocketTrackers{
                PeerId: cl.peerID,
-               Logger: cl.logger,
+               Logger: cl.logger.WithNames("websocketTrackers"),
                GetAnnounceRequest: func(
                        event tracker.AnnounceEvent, infoHash [20]byte,
                ) (

diff --git a/cmd/torrent/download.go b/cmd/torrent/download.go
index 604820181dad5413084ec713272be892cb334119..9bc16c1598e683fe2130fc863da45733520ecca2 100644 (file)
--- a/cmd/torrent/download.go
+++ b/cmd/torrent/download.go
@@ -405,7 +405,7 @@ func downloadErr(flags downloadFlags) error {
                        <-ctx.Done()
                }
        }
-       spew.Dump(expvar.Get("torrent").(*expvar.Map).Get("chunks received"))
+       fmt.Printf("chunks received: %v\n", &torrent.ChunksReceived)
        spew.Dump(client.ConnStats())
        clStats := client.ConnStats()
        sentOverhead := clStats.BytesWritten.Int64() - clStats.BytesWrittenData.Int64()

diff --git a/cmd/torrent/main.go b/cmd/torrent/main.go
index 2c1081bbb1bb338c53d8aa15fe2c281fa5c2e2f5..a15351b979dbb44539268c2e9d59aba37a85010d 100644 (file)
--- a/cmd/torrent/main.go
+++ b/cmd/torrent/main.go
@@ -5,6 +5,7 @@ import (
        "context"
        "encoding/json"
        "fmt"
+       app "github.com/anacrolix/gostdapp"
        "io"
        stdLog "log"
        "net/http"
@@ -39,12 +40,15 @@ func shutdownTracerProvider(ctx context.Context, tp *trace.TracerProvider) {
 }
 
 func main() {
+       app.RunContext(mainErr)
+}
+
+func mainErr(ctx context.Context) error {
        defer stdLog.SetFlags(stdLog.Flags() | stdLog.Lshortfile)
 
-       ctx := context.Background()
        tracingExporter, err := otlptracegrpc.New(ctx)
        if err != nil {
-               log.Fatalf("creating tracing exporter: %v", err)
+               return fmt.Errorf("creating tracing exporter: %w", err)
        }
        tracerProvider := trace.NewTracerProvider(trace.WithBatcher(tracingExporter))
        defer shutdownTracerProvider(ctx, tracerProvider)
@@ -148,5 +152,8 @@ func main() {
                bargle.Subcommand{Name: "serve", Command: serve()},
                bargle.Subcommand{Name: "create", Command: create()},
        )
+       // Well this sux, this old version of bargle doesn't return so we can let the gostdapp Context
+       // clean up.
        main.Run()
+       return nil
 }

diff --git a/global.go b/global.go
index 585bbeafaa576e7663e1604f47ab7657ae45a8e3..c44dfb37c876f8e0d8f8d62bbcdd2a39d6674cf6 100644 (file)
--- a/global.go
+++ b/global.go
@@ -25,7 +25,7 @@ func defaultPeerExtensionBytes() PeerExtensionBits {
 
 func init() {
        torrent.Set("peers supporting extension", &peersSupportingExtension)
-       torrent.Set("chunks received", &chunksReceived)
+       torrent.Set("chunks received", &ChunksReceived)
 }
 
 // I could move a lot of these counters to their own file, but I suspect they
@@ -33,7 +33,9 @@ func init() {
 var (
        torrent                  = expvar.NewMap("torrent")
        peersSupportingExtension expvar.Map
-       chunksReceived           expvar.Map
+       // This could move at any time. It contains counts of chunks received and the conditions they
+       // were received.
+       ChunksReceived expvar.Map
 
        pieceHashedCorrect    = expvar.NewInt("pieceHashedCorrect")
        pieceHashedNotCorrect = expvar.NewInt("pieceHashedNotCorrect")

diff --git a/go.sum b/go.sum
index 14210a02e5a45dddf6cafd112fd9b4ba1cbcf30c..ae5edd04677b7523257f58df1ed8dedfc079025a 100644 (file)
--- a/go.sum
+++ b/go.sum
@@ -66,8 +66,6 @@ github.com/alexflint/go-scalar v1.1.0 h1:aaAouLLzI9TChcPXotr6gUhq+Scr8rl0P9P4Pnl
 github.com/alexflint/go-scalar v1.1.0/go.mod h1:LoFvNMqS1CPrMVltza4LvnGKhaSpc3oyLEBUZVhhS2o=
 github.com/anacrolix/backtrace v0.0.0-20221205112523-22a61db8f82e h1:A0Ty9UeyBDIo29ZMnk0AvPqWDIa4HVvCaJqWNlCrMXA=
 github.com/anacrolix/backtrace v0.0.0-20221205112523-22a61db8f82e/go.mod h1:4YFqy+788tLJWtin2jNliYVJi+8aDejG9zcu/2/pONw=
-github.com/anacrolix/bargle v0.0.0-20220630015206-d7a4d433886a h1:KCP9QvHlLoUQBOaTf/YCuOzG91Ym1cPB6S68O4Q3puo=
-github.com/anacrolix/bargle v0.0.0-20220630015206-d7a4d433886a/go.mod h1:9xUiZbkh+94FbiIAL1HXpAIBa832f3Mp07rRPl5c5RQ=
 github.com/anacrolix/bargle v0.0.0-20221014000746-4f2739072e9d h1:ypNOsIwvdumNRlqWj/hsnLs5TyQWQOylwi+T9Qs454A=
 github.com/anacrolix/bargle v0.0.0-20221014000746-4f2739072e9d/go.mod h1:9xUiZbkh+94FbiIAL1HXpAIBa832f3Mp07rRPl5c5RQ=
 github.com/anacrolix/chansync v0.4.1-0.20240627045151-1aa1ac392fe8 h1:eyb0bBaQKMOh5Se/Qg54shijc8K4zpQiOjEhKFADkQM=

diff --git a/peer.go b/peer.go
index 55e8f19fa7cd3e241e7d0976d4e6422d741e21d2..e28b5afd6960dcbe6889ff9a6bea17f7b5c6799f 100644 (file)
--- a/peer.go
+++ b/peer.go
@@ -608,7 +608,7 @@ func (c *Peer) doChunkReadStats(size int64) {
 
 // Handle a received chunk from a peer.
 func (c *Peer) receiveChunk(msg *pp.Message) error {
-       chunksReceived.Add("total", 1)
+       ChunksReceived.Add("total", 1)
 
        ppReq := newRequestFromMessage(msg)
        t := c.t
@@ -628,17 +628,17 @@ func (c *Peer) receiveChunk(msg *pp.Message) error {
        defer recordBlockForSmartBan()
 
        if c.peerChoking {
-               chunksReceived.Add("while choked", 1)
+               ChunksReceived.Add("while choked", 1)
        }
 
        if c.validReceiveChunks[req] <= 0 {
-               chunksReceived.Add("unexpected", 1)
+               ChunksReceived.Add("unexpected", 1)
                return errors.New("received unexpected chunk")
        }
        c.decExpectedChunkReceive(req)
 
        if c.peerChoking && c.peerAllowedFast.Contains(pieceIndex(ppReq.Index)) {
-               chunksReceived.Add("due to allowed fast", 1)
+               ChunksReceived.Add("due to allowed fast", 1)
        }
 
        // The request needs to be deleted immediately to prevent cancels occurring asynchronously when
@@ -661,7 +661,7 @@ func (c *Peer) receiveChunk(msg *pp.Message) error {
                                c.updateRequests("Peer.receiveChunk deleted request")
                        }
                } else {
-                       chunksReceived.Add("unintended", 1)
+                       ChunksReceived.Add("unintended", 1)
                }
        }
 
@@ -670,7 +670,7 @@ func (c *Peer) receiveChunk(msg *pp.Message) error {
        // Do we actually want this chunk?
        if t.haveChunk(ppReq) {
                // panic(fmt.Sprintf("%+v", ppReq))
-               chunksReceived.Add("redundant", 1)
+               ChunksReceived.Add("redundant", 1)
                c.allStats(add(1, func(cs *ConnStats) *Count { return &cs.ChunksReadWasted }))
                return nil
        }

diff --git a/torrent.go b/torrent.go
index 28bda274a238654e5a641322301d2c0ca93f2977..2742ad6a90afd30da10d4544cdc103f1cdc6365c 100644 (file)
--- a/torrent.go
+++ b/torrent.go
@@ -1910,10 +1910,11 @@ func (t *Torrent) startWebsocketAnnouncer(u url.URL, shortInfohash [20]byte) tor
        go func() {
                err := wtc.Announce(tracker.Started, shortInfohash)
                if err != nil {
-                       t.logger.WithDefaultLevel(log.Warning).Printf(
-                               "error in initial announce to %q: %v",
-                               u.String(), err,
-                       )
+                       level := log.Warning
+                       if t.closed.IsSet() {
+                               level = log.Debug
+                       }
+                       t.logger.Levelf(level, "error doing initial announce to %q: %v", u.String(), err)
                }
        }()
        return wst

diff --git a/webtorrent/tracker-client.go b/webtorrent/tracker-client.go
index 09ea652f234d7fa25c88e00773ae9bf58f72569e..8b307c7beacb22667f771698c5ea638616f34b6d 100644 (file)
--- a/webtorrent/tracker-client.go
+++ b/webtorrent/tracker-client.go
@@ -234,6 +234,7 @@ func (tc *TrackerClient) Announce(event tracker.AnnounceEvent, infoHash [20]byte
                return fmt.Errorf("creating offer: %w", err)
        }
 
+       tc.Logger.Levelf(log.Debug, "announcing offer")
        err = tc.announce(event, infoHash, []outboundOffer{
                {
                        offerId: offerIDBinary,
@@ -308,7 +309,7 @@ func (tc *TrackerClient) trackerReadLoop(tracker *websocket.Conn) error {
                if err != nil {
                        return fmt.Errorf("read message error: %w", err)
                }
-               // tc.Logger.WithDefaultLevel(log.Debug).Printf("received message from tracker: %q", message)
+               tc.Logger.Levelf(log.Debug, "received message: %q", message)
 
                var ar AnnounceResponse
                if err := json.Unmarshal(message, &ar); err != nil {
@@ -333,7 +334,13 @@ func (tc *TrackerClient) trackerReadLoop(tracker *websocket.Conn) error {
                case ar.Answer != nil:
                        tc.handleAnswer(ar.OfferID, *ar.Answer)
                default:
-                       tc.Logger.Levelf(log.Warning, "unhandled announce response %q", message)
+                       // wss://tracker.openwebtorrent.com appears to respond to an initial announces without
+                       // an offer or answer. I think that's fine. Let's check it at least contains an
+                       // infohash.
+                       _, err := jsonStringToInfoHash(ar.InfoHash)
+                       if err != nil {
+                               tc.Logger.Levelf(log.Warning, "unexpected announce response %q", message)
+                       }
                }
        }
 }

diff --git a/webtorrent/transport.go b/webtorrent/transport.go
index a8b6a845489e4d4003cc3610bfb3b3fdff000785..75f1376299e060ac7b622ff57bcb265ed7b3efcb 100644 (file)
--- a/webtorrent/transport.go
+++ b/webtorrent/transport.go
@@ -70,7 +70,7 @@ func newPeerConnection(logger log.Logger, iceServers []webrtc.ICEServer) (*wrapp
        }
        // If the state change handler intends to call Close, it should call it on the wrapper.
        wpc.OnConnectionStateChange(func(state webrtc.PeerConnectionState) {
-               logger.Levelf(log.Warning, "webrtc PeerConnection state changed to %v", state)
+               logger.Levelf(log.Debug, "webrtc PeerConnection state changed to %v", state)
                span.AddEvent("connection state changed", trace.WithAttributes(attribute.String("state", state.String())))
        })
        return wpc, nil

diff --git a/wstracker.go b/wstracker.go
index f94c3923b094995467d9b918da65a92136197e9d..8952cc9475511cdc8f447128ec771eec03b325f0 100644 (file)
--- a/wstracker.go
+++ b/wstracker.go
@@ -57,7 +57,11 @@ func (me *websocketTrackers) Get(url string, infoHash [20]byte) (*webtorrent.Tra
        defer me.mu.Unlock()
        value, ok := me.clients[url]
        if !ok {
-               dialer := &websocket.Dialer{Proxy: me.Proxy, NetDialContext: me.DialContext, HandshakeTimeout: websocket.DefaultDialer.HandshakeTimeout}
+               dialer := &websocket.Dialer{
+                       Proxy:            me.Proxy,
+                       NetDialContext:   me.DialContext,
+                       HandshakeTimeout: websocket.DefaultDialer.HandshakeTimeout,
+               }
                value = &refCountedWebtorrentTrackerClient{
                        TrackerClient: webtorrent.TrackerClient{
                                Dialer:             dialer,
@@ -65,9 +69,11 @@ func (me *websocketTrackers) Get(url string, infoHash [20]byte) (*webtorrent.Tra
                                GetAnnounceRequest: me.GetAnnounceRequest,
                                PeerId:             me.PeerId,
                                OnConn:             me.OnConn,
-                               Logger: me.Logger.WithText(func(m log.Msg) string {
-                                       return fmt.Sprintf("tracker client for %q: %v", url, m)
-                               }),
+                               Logger: me.Logger.WithText(
+                                       func(m log.Msg) string {
+                                               return fmt.Sprintf("tracker client for %q: %v", url, m)
+                                       },
+                               ),
                                WebsocketTrackerHttpHeader: me.WebsocketTrackerHttpHeader,
                                ICEServers:                 me.ICEServers,
                        },