DHT announcements are not happening when using a large blockstore #9722

acejam · 2023-03-14T21:31:32Z

Checklist

This is a bug report, not a question. Ask questions on discuss.ipfs.io.
I have searched on the issue tracker for my bug.
I am running the latest kubo version or have an issue updating.

Installation method

ipfs-update or dist.ipfs.tech

Version

Kubo version: 0.18.1
Repo version: 13
System version: amd64/linux
Golang version: go1.19.1

Config

{
  "API": {
    "HTTPHeaders": {}
  },
  "Addresses": {
    "API": "/ip4/0.0.0.0/tcp/5001",
    "Announce": [
      "/ip4/my.public.ip.address/tcp/4001",
      "/ip4/my.public.ip.address/udp/4001/quic"
    ],
    "AppendAnnounce": [],
    "Gateway": "/ip4/0.0.0.0/tcp/8080",
    "NoAnnounce": [
      "/ip4/10.0.0.0/ipcidr/8",
      "/ip4/100.64.0.0/ipcidr/10",
      "/ip4/169.254.0.0/ipcidr/16",
      "/ip4/172.16.0.0/ipcidr/12",
      "/ip4/192.0.0.0/ipcidr/24",
      "/ip4/192.0.2.0/ipcidr/24",
      "/ip4/192.168.0.0/ipcidr/16",
      "/ip4/198.18.0.0/ipcidr/15",
      "/ip4/198.51.100.0/ipcidr/24",
      "/ip4/203.0.113.0/ipcidr/24",
      "/ip4/240.0.0.0/ipcidr/4",
      "/ip6/100::/ipcidr/64",
      "/ip6/2001:2::/ipcidr/48",
      "/ip6/2001:db8::/ipcidr/32",
      "/ip6/fc00::/ipcidr/7",
      "/ip6/fe80::/ipcidr/10"
    ],
    "Swarm": [
      "/ip4/0.0.0.0/tcp/4001",
      "/ip4/0.0.0.0/udp/4001/quic",
      "/ip4/0.0.0.0/udp/4001/quic-v1",
      "/ip4/0.0.0.0/udp/4001/quic-v1/webtransport"
    ]
  },
  "AutoNAT": {
    "ServiceMode": "disabled"
  },
  "Bootstrap": [
    "/dnsaddr/bootstrap.libp2p.io/p2p/QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN",
    "/dnsaddr/bootstrap.libp2p.io/p2p/QmQCU2EcMqAqQPR2i9bChDtGNJchTbq5TbXJJ16u19uLTa",
    "/dnsaddr/bootstrap.libp2p.io/p2p/QmbLHAnMoJPWSCR5Zhtx6BHJX9KiKNN6tpvbUcqanj75Nb",
    "/dnsaddr/bootstrap.libp2p.io/p2p/QmcZf59bWwK5XFi76CZX8cbJ4BhTzzA3gU1ZjYZcYW3dwt",
    "/ip4/104.131.131.82/tcp/4001/p2p/QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ",
    "/ip4/104.131.131.82/udp/4001/quic/p2p/QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ"
  ],
  "DNS": {
    "Resolvers": {}
  },
  "Datastore": {
    "BloomFilterSize": 268435456,
    "GCPeriod": "1h",
    "HashOnRead": false,
    "Spec": {
      "mounts": [
        {
          "child": {
            "path": "blocks",
            "shardFunc": "/repo/flatfs/shard/v1/next-to-last/3",
            "sync": false,
            "type": "flatfs"
          },
          "mountpoint": "/blocks",
          "prefix": "flatfs.datastore",
          "type": "measure"
        },
        {
          "child": {
            "compression": "none",
            "path": "datastore",
            "type": "levelds"
          },
          "mountpoint": "/",
          "prefix": "leveldb.datastore",
          "type": "measure"
        }
      ],
      "type": "mount"
    },
    "StorageGCWatermark": 90,
    "StorageMax": "45TB"
  },
  "Discovery": {
    "MDNS": {
      "Enabled": false
    }
  },
  "Experimental": {
    "AcceleratedDHTClient": true,
    "FilestoreEnabled": false,
    "GraphsyncEnabled": false,
    "Libp2pStreamMounting": false,
    "P2pHttpProxy": false,
    "StrategicProviding": false,
    "UrlstoreEnabled": false
  },
  "Gateway": {
    "APICommands": [],
    "HTTPHeaders": {
      "Access-Control-Allow-Headers": [
        "X-Requested-With",
        "Range",
        "User-Agent"
      ],
      "Access-Control-Allow-Methods": [
        "GET"
      ],
      "Access-Control-Allow-Origin": [
        "*"
      ]
    },
    "NoDNSLink": false,
    "NoFetch": true,
    "PathPrefixes": [],
    "PublicGateways": null,
    "RootRedirect": "",
    "Writable": false
  },
  "Identity": {
    "PeerID": "12D3KooWNorHNz1DghmWGhCPRUVvs45vsdHi5CFnwVjaWo8wKevw"
  },
  "Internal": {
    "Bitswap": {
      "EngineBlockstoreWorkerCount": 2500,
      "EngineTaskWorkerCount": 500,
      "MaxOutstandingBytesPerPeer": 1048576,
      "TaskWorkerCount": 500
    }
  },
  "Ipns": {
    "RecordLifetime": "",
    "RepublishPeriod": "",
    "ResolveCacheSize": 128
  },
  "Migration": {
    "DownloadSources": [],
    "Keep": ""
  },
  "Mounts": {
    "FuseAllowOther": false,
    "IPFS": "/ipfs",
    "IPNS": "/ipns"
  },
  "Peering": {
    "Peers": [
      "list_of_peers_using_internal_dns"
    ]
  },
  "Pinning": {
    "RemoteServices": {}
  },
  "Plugins": {
    "Plugins": null
  },
  "Provider": {
    "Strategy": ""
  },
  "Pubsub": {
    "DisableSigning": false,
    "Router": ""
  },
  "Reprovider": {
    "Interval": "12h",
    "Strategy": "all"
  },
  "Routing": {
    "Routers": null,
    "Methods": null
  },
  "Swarm": {
    "AddrFilters": [
      "/ip4/10.0.0.0/ipcidr/8",
      "/ip4/100.64.0.0/ipcidr/10",
      "/ip4/169.254.0.0/ipcidr/16",
      "/ip4/172.16.0.0/ipcidr/12",
      "/ip4/192.0.0.0/ipcidr/24",
      "/ip4/192.0.2.0/ipcidr/24",
      "/ip4/192.168.0.0/ipcidr/16",
      "/ip4/198.18.0.0/ipcidr/15",
      "/ip4/198.51.100.0/ipcidr/24",
      "/ip4/203.0.113.0/ipcidr/24",
      "/ip4/240.0.0.0/ipcidr/4",
      "/ip6/100::/ipcidr/64",
      "/ip6/2001:2::/ipcidr/48",
      "/ip6/2001:db8::/ipcidr/32",
      "/ip6/fc00::/ipcidr/7",
      "/ip6/fe80::/ipcidr/10"
    ],
    "ConnMgr": {
      "GracePeriod": "20s",
      "HighWater": 2000,
      "LowWater": 1500,
      "Type": "basic"
    },
    "DisableBandwidthMetrics": true,
    "DisableNatPortMap": true,
    "RelayClient": {
      "Enabled": false
    },
    "RelayService": {
      "Enabled": false
    },
    "ResourceMgr": {},
    "Transports": {
      "Multiplexers": {},
      "Network": {},
      "Security": {}
    }
  }
}

