camlistored memory leaks while syncing to google cloud

[bavovna]

camtool sync -src local -dest google -verbose

leads to memory leaks in camlistored and, eventually, it is OOM-killed.

while :; do r=$(cat /proc/`ps ax | grep camlistore[d] | awk '{print $1;}'`/status | grep VmSize); echo `date` $r; sleep 30; done
Wed Jun 8 21:08:21 PDT 2016 VmSize: 433584 kB
Wed Jun 8 21:08:51 PDT 2016 VmSize: 497304 kB
Wed Jun 8 21:09:21 PDT 2016 VmSize: 506272 kB
Wed Jun 8 21:09:51 PDT 2016 VmSize: 506272 kB
Wed Jun 8 21:10:21 PDT 2016 VmSize: 506272 kB
Wed Jun 8 21:10:51 PDT 2016 VmSize: 506272 kB
Wed Jun 8 21:11:21 PDT 2016 VmSize: 506272 kB
Wed Jun 8 21:11:51 PDT 2016 VmSize: 527412 kB
Wed Jun 8 21:12:21 PDT 2016 VmSize: 553836 kB
Wed Jun 8 21:12:51 PDT 2016 VmSize: 569692 kB
Wed Jun 8 21:13:21 PDT 2016 VmSize: 569692 kB
Wed Jun 8 21:13:51 PDT 2016 VmSize: 579204 kB
Wed Jun 8 21:14:21 PDT 2016 VmSize: 614084 kB
Wed Jun 8 21:14:51 PDT 2016 VmSize: 633368 kB
Wed Jun 8 21:15:21 PDT 2016 VmSize: 633368 kB
Wed Jun 8 21:15:51 PDT 2016 VmSize: 633368 kB
Wed Jun 8 21:16:21 PDT 2016 VmSize: 648164 kB
Wed Jun 8 21:16:51 PDT 2016 VmSize: 658736 kB
Wed Jun 8 21:17:21 PDT 2016 VmSize: 666132 kB
Wed Jun 8 21:17:52 PDT 2016 VmSize: 674588 kB
Wed Jun 8 21:18:22 PDT 2016 VmSize: 686216 kB
Wed Jun 8 21:18:52 PDT 2016 VmSize: 766292 kB
Wed Jun 8 21:19:22 PDT 2016 VmSize: 770520 kB

after I stop the sync, memory stops growing:

Wed Jun 8 21:19:52 PDT 2016 VmSize: 775804 kB
Wed Jun 8 21:20:22 PDT 2016 VmSize: 775804 kB
Wed Jun 8 21:20:52 PDT 2016 VmSize: 775804 kB
Wed Jun 8 21:21:22 PDT 2016 VmSize: 775804 kB

server-config.json:

"/sto-googlecloudstorage/": {
      "handler": "storage-googlecloudstorage",
      "handlerArgs": {
        "auth": {
          "client_id": "suchmuch-very-secret.apps.googleusercontent.com",
          "client_secret": "secret-secret",
          "refresh_token": "1/token-secret"
        },
        "bucket": "camlistorage"
      }
    },
    "/sync-to-googlecloudstorage/": {
      "handler": "sync",
      "handlerArgs": {
        "from": "/bs/",
        "queue": {
          "file": "/srv/camlistore/var/camlistore/blobs/sync-to-googlecloud-queue.kv",
          "type": "kv"
        },
        "to": "/sto-googlecloudstorage/"
      }
    },

client-config.json:

{
  "servers": {
    "local": {
      "server": "http://127.0.0.1:3179",
      "auth": "userpass:username:secret",
      "default": true
    },
    "google": {
      "server": "http://127.0.0.1:3179/sto-googlecloudstorage/",
      "auth": "userpass:username:secret",
      "default": false
    }
  },
  "identity": "very-secret-identity",
  "ignoredFiles": [
    ".DS_Store"
  ]
}

[mpl]

thanks, I'll try to reproduce.
Can you tell me if the fact that it syncs to GCS is relevant, or can you observe the same behaviour when syncing to anywhere else?

[mpl]

