Ipfs-cluster unresponsive

Help
1

Hi,
I have a two node ipfs cluster. The cluster operates normally for about a week and then becomes unresponsive. Once in this state calls to its API time out. Restarting the ipfs-cluster-service (but not the ipfs daemon) fixes the problem until it happens again.

There are a variety of error messages in the log which are included below:

adder adder/util.go:58 BlockPut .. dial tcp 127.0.0.1:5001: socket: too many open files

adder adder/util.go:58 BlockPut .. dial tcp 127.0.0.1:5001: connect: connection refused

adder adder/util.go:58 BlockPut .. read tcp 127.0.0.1:41616->127.0.0.1:5001: read: connection reset by peer

adder adder/util.go:58 BlockPut .. EOF

ipfshttp ipfshttp/ipfshttp.go:749 IPFS request unsuccessful (repo/stat?size-only=true). Code: 500. Message getting disk usage at /: lstat /home/admin/.ipfs/datastore/391162.ldb: no such file or directory

Can anyone help me to diagnose/fix this problem?

Many thanks

2

At first view, you need to increase the number of file descriptors that the process can use (see ulimit, etc/limits.d, systemd service file settings etc).

It also seems that go-ipfs is not running or that it exhausted file descriptors too.

It also seems that there is an issue in the IPFS datastore (based on the last message).

I don’t know what your usage pattern is or if you made changes to the default configuration but usually FD issues come from badger or from handling too many connections while keeping a default limit which is low.

3

Hi,
Thanks for the help. What would you consider to be a normal or reasonable maximum for the file descriptors open by ipfs-cluster? As far as I can tell I have no special limiting on the open files for that process. I restarted it a few hours ago and currently it has 910 files open. That sounds like a lot to me.

Our usage pattern is that it has quite a heavy load of calls to
/api/v0/add?pin=true&hash=sha2-256
nearly all of which are files it already has pinned.

4

10k ? Depends on connections handled by the API and on badger configuration (number of tables/files it keeps open).

Meaning you are using the proxy api right?

5

I’ve increased the FD limit from 1024 to 20000, I’ll post the result after a few days.

Yes we are using the proxy api.

By the way, we are using leveldb rather than badger. AFAIK badger is not involved in the mix.

Thanks again!

6

You can use lsof to see what the file descriptors are used for (i.e. network/file etc).

Also keep an eye on IPFS.

7

OK, so the problem is not resolved. I’m still getting errors due to ‘too many open files’ after a while of the system running. I have captured the output of lsof when the system is in this state. Here is some information that may help determine what the problem is:

The max open files is set to 65535:

> ulimit -n
65535
> ulimit -Hn
65535

The number of lines of output of lsof is 29647. (Therefore I’m not sure how we’ve reached max open files.) Of the lines in lsof, 13425 are TCP connections belonging to ipfs, 1755 are levelDB files belonging to ipfs. 6682 are TCP connections belonging to ipfs-cluster and 6539 are levelDB files belonging to ipfs-cluster. A lot, if not all of the 6682 TCP connections belonging to ipfs-cluster are connected to the ipfs daemon (port 5001). Doe’s this sound right?

Does this give you any ideas as to where I’m going wrong?

Thanks for your help!

8

6500 connections from cluster to the IPFS daemon sounds too much. Have you modified the cluster configuration, and if so, how?

If you run ipfs diags cmds -v, does it show 6500+ commands running?

9

I used the default cluster config. I only modified it to set the secret and modified peerstore to add the other peer.

I’ve restarted both servers so the numbers are different now but currently there are 59 TCP connections from the cluster to ipfs and at the same time there is only one active command, which is the diag command itself.

I will try that again and post the results once the system becomes unresponsive again.

10

I checked against a busy service of mine and I only see 2 connections from cluster to IPFS:5001:

lsof -i -n -P | grep ipfs-clus | grep 5001

So something is not right. Is there a firewall between ipfs and cluster? Anything that would make those connections hang or not close correctly?

11

That command currently returns 70 lines for me.

No, there’s nothing, they are on the same machine.

Its ipfs v0.9.0 and ipfs-cluster-service v0.14.0. I’m reluctant to post the configs publicly in case I fail to redact a secret. If you have a private channel I could send you those in case that would be helpful, although I think they are quite standard - especially the ipfs-cluster config.

12

If you are using the default config then I don’t think there’s anything to see in it.

I can only think of wildshots about why so many connections stay open. How long does it take to do ipfs repo stat --size-only on your ipfs daemon? Hopefully not longer than 1 minute?

13

That command executes in less than a second. This is the output:

RepoSize:   992601875
StorageMax: 10000000000

It is a two node cluster and the other node runs without problems (although the other node doesn’t serve any external proxy API calls). Like your setup, the other node only has two TCP connections between ipfs and ipfs-cluster-service. I performed a diff on the configs of the setups. There are differences in both .ipfs/config and .ipfs-cluster/service.json as detailed below:

In each diff, the first file is the one of the peer that is having problems.

.ipfs/config:

3,98c3
<     "HTTPHeaders": {
<       "Access-Control-Allow-Credentials": [
<         "true"
<       ],
<       "Access-Control-Allow-Methods": [
<         "PUT",
<         "POST",
<         "GET"
<       ],
<       "Access-Control-Allow-Origin": [
<         "*",
[ There is a long list of URLs here that I'm pretty sure serve no purpose and could be removed]
<       ]
<     }
---
>     "HTTPHeaders": null
158a64,67
>   "Experimental": {
>     "FilestoreEnabled": false,
>     "ShardingEnabled": false
>   },
176,177c85,86
<     "PeerID": "[redacted",
<     "PrivKey": "[redacted]"
---
>     "PeerID": "[redacted]",
>     "PrivKey": "[redacted]"
188a98,100
>   "Reprovider": {
>     "Interval": "12h"
>   },
193c105,107
<     "AddrFilters": null
---
>     "AddrFilters": null,
>     "DisableBandwidthMetrics": false,
>     "DisableNatPortMap": false

.ipfs-cluster/service.json

3c3
<     "peername": "eth-server",
---
>     "peername": "ipfs",
24c24
<     "disable_repinning": true,
---
>     "disable_repinning": false,

Does this give any clues?

Thanks as usual!

14

It doesn’t give clues.

What is the cluster peer that has all those connection doing? Is it pinning? Is it adding? Does it have a large queue of pins?

15

How can I see the pin queue size?

The cluster node is serving requests of the form:

/api/v0/add?pin=true&hash=sha2-256

which are POSTed with a body of about 1KB each. I’m not sure how to measure the frequency of these requests but by watching journalctl --follow I’d estimate a few requests per second and likely bursting up to tens per second. The cluster is set up for full replication.

16

ipfs-cluster-ctl status --filter queued

Hm ok. How is your disk doing (iotop) ? Are requests taking very long? Perhaps the FD limit reaches because you are adding and adding and there are too many ongoing add operations. Some tips:

  • Make sure you enable crdt-batching (see config reference).
  • Consider to add with --local=true
  • Distribute requests among more peers.