Description

I have observed that DHT announcements are not happening when pinning content from a node that has a large blockstore. I'm using the AcceleratedDHTClient on 0.18.1, but previously saw this behavior on 0.17 as well. I'm seeing this across multiple servers, and the pinned content is being stored long term.

ipfs bitswap provide runs for about 5 minutes, and does not return any error codes. However when querying ipfs dht findprovs for any randomly selected CID, no peer ID's are returned. If I manually run ipfs dht provide <cid>, a peer ID is properly returned. However, it is my understanding that this command invokes the non-Accelerated DHT client.

DHT announcement information:

$ ipfs stats provide
TotalProvides:          299M (299,055,054)
AvgProvideDuration:     3µs
LastReprovideDuration:  5m37.700645s
LastReprovideBatchSize: 99M (99,685,018)

Blockstore information:

NumObjects: 99685018
RepoSize:   8.8 TB
StorageMax: 45 TB
RepoPath:   /data
Version:    fs-repo@13

The text was updated successfully, but these errors were encountered:

lidel · 2023-03-20T12:55:47Z

(reposting comment from slack) @acejam noted this is still a problem in 0.19.0-rc1

acejam · 2023-03-21T00:45:29Z

Quick update: We are starting to see more content drop out of the DHT. This appears to be causing some impact to our production services.

