Webseed update timer

[mh0lt]

This fixes an issue with small files (1 to 2 pieces) when they are seeded from web peers into a sparse torrent network.

If there are a significant number of peers in the network which don't have the requested torrent on initial download a webpeer with the file is not guaranteed to be the selected request provider. When this happens if the webpeer does not do an update to its request state it will wait forever and the torrent will never get downloaded.

This fix also includes an update to steal processing in applyRequestState - so that rejecting and cancelled peers do not steal from a potentially good peer. Also the steal logic uses after instead of before in its time logic, to avoid a peer with equal time (which is zero at initial download) preemptively stealing as this creates a chain reaction on initial download.

[mh0lt]

As additional background here are the torrent details from a resent test-run of the erigon downloader.

The overall run results where as follows:

progress="100.00% 3.3TB/3.3TB" time-left=0hrs:0m total-time=8h25m20s download=117.7MB/s upload=0B/s peers=58 files=1136 metadata=1136/1136 connections=62 alloc=3.0GB sys=7.0GB
files=6 list="v1-001000-001500-transactions.seg (0%), v1-001500-002000-transactions.seg (0%), v1-034000-034500-borevents.seg (2%), v1-038000-038500-borevents.seg (6%), v1-038500-039000-borevents.seg (6%), v1-039500-040000-borevents.seg (6%)"

len=1136 webTransfers=0 torrent=1136 db=0 t-complete=0 db-complete=1130 webseed-trips=1802116 webseed-discards=0 webseed-fails=2 webseed-bytes=3.4TB localHashes=0 localHashTime=0s

The status of the incomplete files reveals this:

