OOM in a 2G box

[cannium]

Version information:

go-ipfs version: 0.4.18-dev-
Repo version: 7
System version: amd64/linux
Golang version: go1.10.1

Type:

Bug

Description:

I reserved a droplet(VPS in digitalocean) with 1 core, 2G memory in digitalocean, and solely run IPFS. After about 12 hours, OOM occured. The commands I used to build and run IPFS are:

go get -u -d github.com/ipfs/go-ipfs
cd $GOPATH/src/github.com/ipfs/go-ipfs
make install
ipfs init
ipfs daemon &

kernel OOM log:

[52300.460643] Out of memory: Kill process 9053 (ipfs) score 885 or sacrifice child
[52300.465445] Killed process 9053 (ipfs) total-vm:2660108kB, anon-rss:1860420kB, file-rss:0kB, shmem-rss:0kB

monitor graph:

As a second try, I lowered connection numbers to

"LowWater": 60
"HighWater": 90

I'll wait and see if it would OOM again.

I'd like to know the recommended memory configuration for a production system. On the other side, if I need to run IPFS in a 2G box, how to tune its memory usage(by both config and code)?

[cannium]

Out of memory again. Ran about 24 hours.

"LowWater": 60
"HighWater": 90

[schomatis]

Hey @cannium, could you provide a few heap trace dumps (ideally at different uptimes, like every 3/4 hours), you can do this with:

curl localhost:5001/debug/pprof/heap > ipfs.heap

[cannium]

Sure, I'll do.

[cannium]

In case you become impatient, I'll put some updates here.
I started another instance, with LowWater 60, HighWater 90 config, ran for about 2 days, but OOM didn't happen. The only difference is that this instance is in region Toronto.
So I started another instance in US region today. Hopefully OOM would happen in 24 hours...

[schomatis]

No problem, take your time.

[cannium]

It happened again. I started a file server containing all the heap files here: http://159.203.36.22:8000/
Note the last 2 heap files are empty because ipfs was already killed. I leave them there as an indicator.
Also I put in the binary file(file ipfs) in case someone need it.

Monitor graphs for last few hours:

[Stebalien]

What commit did you build?

[cannium]

I believe it's 78a32f2

[schomatis]

It would seem to be related to the number of active connections.

tool pprof top "ipfs.heap-Fri Sep  7 02_15_20 UTC 2018"
[...]
(pprof) top
Showing nodes accounting for 682.71MB, 84.78% of 805.26MB total
Dropped 183 nodes (cum <= 4.03MB)
Showing top 10 nodes out of 88
      flat  flat%   sum%        cum   cum%
  290.93MB 36.13% 36.13%   435.98MB 54.14%  gx/ipfs/QmZt87ZHYGaZFBrtGPEqYjAC2yNAhgiRDBmu8KaCzHjx6h/yamux.newSession
  148.57MB 18.45% 54.58%   148.57MB 18.45%  bufio.NewReaderSize (inline)
   57.51MB  7.14% 61.72%    57.51MB  7.14%  gx/ipfs/QmZt87ZHYGaZFBrtGPEqYjAC2yNAhgiRDBmu8KaCzHjx6h/yamux.newStream
   46.52MB  5.78% 67.50%    48.02MB  5.96%  crypto/cipher.NewCTR
   45.51MB  5.65% 73.15%    45.51MB  5.65%  crypto/aes.newCipher
   24.51MB  3.04% 76.19%    33.01MB  4.10%  gx/ipfs/QmWri2HWdxHjWBUermhWy7QWJqN1cV8Gd1QbDiB5m86f1H/go-libp2p-secio.newSecureSession
      18MB  2.24% 78.43%       18MB  2.24%  gx/ipfs/QmXTpwq2AkzQsPjKqFQDNY2bMdsAT53hUBETeyj8QRHTZU/sha256-simd.New
   17.50MB  2.17% 80.60%    35.50MB  4.41%  crypto/hmac.New
   17.15MB  2.13% 82.73%    23.15MB  2.88%  gx/ipfs/QmVYxfoJQiZijTgPNHCHgHELvQpbsJNTg6Crmc3dQkj3yy/golang-lru/simplelru.(*LRU).Add
   16.50MB  2.05% 84.78%    16.50MB  2.05%  math/big.nat.make

[cannium]

Could you give more instructions about the session - stream structure? I'd like to understand how could a session take 290M memory, cache the whole file object in memory?

[Stebalien]

It's not a single session, that's all your connections. However, that's still an absurd number.

I'm getting:

         .          .     89:	s := &Session{
         .          .     90:		config:     config,
         .          .     91:		logger:     log.New(config.LogOutput, "", log.LstdFlags),
         .          .     92:		conn:       conn,
         .          .     93:		bufRead:    bufio.NewReader(conn),
    1.50MB     1.50MB     94:		pings:      make(map[uint32]chan struct{}),
  512.02kB   512.02kB     95:		streams:    make(map[uint32]*Stream),
       1MB        1MB     96:		inflight:   make(map[uint32]struct{}),
       2MB        2MB     97:		synCh:      make(chan struct{}, config.AcceptBacklog),
  108.92MB   108.92MB     98:		acceptCh:   make(chan *Stream, config.AcceptBacklog),
   70.70MB    70.70MB     99:		sendCh:     make(chan sendReady, 64),
    2.50MB     2.50MB    100:		recvDoneCh: make(chan struct{}),
       5MB        5MB    101:		shutdownCh: make(chan struct{}),
         .          .    102:	}
         .          .    103:	if client {
         .          .    104:		s.nextStreamID = 1
         .          .    105:	} else {
         .          .    106:		s.nextStreamID = 2

Really, those channels should be pretty small. I wonder if we're leaking connection objects somewhere. Looking at this, I'm pretty sure we are.

[Stebalien]

Yeah, there's definitely a slow leak. I've tried killing a bunch of connections but that memory doesn't move anywhere. However, this is quite a slow leak so it'll be tricky to track down where it's happening.

[Stebalien]

Historically, this has always been a race in stream management. That is, some service is holding onto an open stream but not actually using it. When services do that, they're supposed to detect that the client has disconnected and free the stream but I'm guessing that that isn't happening here.

[Stebalien]

Found it! If we abort the connection while the identify protocol is running, we'll keep a reference to the connection forever. This is an ancient bug.

[Stebalien]

fix: libp2p/go-libp2p#420

[cannium]

Awesome! I'll test with the latest version to see if fixed.

[Stebalien]

You'll have to wait for me to bubble the update to go-ipfs. I should get to that in a few days.

[cannium]

I gx-go linked it. The memory graph still grows slowly, but is far better than before.

[Stebalien]

That's great to hear (I didn't want to have to trouble you with getting gx working but I'm glad you were able to).

The remaining growth is probably the peerstore (which we're working on). However, so we don't make assumptions, mind posting a heap profile (just one should be fine) along with the IPFS binary and commit used to build it?

[cannium]

Put here as before: http://159.203.36.22:8000/
The go-ipfs version is 7ad12bf, linked go-libp2p version is 542d43a30fdece4b61517cacff56a3ccbedc4139

[Stebalien]

Thanks! Yeah, that looks like a known bug: ipfs/go-ipfs-blockstore#3. Basically, we should be using a significantly more efficient "has" cache for our blockstore.