yiannisbot · 2023-03-23T06:28:39Z

Not sure if you've discussed this elsewhere, but have you tried (temporarily) disabling the resource manager (or increase the limits there)? Just to make sure it's not because of this.

guillaumemichel · 2023-03-23T12:32:51Z

The context is being cancelled a 5 minutes timeout. The timeout value is defined at

kubo/core/node/libp2p/routing.go

Lines 186 to 193 in 1457b4f

    
           var cRouters []*routinghelpers.ParallelRouter 
        
           for _, v := range routers { 
        
           	cRouters = append(cRouters, &routinghelpers.ParallelRouter{ 
        
           		Timeout:     5 * time.Minute, 
        
           		IgnoreError: true, 
        
           		Router:      v.Routing, 
        
           	}) 
        
           }

or

kubo/core/node/libp2p/routingopt.go

Lines 65 to 70 in 1457b4f

    
           routers = append(routers, &routinghelpers.ParallelRouter{ 
        
           	Router:       dhtRouting, 
        
           	IgnoreError:  false, 
        
           	Timeout:      5 * time.Minute, // https://github.com/ipfs/kubo/pull/9475#discussion_r1042501333 
        
           	ExecuteAfter: 0, 
        
           })

This was probably introduced with #9475

The quick fix is to temporarily increase these Timeout values (e.g to 10 * time.Hour).

acejam · 2023-03-23T16:38:13Z

@guillaumemichel I can confirm that bumping this value to 10 * time.Hour fixed this issue for us. Thank you for the suggestion. I made this change using version 0.19.

Records are now being properly announced, and the stats output now shows:

TotalProvides:          99M (99,685,018)
AvgProvideDuration:     53µs
LastReprovideDuration:  1h28m18.881264s
LastReprovideBatchSize: 99M (99,685,018)

guillaumemichel · 2023-03-23T16:42:59Z

I don't understand why an arbitrary constant timeout is defined for all Content Routers. IMO this timeout should be content router specific, if it is needed at all. We need to make sure that the fullrt provide operation doesn't time out, or has a large enough timeout value.

aschmahmann · 2023-03-23T16:43:12Z

Yeah, I think there are two main issues here:

There's a hard-coded timeout despite their being two different layers of timeouts definable in the config https://github.com/ipfs/kubo/blob/1f5763f7877a59e933fa729afdfbf26d253b0fe0/docs/config.md#routingrouters-parameters
- If this was not true then this would have been resolvable with a config change rather than a code change
The default limit for the *Many operations should not be the same as for the individual ones
- Note: perhaps reasonably the *Many operations are not exposed in the config at all, which is nice for reducing user complexity but means the defaults have to actually be good
- Or at least the out-of-the-box defaults here should be better (e.g. with ProvideMany having a timeout matching the reprovide interval or the default one if reproviding was turned off)

BigLep · 2023-03-24T15:45:48Z

2023-03-24 maintainer conversation
Plan to include this for 0.19.1: #9754

We're not just fixing ProvideMany:

kubo/routing/composer.go

Line 36 in 1457b4f