[DBUG] [04-18|07:15:26.452] [snapshots] torrent status: v1-001500-002000-transactions.seg
    0.000000% of 1131372 bytes (1.1 MB)
    Infohash: 2f074aea66fd57da75f3ba16279491e9e3bed5e3
    Metadata length: 116
    Piece length: 2097152 (0.25 chunks)
    Num Pieces: 1 (0 completed)
    Piece States: 1.
    Piece availability frequency: 13: 1
    Reader Pieces:
    Enabled trackers:
        URL                                                Extra
        "udp4://open.stealth.si:80/announce"               next ann: 16m4s, last ann: 0 peers
        "udp4://opentracker.i2p.rocks:6969/announce"       next ann: 3s, last ann: error getting ip: lookup opentracker.i2p.rocks: no such host
        "udp4://tracker.openbittorrent.com:6969/announce"  next ann: anytime, last ann: announcing: context deadline exceeded
        "udp4://tracker.opentrackr.org:1337/announce"      next ann: 19m8s, last ann: 0 peers
        "udp4://tracker.torrent.eu.org:451/announce"       next ann: 21m4s, last ann: 0 peers
    DHT Announces: 0
    (torrent.TorrentStats) {
     ConnStats: (torrent.ConnStats) {
      BytesWritten: (torrent.Count) 7364950,
      BytesWrittenData: (torrent.Count) 0,
      BytesRead: (torrent.Count) 6251774,
      BytesReadData: (torrent.Count) 0,
      BytesReadUsefulData: (torrent.Count) 0,
      BytesReadUsefulIntendedData: (torrent.Count) 0,
      ChunksWritten: (torrent.Count) 0,
      ChunksRead: (torrent.Count) 0,
      ChunksReadUseful: (torrent.Count) 0,
      ChunksReadWasted: (torrent.Count) 0,
      MetadataChunksRead: (torrent.Count) 1,
      PiecesDirtiedGood: (torrent.Count) 0,
      PiecesDirtiedBad: (torrent.Count) 0
     },
     TotalPeers: (int) 180,
     PendingPeers: (int) 172,
     ActivePeers: (int) 10,
     ConnectedSeeders: (int) 10,
     HalfOpenPeers: (int) 0,
     PiecesComplete: (int) 0
    }
    webseeds:
    - https://erigon2-v3-snapshots-bor-mainnet.erigon.network/v1-001500-002000-transactions.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 14h33m43.911878409s, etime: 1.221663ms
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v1-001500-002000-transactions.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 14h33m43.910610556s, etime: 3.301163ms
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v2/v1-001500-002000-transactions.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 14h33m43.910659669s, etime: 31.308µs
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    10 peer conns:
    - 10.132.0.29:42069-202.8.11.59:29368
      peer id: "-GT0003-\x02\u01bc\xa4m\x14\x8b:\xe5]\xfcy"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 2 unsent events
      bep40-prio: f81a6225
      last msg: 0.13s ago, connected: 52481.32s ago, last helpful: 52480.64s ago, itime: 14h33m43.907394151s, etime: 14h16m14.616077259s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 1+0/(2/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces: 0(1)
    - 10.132.0.29:42069-209.249.216.154:55144
      peer id: "-GT0003-\xf0s?\xfd\x1b\x9c=@\xc4\u36a5"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 2 unsent events
      bep40-prio: dce6f64c
      last msg: 18.32s ago, connected: 97.04s ago, last helpful: never, itime: 1m36.936515091s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:37730-43.134.130.32:31414
      peer id: "-GT0003-0D\x92\u0383\xf1X5\xe6\xb8\x0e\x85"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 2 unsent events
      bep40-prio: dce6f64c
      last msg: 18.32s ago, connected: 97.04s ago, last helpful: never, itime: 1m36.936515091s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:37730-43.134.130.32:31414
      peer id: "-GT0003-0D\x92\u0383\xf1X5\xe6\xb8\x0e\x85"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 982c2944
      last msg: 7.11s ago, connected: 187.28s ago, last helpful: never, itime: 3m7.278462732s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eTr-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:41498-144.76.221.114:42069
      peer id: "-GT0003-(\x8b7\xd0\x1eS\x10\xb5\x92\x16/F"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 2 unsent events
      bep40-prio: 970820bd
      last msg: 40.98s ago, connected: 160.98s ago, last helpful: never, itime: 2m40.982199153s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eTr-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-23.88.5.62:39586
      peer id: "-GT0003-\xaf\x00\x96[\x04\xfa\xd4\xe12\x16c}"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 94d93e66
      last msg: 13.77s ago, connected: 73.78s ago, last helpful: never, itime: 1m13.772312148s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-103.106.59.59:42069
      peer id: "-GT0003-\x82\xdf\x19[\x1dP\x91\xe0\xac2\xbd\xb1"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 7b379f7d
      last msg: 42.67s ago, connected: 192.29s ago, last helpful: never, itime: 3m12.123860382s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-168.119.90.117:59776
      peer id: "-GT0003-!\xae|\xeb\"\u02a4B\xf11\x1b\xb7"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 2 unsent events
      bep40-prio: 744d7372
      last msg: 19.96s ago, connected: 169.02s ago, last helpful: never, itime: 2m49.011596262s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-103.106.59.6:43467
      peer id: "-GT0003-;h1\x9f\v\t\xd7K&\xe3;~"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 5e984c0e
      last msg: 15.38s ago, connected: 183.94s ago, last helpful: never, itime: 3m3.855859438s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-217.115.120.70:39008
      peer id: "-GT0003-T\u06541n\x9d\xd0\xfc\xfb\xafq\xd0"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 4004c3ed
      last msg: 29.69s ago, connected: 29.71s ago, last helpful: never, itime: 29.689665705s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-31.172.68.140:42069
      peer id: "-GT0003-\xa0S\x80|\x89/26Gi\xc3\xe7"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 2 unsent events
      bep40-prio: 33cdded9
      last msg: 23.19s ago, connected: 104.11s ago, last helpful: never, itime: 1m44.088031355s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces: 
[DBUG] [04-18|07:15:26.452] [snapshots] torrent status: v1-001000-001500-transactions.seg
    0.000000% of 1088975 bytes (1.1 MB)
    Infohash: 76b4fa35c6805dbb5be2eb6ed74b2576ce26d09a
    Metadata length: 116
    Piece length: 2097152 (0.25 chunks)
    Num Pieces: 1 (0 completed)
    Piece States: 1.
    Piece availability frequency: 13: 1
    Reader Pieces:
    Enabled trackers:
        URL                                                Extra
        "udp4://open.stealth.si:80/announce"               next ann: 22m8s, last ann: 0 peers
        "udp4://opentracker.i2p.rocks:6969/announce"       next ann: 3s, last ann: error getting ip: lookup opentracker.i2p.rocks: no such host
        "udp4://tracker.openbittorrent.com:6969/announce"  next ann: anytime, last ann: announcing: context deadline exceeded
        "udp4://tracker.opentrackr.org:1337/announce"      next ann: 20m13s, last ann: 0 peers
        "udp4://tracker.torrent.eu.org:451/announce"       next ann: 19m59s, last ann: 0 peers
    DHT Announces: 0
    (torrent.TorrentStats) {
     ConnStats: (torrent.ConnStats) {
      BytesWritten: (torrent.Count) 6750742,
      BytesWrittenData: (torrent.Count) 0,
      BytesRead: (torrent.Count) 5524147,
      BytesReadData: (torrent.Count) 0,
      BytesReadUsefulData: (torrent.Count) 0,
      BytesReadUsefulIntendedData: (torrent.Count) 0,
      ChunksWritten: (torrent.Count) 0,
      ChunksRead: (torrent.Count) 0,
      ChunksReadUseful: (torrent.Count) 0,
      ChunksReadWasted: (torrent.Count) 0,
      MetadataChunksRead: (torrent.Count) 1,
      PiecesDirtiedGood: (torrent.Count) 0,
      PiecesDirtiedBad: (torrent.Count) 0
     },
     TotalPeers: (int) 252,
     PendingPeers: (int) 243,
     ActivePeers: (int) 10,
     ConnectedSeeders: (int) 10,
     HalfOpenPeers: (int) 0,
     PiecesComplete: (int) 0
    }
    webseeds:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v1-001000-001500-transactions.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 14h34m3.315696968s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v2/v1-001000-001500-transactions.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 14h34m3.315630104s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon2-v3-snapshots-bor-mainnet.erigon.network/v1-001000-001500-transactions.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 14h34m3.315659317s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:   
    10 peer conns:
    - 0.0.0.0:42069-159.69.71.122:7104
      peer id: "-GT0003-\x8b\x99\x16\u049d\x02\xb8\xf9<\u0605\x1b"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 8 unsent events
      bep40-prio: da99a6ab
      last msg: 12.73s ago, connected: 58.76s ago, last helpful: never, itime: 58.731351603s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-69.175.102.62:31414
      peer id: "-GT0003-\xf8\xb1>8'\x16\xb1\xc4s/\xf0*"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 2 unsent events
      bep40-prio: cca3b3bb
      last msg: 24.04s ago, connected: 194.68s ago, last helpful: never, itime: 3m14.675793s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eTrU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-103.50.32.171:1596
      peer id: "-GT0003-$\np\xa6\xdfT\x1b[\xbd\x97\xccQ"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: c898f272
      last msg: 4.62s ago, connected: 4.63s ago, last helpful: never, itime: 4.618719583s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-15.204.100.47:42069
      peer id: "-GT0003-$\xdeVV\xb3\xad^\x1d@(\xd6\xf8"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 6 unsent events
      bep40-prio: c8463c06
      last msg: 40.83s ago, connected: 40.83s ago, last helpful: never, itime: 40.833596601s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eTrU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:46284-135.148.35.229:3091
      peer id: "-GT0003-\xde\x15\xe2\x0eM\n\x83e\xa6\x82\xdda"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 2 unsent events
      bep40-prio: c82a18b5
      last msg: 26.57s ago, connected: 26.66s ago, last helpful: never, itime: 26.658743124s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eX-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-75.98.207.227:40061
      peer id: "-GT0003-_o\xee\xcb\xdap\xbe\xf4\xb2Q\xe7O"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 2 unsent events
      bep40-prio: c6586bac
      last msg: 32.64s ago, connected: 66.65s ago, last helpful: never, itime: 1m6.481167873s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-222.216.128.160:36837
      peer id: "-GT0003-r\xd9&H\x9a\xea\xd2\xe9\b\xad\xf3\x00"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]   
      pex: 1 conns, 2 unsent events
      bep40-prio: a72bb4e0
      last msg: 0.21s ago, connected: 52494.03s ago, last helpful: 52493.44s ago, itime: 14h34m3.315910641s, etime: 14h18m15.164777618s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 1+0/(2/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces: 0(1)
    - 10.132.0.29:42069-147.28.163.2:41070
      peer id: "-GT0003-\x19W\f\n\xdd\u046e\xe9\xf9\fXu"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 2 conns, 4 unsent events
      bep40-prio: 9d90d85d
      last msg: 2.75s ago, connected: 30.71s ago, last helpful: never, itime: 30.625375059s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-148.251.45.86:52830
      peer id: "-GT0003-&J\xb3*\xfc\x04r9\xc7\xed\xbdK"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 0 unsent events
      bep40-prio: 85532460
      last msg: 12.82s ago, connected: 63.28s ago, last helpful: never, itime: 1m3.270432009s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-50.115.113.26:31414
      peer id: "-GT0003-\xfb\xa4\f\x86\xcd\vq\x89\xc6\xd162"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 2 unsent events
      bep40-prio: 7f5c7eda
      last msg: 13.66s ago, connected: 73.98s ago, last helpful: never, itime: 1m13.657792652s, etime: 0s
      1/1 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces: 
[DBUG] [04-18|07:15:26.452] [snapshots] torrent status: v1-039500-040000-borevents.seg
    6.088659% of 2233119 bytes (2.2 MB)
    Infohash: 516a5536c4910a4877b1d2fa816e71804c401b6d
    Metadata length: 133
    Piece length: 2097152 (0.25 chunks)
    Num Pieces: 2 (1 completed)
    Piece States: 1. 1C
    Piece availability frequency: 13: 2
    Reader Pieces:
    Enabled trackers:
        URL                                                Extra
        "udp4://open.stealth.si:80/announce"               next ann: 22m47s, last ann: 0 peers
        "udp4://opentracker.i2p.rocks:6969/announce"       next ann: 4s, last ann: error getting ip: lookup opentracker.i2p.rocks: no such host
        "udp4://tracker.openbittorrent.com:6969/announce"  next ann: anytime, last ann: announcing: context deadline exceeded
        "udp4://tracker.opentrackr.org:1337/announce"      next ann: 27m12s, last ann: 0 peers
        "udp4://tracker.torrent.eu.org:451/announce"       next ann: 23m4s, last ann: 0 peers
    DHT Announces: 0
    (torrent.TorrentStats) {
     ConnStats: (torrent.ConnStats) {
      BytesWritten: (torrent.Count) 23524076,
      BytesWrittenData: (torrent.Count) 0,
      BytesRead: (torrent.Count) 24663725,
      BytesReadData: (torrent.Count) 1718621,
      BytesReadUsefulData: (torrent.Count) 135967,
      BytesReadUsefulIntendedData: (torrent.Count) 135967,
      ChunksWritten: (torrent.Count) 0,
      ChunksRead: (torrent.Count) 4,
      ChunksReadUseful: (torrent.Count) 1,
      ChunksReadWasted: (torrent.Count) 2,
      MetadataChunksRead: (torrent.Count) 0,
      PiecesDirtiedGood: (torrent.Count) 1,
      PiecesDirtiedBad: (torrent.Count) 0
     },
     TotalPeers: (int) 132,
     PendingPeers: (int) 122,
     ActivePeers: (int) 10,
     ConnectedSeeders: (int) 10,
     HalfOpenPeers: (int) 0,
     PiecesComplete: (int) 1
    }
    webseeds:
    - https://erigon2-v3-snapshots-bor-mainnet.erigon.network/v1-039500-040000-borevents.seg
      last unhandled error: 45506.84s ago
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h38m27.254834671s, etime: 616.084214ms
      2/2 completed, 0 pieces touched, good chunks: 0/1:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v1-039500-040000-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h38m27.254778086s, etime: 11.326291ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+1/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v2/v1-039500-040000-borevents.seg
      last unhandled error: 45506.84s ago
      bep40-prio: 48674bc7    last msg: never, connected: never, last helpful: never, itime: 12h38m27.255047285s, etime: 627.261874ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    10 peer conns:
    - 10.132.0.29:42069-63.251.87.39:59384
      peer id: "-GT0003-g\xbf\xad\x88\u01fdk\xf6\u049a?i"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 11 conns, 0 unsent events
      bep40-prio: f72c7d5e
      last msg: 23.54s ago, connected: 263.66s ago, last helpful: never, itime: 4m23.572359239s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-144.76.208.96:42069
      peer id: "-GT0003-B\xd5AA\x0eHA\xc7A\xe8\x13\xea"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 0 unsent events
      bep40-prio: da7e1e79
      last msg: 25.88s ago, connected: 121.20s ago, last helpful: never, itime: 2m1.089029568s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-103.50.32.171:55130
      peer id: "-GT0003-$\np\xa6\xdfT\x1b[\xbd\x97\xccQ"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: c898f272
      last msg: 26.37s ago, connected: 446.38s ago, last helpful: never, itime: 7m26.369490826s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-8.218.121.116:42069
      peer id: "-GT0003-y\x9e\xc9\u04a4D\xc3hU\xacn4"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 2 conns, 0 unsent events
      bep40-prio: c6095764
      last msg: 16.68s ago, connected: 378.25s ago, last helpful: never, itime: 6m17.848872987s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:40832-43.134.130.32:31414
      peer id: "-GT0003-0D\x92\u0383\xf1X5\xe6\xb8\x0e\x85"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 0 unsent events
      bep40-prio: 982c2944
      last msg: 21.67s ago, connected: 664.43s ago, last helpful: never, itime: 11m4.43227585s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eX-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-15.204.162.41:42069
      peer id: "-GT0003-]\x9a9\x94\x9b\x0f2\xfc\xb9\xd6\xcc\t"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 0 unsent events
      bep40-prio: 94f2ee2a
      last msg: 4.56s ago, connected: 68.32s ago, last helpful: never, itime: 1m8.126857867s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:   last msg: never, connected: never, last helpful: never, itime: 12h38m27.255047285s, etime: 627.261874ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-69.162.99.146:1988
      peer id: "-GT0003-,f\xd8Y\x944Mn\xf2\xf7\xd2\xe2"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 6 conns, 0 unsent events
      bep40-prio: 55dfd5ae
      last msg: 42.42s ago, connected: 234.08s ago, last helpful: never, itime: 3m53.970798646s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-3.219.100.27:3323
      peer id: "-GT0003-\x8d%\x9a<\xac\t.\x1a\xc1?\xefD"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 2 conns, 0 unsent events
      bep40-prio: 45b92ffd
      last msg: 17.06s ago, connected: 606.67s ago, last helpful: never, itime: 10m6.506554848s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-88.217.142.187:21873
      peer id: "-GT0003-\x9fo\x1bQF\x90L\xbb9\xda}\xb0"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 3830d863
      last msg: 0.12s ago, connected: 45687.04s ago, last helpful: 45506.63s ago, itime: 12h38m27.254989399s, etime: 12h36m10.671004831s
      2/2 completed, 0 pieces touched, good chunks: 1/1:0 reqq: 1+0/(2/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces: 0(1)
    - 10.132.0.29:42069-64.31.20.82:5580
      peer id: "-GT0003-\x13\xce\x1fjS\x16i\u00a1\x1c\xeds"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 3636640b
      last msg: 53.23s ago, connected: 571.39s ago, last helpful: never, itime: 9m31.305380932s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces: 
DBUG] [04-18|07:15:26.452] [snapshots] torrent status: v1-038500-039000-borevents.seg
    6.381991% of 2240116 bytes (2.2 MB)
    Infohash: 17bbf04184963eb434073d5dde858fc29d3f4d3f
    Metadata length: 133
    Piece length: 2097152 (0.25 chunks)
    Num Pieces: 2 (1 completed)
    Piece States: 1. 1C
    Piece availability frequency: 13: 2
    Reader Pieces:
    Enabled trackers:
        URL                                                Extra
        "udp4://open.stealth.si:80/announce"               next ann: 2m44s, last ann: 0 peers
        "udp4://opentracker.i2p.rocks:6969/announce"       next ann: 4s, last ann: error getting ip: lookup opentracker.i2p.rocks: no such host
        "udp4://tracker.openbittorrent.com:6969/announce"  next ann: anytime, last ann: announcing: context deadline exceeded
        "udp4://tracker.opentrackr.org:1337/announce"      next ann: 12m57s, last ann: 0 peers
        "udp4://tracker.torrent.eu.org:451/announce"       next ann: 16m8s, last ann: 0 peers
    DHT Announces: 0
    (torrent.TorrentStats) {
     ConnStats: (torrent.ConnStats) {
      BytesWritten: (torrent.Count) 35873214,
      BytesWrittenData: (torrent.Count) 0,
      BytesRead: (torrent.Count) 35421029,
      BytesReadData: (torrent.Count) 142964,
      BytesReadUsefulData: (torrent.Count) 142964,
      BytesReadUsefulIntendedData: (torrent.Count) 142964,
      ChunksWritten: (torrent.Count) 0,
      ChunksRead: (torrent.Count) 1,
      ChunksReadUseful: (torrent.Count) 1,
      ChunksReadWasted: (torrent.Count) 0,
      MetadataChunksRead: (torrent.Count) 0,
      PiecesDirtiedGood: (torrent.Count) 1,
      PiecesDirtiedBad: (torrent.Count) 0
     },
     TotalPeers: (int) 155,
     PendingPeers: (int) 150,
     ActivePeers: (int) 10,
     ConnectedSeeders: (int) 10,
     HalfOpenPeers: (int) 0,
     PiecesComplete: (int) 1
    }
    webseeds:
    - https://erigon2-v3-snapshots-bor-mainnet.erigon.network/v1-038500-039000-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h40m17.338366522s, etime: 252.968799ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v1-038500-039000-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h40m17.338360052s, etime: 11.883916ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+1/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v2/v1-038500-039000-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7    
      last msg: never, connected: never, last helpful: never, itime: 12h40m17.338441722s, etime: 264.314878ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    10 peer conns:
    - 10.132.0.29:37654-147.28.211.67:42069
      peer id: "-GT0003-\xe1q\xc0\xb2\xd8s\u9156uB\x17"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: ee527167
      last msg: 17.04s ago, connected: 390.53s ago, last helpful: never, itime: 6m30.531446274s, etime: 126.127µs
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eX-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:39006-144.76.75.88:31294
      peer id: "-GT0003-LH\xc0EX\x0e\xf8\x8fY=v="
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: e647b0e0
      last msg: 51.53s ago, connected: 351.55s ago, last helpful: never, itime: 5m51.548458911s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eX-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-67.209.55.20:42069
      peer id: "-GT0003-\xa1y@\"\x0f\xde\xdekv\x86^\xa2"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 64f5c0ae
      last msg: 19.54s ago, connected: 653.98s ago, last helpful: never, itime: 10m53.494213537s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-63.251.15.90:31414
      peer id: "-GT0003-\xe3u\xc7]:\x80\x18C\xe3.\xc87"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 532a8414
      last msg: 16.20s ago, connected: 616.50s ago, last helpful: never, itime: 10m16.205819427s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-67.209.55.19:42069
      peer id: "-GT0003-I=\x80^\xdak\x1c\xc0\xb5\xf6\x06\x99"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 5104d4b2
      last msg: 35.46s ago, connected: 35.94s ago, last helpful: never, itime: 35.458721384s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-67.209.55.17:42069
      peer id: "-GT0003-\xe5\xb0\xe3['\x98\x88?\xb3\f\xcfm"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 5104d4b2    
      last msg: 16.26s ago, connected: 474.02s ago, last helpful: never, itime: 7m53.739857667s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-34.86.236.186:2562
      peer id: "-GT0003-\x88\xaf\v\xd9m\xe8\ni\xfceW]"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 2e0e0abd
      last msg: 26.24s ago, connected: 667.87s ago, last helpful: never, itime: 11m7.783979724s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-62.12.153.168:63611
      peer id: "-GT0003-\x1dBE\x05k{\x1c\xabr\x9b\xf71"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 0751714f
      last msg: 53.08s ago, connected: 293.10s ago, last helpful: never, itime: 4m53.083624679s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-167.235.182.18:39700
      peer id: "-GT0003-|\u058d\xa9\x13M\xaa\x90\xf2\x0e\xba,"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 03149630
      last msg: 0.03s ago, connected: 45838.21s ago, last helpful: 45616.79s ago, itime: 12h40m17.33886423s, etime: 12h35m41.414853069s
      2/2 completed, 0 pieces touched, good chunks: 1/1:0 reqq: 1+0/(2/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces: 0(1) 
[DBUG] [04-18|07:15:26.452] [snapshots] torrent status: v1-034000-034500-borevents.seg
    2.403710% of 2148803 bytes (2.1 MB)
    Infohash: 9c1aaf8c96828613f00c3d063dabd566b8d2ea1a
    Metadata length: 133
    Piece length: 2097152 (0.25 chunks)
    Num Pieces: 2 (1 completed)
    Piece States: 1. 1C
    Piece availability frequency: 13: 2
    Reader Pieces:
    Enabled trackers:
        URL                                                Extra
        "udp4://open.stealth.si:80/announce"               next ann: 15m2s, last ann: 0 peers
        "udp4://opentracker.i2p.rocks:6969/announce"       next ann: 4s, last ann: error getting ip: lookup opentracker.i2p.rocks: no such host
        "udp4://tracker.openbittorrent.com:6969/announce"  next ann: anytime, last ann: announcing: context deadline exceeded
        "udp4://tracker.opentrackr.org:1337/announce"      next ann: 20m29s, last ann: 0 peers
        "udp4://tracker.torrent.eu.org:451/announce"       next ann: 3m45s, last ann: 0 peers
    DHT Announces: 0
    (torrent.TorrentStats) {
     ConnStats: (torrent.ConnStats) {
      BytesWritten: (torrent.Count) 8034211,
      BytesWrittenData: (torrent.Count) 0,
      BytesRead: (torrent.Count) 7600622,
      BytesReadData: (torrent.Count) 154953,
      BytesReadUsefulData: (torrent.Count) 51651,
      BytesReadUsefulIntendedData: (torrent.Count) 51651,
      ChunksWritten: (torrent.Count) 0,
      ChunksRead: (torrent.Count) 3,
      ChunksReadUseful: (torrent.Count) 1,
      ChunksReadWasted: (torrent.Count) 2,
      MetadataChunksRead: (torrent.Count) 0,
      PiecesDirtiedGood: (torrent.Count) 1,
      PiecesDirtiedBad: (torrent.Count) 0
     },
     TotalPeers: (int) 190,
     PendingPeers: (int) 180,
     ActivePeers: (int) 10,
     ConnectedSeeders: (int) 10,
     HalfOpenPeers: (int) 0,
     PiecesComplete: (int) 1
    }
    webseeds:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v1-034000-034500-borevents.seg
      last unhandled error: 46548.76s ago
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h55m48.791306925s, etime: 488.574164ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v2/v1-034000-034500-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h55m48.791243222s, etime: 492.315622ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon2-v3-snapshots-bor-mainnet.erigon.network/v1-034000-034500-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h55m48.791220534s, etime: 1.020313625s
      2/2 completed, 0 pieces touched, good chunks: 0/1:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:  10 peer conns:
    - 10.132.0.29:42069-162.55.102.170:35214
      peer id: "-GT0003-\x05\xfa\x97\bb`\x9c~\xa2\xbfH\x15"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: ef90ed5e
      last msg: 53.63s ago, connected: 113.65s ago, last helpful: never, itime: 1m53.633351565s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-182.140.240.50:30724
      peer id: "-GT0003-#\x10\xd4\r<\x87\x8a\xe6\xb4\xff\xa4Q"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: d47935c9
      last msg: 14.39s ago, connected: 401.57s ago, last helpful: never, itime: 6m41.290765218s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-15.204.100.47:40368
      peer id: "-GT0003-$\xdeVV\xb3\xad^\x1d@(\xd6\xf8"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: c8463c06
      last msg: 34.38s ago, connected: 234.44s ago, last helpful: never, itime: 3m54.2921874s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-64.31.20.158:42069
      peer id: "-GT0003-\xb6/\xeb\xcd\xdd1f\x89;\xdc\xc9i"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: b0d7eea8
      last msg: 0.22s ago, connected: 46852.22s ago, last helpful: 46547.75s ago, itime: 12h55m48.791230859s, etime: 12h54m54.600317076s
      2/2 completed, 0 pieces touched, good chunks: 1/1:0 reqq: 1+0/(2/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces: 0(1)
    - 10.132.0.29:42069-67.209.55.16:37838
      peer id: "-GT0003-\x95k\xe5\u06f1\xaa-\x1a\x1f\xb8\x0f|"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: a36f57b1
      last msg: 7.74s ago, connected: 166.52s ago, last helpful: never, itime: 2m46.279719868s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-51.178.60.70:34640
      peer id: "-GT0003-\x94':9\x17\xab\xb6&\x81\x7fo\x14"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 2 conns, 0 unsent events
      bep40-prio: 7f9ac3e5
      last msg: 16.03s ago, connected: 170.87s ago, last helpful: never, itime: 2m50.849931247s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-91.194.30.111:51036
      peer id: "-GT0003-\b5\x19\x1d\xc1\x19\x883y\xb9\xf9\xdc"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2] pex: 2 conns, 0 unsent events
      bep40-prio: 51b56e2b
      last msg: 27.87s ago, connected: 602.35s ago, last helpful: never, itime: 10m2.314024005s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-148.113.163.116:56998
      peer id: "-GT0003-KO\u0414\\b\x1c\x89M\x1b\x1b\xce"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 37c05e37
      last msg: 42.58s ago, connected: 102.67s ago, last helpful: never, itime: 1m42.582899265s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-31.172.68.134:42069
      peer id: "-GT0003-\x82.&\x9b~vV-\x95\xb2\x88\xac"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 33cdded9
      last msg: 13.97s ago, connected: 314.03s ago, last helpful: never, itime: 5m13.994552887s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-35.76.51.87:62326
      peer id: "-GT0003-+\x8d\x8d4\x97\xae\xa6a\xc0gM\x82"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 1da776c9
      last msg: 10.61s ago, connected: 239.93s ago, last helpful: never, itime: 3m59.46015066s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces: 
[DBUG] [04-18|07:15:26.452] [snapshots] torrent status: v1-038000-038500-borevents.seg
    5.745046% of 2224978 bytes (2.2 MB)
    Infohash: 2968e5fc01ff1c63897e41de77f83fc323079956
    Metadata length: 133
    Piece length: 2097152 (0.25 chunks)
    Num Pieces: 2 (1 completed)
    Piece States: 1. 1C
    Piece availability frequency: 13: 2
    Reader Pieces:
    Enabled trackers:
        URL                                                Extra
        "udp4://open.stealth.si:80/announce"               next ann: 11m22s, last ann: 0 peers
        "udp4://opentracker.i2p.rocks:6969/announce"       next ann: 4s, last ann: error getting ip: lookup opentracker.i2p.rocks: no such host
        "udp4://tracker.openbittorrent.com:6969/announce"  next ann: anytime, last ann: announcing: context deadline exceeded
        "udp4://tracker.opentrackr.org:1337/announce"      next ann: 11m48s, last ann: 0 peers
        "udp4://tracker.torrent.eu.org:451/announce"       next ann: 17m33s, last ann: 0 peers
    DHT Announces: 0
    (torrent.TorrentStats) {
     ConnStats: (torrent.ConnStats) {
      BytesWritten: (torrent.Count) 8023521,
      BytesWrittenData: (torrent.Count) 0,
      BytesRead: (torrent.Count) 7564179,
      BytesReadData: (torrent.Count) 127826,
      BytesReadUsefulData: (torrent.Count) 127826,
      BytesReadUsefulIntendedData: (torrent.Count) 127826,
      ChunksWritten: (torrent.Count) 0,
      ChunksRead: (torrent.Count) 1,
      ChunksReadUseful: (torrent.Count) 1,
      ChunksReadWasted: (torrent.Count) 0,
      MetadataChunksRead: (torrent.Count) 1,
      PiecesDirtiedGood: (torrent.Count) 1,
      PiecesDirtiedBad: (torrent.Count) 0
     },
     TotalPeers: (int) 191,
     PendingPeers: (int) 184,
     ActivePeers: (int) 10,
     ConnectedSeeders: (int) 10,
     HalfOpenPeers: (int) 0,
     PiecesComplete: (int) 1
    }
    webseeds:
    - https://erigon2-v3-snapshots-bor-mainnet.erigon.network/v1-038000-038500-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h44m17.664937085s, etime: 20.886787ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+1/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v1-038000-038500-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h44m17.664891964s, etime: 447.341554ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+1/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces:
    - https://erigon3-v3-snapshots-bor-mainnet.erigon.network/v2/v1-038000-038500-borevents.seg
      last unhandled error: never
      bep40-prio: 48674bc7
      last msg: never, connected: never, last helpful: never, itime: 12h44m17.664657594s, etime: 566.229571ms
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/128):0/1024, flags: i-WS-, dr: 0.0 KiB/s
      requested pieces: 
10 peer conns:
    - 0.0.0.0:42069-65.21.71.147:42069
      peer id: "-GT0003-\x1f\x81\x17\u0161\x14\x03\x7fH\xb3\x1f\xa4"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: fc2d9336
      last msg: 46.30s ago, connected: 704.00s ago, last helpful: never, itime: 11m43.934994594s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:44486-162.55.5.182:21294
      peer id: "-GT0003-!\x93\x03I\x15\xe3\xeb\xf1pj\xb1p"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 0 conns, 0 unsent events
      bep40-prio: d4e1e35d
      last msg: 20.04s ago, connected: 269.18s ago, last helpful: never, itime: 4m29.178010408s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eX-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-62.90.115.170:49788
      peer id: "-GT0003-\u05d9\bW\xd0Wwmq\u06c2p"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 9e30bc0f
      last msg: 51.70s ago, connected: 321.15s ago, last helpful: never, itime: 5m21.086643751s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-23.88.5.62:35932
      peer id: "-GT0003-\xaf\x00\x96[\x04\xfa\xd4\xe12\x16c}"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 94d93e66
      last msg: 5.21s ago, connected: 648.08s ago, last helpful: never, itime: 10m48.063972447s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-64.31.20.154:42069
      peer id: "-GT0003-'\xe7* \xa6z\xf6\x82\"\xe8\xe5\x84"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 774d79b7
      last msg: 0.12s ago, connected: 46197.75s ago, last helpful: 45856.57s ago, itime: 12h44m17.665156605s, etime: 12h43m25.008139807s
      2/2 completed, 0 pieces touched, good chunks: 1/1:0 reqq: 1+0/(2/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces: 0(1)
    - 0.0.0.0:42069-67.209.55.19:42069
      peer id: "-GT0003-I=\x80^\xdak\x1c\xc0\xb5\xf6\x06\x99"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 5104d4b2
      last msg: 4.58s ago, connected: 485.07s ago, last helpful: never, itime: 8m4.586981569s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-88.217.142.187:41703
      peer id: "-GT0003-\x9fo\x1bQF\x90L\xbb9\xda}\xb0"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]     
      pex: 1 conns, 0 unsent events
      bep40-prio: 3830d863
      last msg: 3.44s ago, connected: 131.46s ago, last helpful: never, itime: 2m11.443146675s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 10.132.0.29:42069-74.63.213.58:6424
      peer id: "-GT0003-Dw\x8ccm\xe4x\x8d\"\x92&\xa6"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 339f9cb7
      last msg: 35.53s ago, connected: 640.90s ago, last helpful: never, itime: 10m40.784450411s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eI-, dr: 0.0 KiB/s
      requested pieces:
    - 0.0.0.0:42069-15.235.196.72:31294
      peer id: "-GT0003-J\x8dsm\x17\x145\xfc\xb9\xa6\xb3#"
      extensions: 0000000000100005 (ltep, fast, dht)
      ltep extensions: map[ut_holepunch:3 ut_metadata:1 ut_pex:2]
      pex: 1 conns, 0 unsent events
      bep40-prio: 07fdb480
      last msg: 10.95s ago, connected: 246.48s ago, last helpful: never, itime: 4m6.157302851s, etime: 0s
      2/2 completed, 0 pieces touched, good chunks: 0/0:0 reqq: 0+0/(1/1024):0/1024, flags: i-eIU-, dr: 0.0 KiB/s
      requested pieces:       

[anacrolix]

Sorry for the delay on this, I'll get to it soon.

[anacrolix]

This fixes an issue with small files (1 to 2 pieces) when they are seeded from web peers into a sparse torrent network.

If there are a significant number of peers in the network which don't have the requested torrent on initial download a webpeer with the file is not guaranteed to be the selected request provider. When this happens if the webpeer does not do an update to its request state it will wait forever and the torrent will never get downloaded.

I think I follow. I don't quite understand the implementation of your fix though. I don't think the requester (pretty sure it should be an e not an o) needs to be checking a bunch of stuff about whether it should fire a request update. The timer code for peerconns should be just using a timer as a fallback, I think it's fine to do something similar if you think it would work.

This fix also includes an update to steal processing in applyRequestState - so that rejecting and cancelled peers do not steal from a potentially good peer. Also the steal logic uses after instead of before in its time logic, to avoid a peer with equal time (which is zero at initial download) preemptively stealing as this creates a chain reaction on initial download.

I've cherry picked this to master, this looks good.

[mh0lt]

This fixes an issue with small files (1 to 2 pieces) when they are seeded from web peers into a sparse torrent network. If there are a significant number of peers in the network which don't have the requested torrent on initial download a webpeer with the file is not guaranteed to be the selected request provider. When this happens if the webpeer does not do an update to its request state it will wait forever and the torrent will never get downloaded.

I think I follow. I don't quite understand the implementation of your fix though. I don't think the requester (pretty sure it should be an e not an o) needs to be checking a bunch of stuff about whether it should fire a request update. The timer code for peerconns should be just using a timer as a fallback, I think it's fine to do something similar if you think it would work.

This fix also includes an update to steal processing in applyRequestState - so that rejecting and cancelled peers do not steal from a potentially good peer. Also the steal logic uses after instead of before in its time logic, to avoid a peer with equal time (which is zero at initial download) preemptively stealing as this creates a chain reaction on initial download.

I've cherry picked this to master, this looks good.

The issue is as follows:

When you start a set of requester's (o is the english spelling) (I'll fix) for the a webpeer once they have started and exhausted any initial requests they have they will just sit waiting for a signal before doing anything else.

If the condition is only signaled by a request being processed (in _request) if the webseed is starved of requests (because some get stolen, or fail) - the requester will sit on the condition forever and never process any more requests.

This is the condition we're hitting - in the examaple we have 1 good webseed and 14 bad peers, so the chances of the webseed not getting bumped are pretty high with small torrents.

What I have done here is introduced a timer to kick one of the responers into life to see if there is any more work to be done. I think it needs a timer as the as the connection is otherwise passive - there is no networking event to catch.

A more natural implementation of this I think would be to have channels and a select loop with a timeout. But I went for the minimal change which I think achieves the same effect.

[anacrolix]

Okay that makes sense. I commented on the code a bit. Is it possible just to add more condition signalling somewhere to bring them back to life?

[anacrolix]

I'll close this as there's no activity. However I really appreciate the effort and am receptive to restarting it to get the parts that weren't already accepted.