@mkorenkov I was able to reproduce, thanks.

[mpl]

I strongly suspect that at least some of that mem usage increase is simply the memory blobserver used as cache for the cloudstorage blobserver. Which might not be so useful when your cloudstorage server is not a primary (i.e. you also have a local blobserver defined, as the primary).
If that is confirmed, we could let the user configure the max size of that cache (it defaults to 32MB), or at the very least we could cap it to a lower value in that configuration.

Anyway, I'll confirm and write a fix tomorrow.

[bavovna]

@mpl I indeed have a google cloudstorage as a secondary storage.

Some facts, that might be useful. I have 413,274 blobs (21.338 GiB) total. I run camlistore in a docker-container with --memory="8G" and it needs only only 40k-50k blobs to OOM. Given the numbers above, roughly 8G should be more than enough to hold 100k blobs. So there might be some issue with cache consuming a few times more memory it actually needs.

Let me know if I can help you.

[mpl]

@mkorenkov If I set the cloudstorage cache size to a much lower limit (5MB), then I see the VmSize only increase by ~25MB, and it stops growing before the sync is finished. So I don't actually see any leak, just the cache filling in until it reaches its max size.

Still, if there's only a multiplicative factor between the cache size and the measured VmSize increase (~ 5 times according to the above), then you shouldn't see more than a 32*5 = ~160MB increase, and you shouldn't get an OOM. So I don't know what's actually going on for you then. Maybe a problem with the garbage collector when within docker?

In any case, could you please apply the diff below, and retry the sync please? If you still see the mem increase a lot (more than say, 25MB) with that diff, then we'll definitely know there's something else going on in your case.

diff --git a/pkg/blobserver/google/cloudstorage/storage.go b/pkg/blobserver/google/cloudstorage/storage.go
index dd5188d..22eb64a 100644
--- a/pkg/blobserver/google/cloudstorage/storage.go
+++ b/pkg/blobserver/google/cloudstorage/storage.go
@@ -157,7 +157,7 @@ func newFromConfig(_ blobserver.Loader, config jsonconfig.Obj) (blobserver.Stora
        gs.client = cl

        if cacheSize != 0 {
-               gs.cache = memory.NewCache(cacheSize)
+               gs.cache = memory.NewCache(5<<20)
        }

        ba, err := gs.client.Bucket(gs.bucket).Attrs(ctx)

[bavovna]

@mpl sorry for being that tardy with a response.

I have tested the given diff on the latest release (0.9) and it is still able to OOM. However, master branch seems to have different behavior: the curve on memory increase in not that steep, it took it almost 90 minutes to get to 506612 kB and it didn't change after that. I've given up waiting after another 90 minutes. RAM usage dropped to 328236 kB with the applied patch under the same test conditions.

That being said, this issue is already solved in master branch. It would be great if you could backport it to 0.9 as well. The proposed patch seems also have great value for low-memory configurations.

[mpl]

oh, I didn't know you were on 0.9, I was testing on master all along.
I don't know what it is in master that makes a difference, and I'm not sure that's worth investigating since we were supposed to have cut 0.10 for a while already. Is using master in the meantime out of the question for you?

As for my patch, if on master/0.10 you still have memory usage problem, we could indeed consider something like it (a cleaner version of course, that would give the user more control over that cache size).

[bavovna]

@mpl, sorry, it's my bad. I forgot to mention I was on 0.9.

I'm excited to hear 0.10 is coming soon, in the meantime I'm fine using master. In fact, I've been using master with and without patch for a few days now. It works well, mem usage is growing up to 506612 kB without a patch and 328236 kB with a patch. And mem usage does not go any further (no leaks detected).

As for the patched / non patched version, I would definitely prefer the patched version due to smaller memory footprint.

[mpl]

@mkorenkov sorry, I forgot about this for a while. Then I hesitated, because I'm not sure making the option available in the high-level config is that interesting, since it's a corner case and it's available at the low-level already if needed.
But I made it anyway, so here goes: https://camlistore-review.googlesource.com/6976
Let me know if that works for you please.