func (c *Composer) ProvideMany(ctx context.Context, keys []multihash.Multihash) error {
@guseggert suggsted of allowing 0 to mean "no timeout" and then have default of 0 for all operations
@guseggert will take / @lidel review

We think the above will stop the bleeding and be good enough for the foreseeable future.

guseggert · 2023-03-27T16:46:12Z

Made the change to the router composers in libp2p/go-libp2p-routing-helpers#72, after merging next step is to plumb it into Kubo.

guseggert · 2023-03-30T20:09:48Z

I've merged a fix into Kubo here: a09c8df

This is hard to reproduce, so would you be able to test it out and see if the issue is fixed for you?

If we can get this validated, we can include it in v0.19.1 which is being released soon. See #9754

BigLep · 2023-03-31T23:28:29Z

@acejam : are you able to confirm an improvement here? I'd like to include this with 0.19.1 on Monday.

acejam · 2023-04-01T14:18:26Z

@BigLep We're testing the merged fix now.

acejam · 2023-04-01T22:12:18Z

@BigLep @guseggert I can confirm that the merged fix appears to work. We have been running 55587d8 and provides using the AcceleratedDHTClient no longer timeout after 5 minutes:

/ # ipfs stats provide
TotalProvides:          99M (99,707,542)
AvgProvideDuration:     68µs
LastReprovideDuration:  1h53m31.764363s
LastReprovideBatchSize: 99M (99,707,541)

Thank you!

BigLep · 2023-04-06T06:40:17Z

Thanks @acejam .

Closing since this was released in 0.19.1.

acejam added kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization labels Mar 14, 2023

lidel added kind/test Testing work need/analysis Needs further analysis before proceeding P1 High: Likely tackled by core team if no one steps up and removed need/triage Needs initial labeling and prioritization labels Mar 20, 2023

BigLep mentioned this issue Mar 25, 2023

Release 0.19.1 #9754

Closed

guseggert mentioned this issue Mar 27, 2023

feat: zero timeout on composed routers should disable timeout libp2p/go-libp2p-routing-helpers#72

Merged

BigLep assigned guseggert Mar 28, 2023

BigLep closed this as completed Apr 6, 2023

Jorropo mentioned this issue Jun 6, 2023

Unreachable providers for popular CIDs probe-lab/network-measurements#49

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

DHT announcements are not happening when using a large blockstore #9722

DHT announcements are not happening when using a large blockstore #9722

acejam commented Mar 14, 2023 •

edited

Loading

lidel commented Mar 20, 2023

acejam commented Mar 21, 2023 •

edited

Loading

yiannisbot commented Mar 23, 2023 •

edited

Loading

guillaumemichel commented Mar 23, 2023 •

edited

Loading

acejam commented Mar 23, 2023

guillaumemichel commented Mar 23, 2023

aschmahmann commented Mar 23, 2023 •

edited

Loading

BigLep commented Mar 24, 2023 •

edited

Loading

guseggert commented Mar 27, 2023

guseggert commented Mar 30, 2023 •

edited

Loading

BigLep commented Mar 31, 2023

acejam commented Apr 1, 2023 •

edited

Loading

acejam commented Apr 1, 2023 •

edited

Loading

BigLep commented Apr 6, 2023

DHT announcements are not happening when using a large blockstore #9722

DHT announcements are not happening when using a large blockstore #9722

Comments

acejam commented Mar 14, 2023 • edited Loading

Checklist

Installation method

Version

Config

Description

lidel commented Mar 20, 2023

acejam commented Mar 21, 2023 • edited Loading

yiannisbot commented Mar 23, 2023 • edited Loading

guillaumemichel commented Mar 23, 2023 • edited Loading

acejam commented Mar 23, 2023

guillaumemichel commented Mar 23, 2023

aschmahmann commented Mar 23, 2023 • edited Loading

BigLep commented Mar 24, 2023 • edited Loading

guseggert commented Mar 27, 2023

guseggert commented Mar 30, 2023 • edited Loading

BigLep commented Mar 31, 2023

acejam commented Apr 1, 2023 • edited Loading

acejam commented Apr 1, 2023 • edited Loading

BigLep commented Apr 6, 2023

acejam commented Mar 14, 2023 •

edited

Loading

acejam commented Mar 21, 2023 •

edited

Loading

yiannisbot commented Mar 23, 2023 •

edited

Loading

guillaumemichel commented Mar 23, 2023 •

edited

Loading

aschmahmann commented Mar 23, 2023 •

edited

Loading

BigLep commented Mar 24, 2023 •

edited

Loading

guseggert commented Mar 30, 2023 •

edited

Loading

acejam commented Apr 1, 2023 •

edited

Loading

acejam commented Apr 1, 2023 •

edited

Loading