tahoe-lafs/trac

Memory leak during massive file upload (or download) through SFTP frontend #1045

New issue

Closed

opened 2010-05-18 01:14:15 +00:00 by francois · 48 comments

francois commented

2010-05-18 01:14:15 +00:00

Owner

Today, I copied about 12'000 files for a total size of about 52 GB into Tahoe with the SFTP frontend.

Here's what top has to say about the Tahoe process after this operation.

 2765 francois  20   0 2059m 1.5g 2472 D    2 75.4 527:08.83 python

I will update this ticket as soon as I can gather more details.

David-Sarah Hopwood proposed to do the same test a second time via the wapi to help locate the leak.

Here is what Brian Warner proposed on IRC:

keep track of the process size vs time, with munin or a script that saves values and then graph them with gnuplot or something

I think tahoe's /stats WAPI will give you process-memory-size info

the idea is to do some operation repeatedly, measure process-space change while that's running, then switch to some other operation and measure that slope, and look for differences

'cp' to an SFTP-mounted FUSEish thing, vs 'tahoe cp' might be a good comparison

Today, I copied about 12'000 files for a total size of about 52 GB into Tahoe with the SFTP frontend. Here's what `top` has to say about the Tahoe process after this operation. ``` 2765 francois 20 0 2059m 1.5g 2472 D 2 75.4 527:08.83 python ``` I will update this ticket as soon as I can gather more details. David-Sarah Hopwood proposed to do the same test a second time via the wapi to help locate the leak. Here is what Brian Warner proposed on IRC: > keep track of the process size vs time, with munin or a script that saves values and then graph them with gnuplot or something > I think tahoe's /stats WAPI will give you process-memory-size info > the idea is to do some operation repeatedly, measure process-space change while that's running, then switch to some other operation and measure that slope, and look for differences > 'cp' to an SFTP-mounted FUSEish thing, vs 'tahoe cp' might be a good comparison

tahoe-lafs added the

labels 2010-05-18 01:14:15 +00:00

tahoe-lafs added this to the 1.8.0 milestone 2010-05-18 01:14:15 +00:00

daira added

c/code

and removed

c/unknown

labels 2010-05-18 01:24:48 +00:00

daira modified the milestone from 1.8.0 to undecided

2010-05-18 01:24:48 +00:00

zooko commented

2010-05-18 02:19:31 +00:00

Also try the handy new tool "smem":

http://www.selenic.com/smem/

That process that you are reporting on is the gateway process, right? (I.e., the SFTP server and the Tahoe-LAFS storage client.)

Also try the handy new tool "smem": <http://www.selenic.com/smem/> That process that you are reporting on is the gateway process, right? (I.e., the SFTP server and the Tahoe-LAFS storage client.)

zooko commented

2010-05-18 15:32:12 +00:00

This is serious! If it happens when not using SFTP then it is a critical regression in Tahoe-LAFS. If it happens when using SFTP then it is a critical problem in the new SFTP support. :-/

zooko added

p/critical

and removed

p/major

labels 2010-05-18 15:32:12 +00:00

francois commented

2010-05-18 15:42:44 +00:00

Author

Owner

In both graphs, x axis is in 10 seconds increments and y is in bytes.

The first graph was generated by logging memory usage, as reported by
smem during the upload of 53 GB of files with tahoe cp.
Please note that the increase in memory usage (at ''x==4000'') was due
to the opening of a single file with SFTP during this process.

Image(tahoe-cp-smem.jpg)

The second graph was generated by logggin memory usage during the upload
of the same files through the SFTP frontend. The upload was stopped
before it finished.

Image(tahoe-sftp-smem.jpg)

The conclusion I take from these graphs, is that the leak probably lies in the SFTP frontend.

In both graphs, x axis is in 10 seconds increments and y is in bytes. The first graph was generated by logging memory usage, as reported by `smem` during the upload of 53 GB of files with `tahoe cp`. Please note that the increase in memory usage (at ''x==4000'') was due to the opening of a single file with SFTP during this process. [[Image(tahoe-cp-smem.jpg)]] The second graph was generated by logggin memory usage during the upload of the same files through the SFTP frontend. The upload was stopped before it finished. [[Image(tahoe-sftp-smem.jpg)]] The conclusion I take from these graphs, is that the leak probably lies in the SFTP frontend.

francois commented

2010-05-18 15:47:36 +00:00

Author

Owner

Attachment tahoe-cp-smem.jpg (28965 bytes) added

**Attachment** tahoe-cp-smem.jpg (28965 bytes) added

tahoe-cp-smem.jpg

28 KiB

francois commented

2010-05-18 15:47:45 +00:00

Author

Owner

Attachment tahoe-sftp-smem.jpg (29848 bytes) added

**Attachment** tahoe-sftp-smem.jpg (29848 bytes) added

tahoe-sftp-smem.jpg

29 KiB

francois commented

2010-05-18 15:52:34 +00:00

Author

Owner

For the record, those were the scripts used to generated both graphs.

$ smem-log.sh 1 [t]ahoe-client.tac | tee /tmp/tahoe-sftp-smem.log

The gnuplot script.

set xlabel "seconds"
set ylabel "bytes"
plot "tahoe-sftp-smem.log" using 0:6 with lines title 'Swap', \
              "tahoe-sftp-smem.log" using 0:7 with lines title 'USS',  \
              "tahoe-sftp-smem.log" using 0:8 with lines title 'PSS',  \
              "tahoe-sftp-smem.log" using 0:9 with lines title 'RSS'

smem-log.sh


while :; do
  SMEM=$(smem -P $2 -H)

  if [ $? -eq 0 ]; then
    echo "\"$(date)\" $SMEM"
  fi
  sleep $1
done

For the record, those were the scripts used to generated both graphs. ``` $ smem-log.sh 1 [t]ahoe-client.tac | tee /tmp/tahoe-sftp-smem.log ``` The gnuplot script. ``` set xlabel "seconds" set ylabel "bytes" plot "tahoe-sftp-smem.log" using 0:6 with lines title 'Swap', \ "tahoe-sftp-smem.log" using 0:7 with lines title 'USS', \ "tahoe-sftp-smem.log" using 0:8 with lines title 'PSS', \ "tahoe-sftp-smem.log" using 0:9 with lines title 'RSS' ``` `smem-log.sh` ```/bin/sh while :; do SMEM=$(smem -P $2 -H) if [ $? -eq 0 ]; then echo "\"$(date)\" $SMEM" fi sleep $1 done ```

tahoe-lafs changed title from ~~Memory leak during massive file upload~~ to Memory leak during massive file upload through SFTP frontend

2010-05-18 15:52:34 +00:00

zooko commented

2010-05-18 19:47:53 +00:00

François: what is the script used to initiate the 12,000 file uploads? There should be two scripts--one using tahoe cp and one using SFTP, right? I want to see how many files are being uploaded in parallel vs. in serial.

François: what is the script used to initiate the 12,000 file uploads? There should be two scripts--one using `tahoe cp` and one using SFTP, right? I want to see how many files are being uploaded in parallel vs. in serial.

zooko commented

2010-05-18 19:50:04 +00:00

"memory usage, as reported by smem" -- more specifically what does smem report here? resident/virtual-size/ ?

zooko commented

2010-05-18 19:51:49 +00:00

Replying to zooko:

"memory usage, as reported by smem" -- more specifically what does smem report here? resident/virtual-size/ ?
Well fdz posted the script:

  SMEM=$(smem -P $2 -H)

Oh, and I see the graph says "swap/PSS/USS/RSS".

Replying to [zooko](/tahoe-lafs/trac/issues/1045#issuecomment-378255): > "memory usage, as reported by smem" -- more specifically what does smem report here? resident/virtual-size/ ? Well fdz posted the script: ``` SMEM=$(smem -P $2 -H) ``` Oh, and I see the graph says "swap/PSS/USS/RSS".

francois commented

2010-05-18 22:00:50 +00:00

Author

Owner

Replying to zooko:

François: what is the script used to initiate the 12,000 file uploads? There should be two scripts--one using tahoe cp and one using SFTP, right? I want to see how many files are being uploaded in parallel vs. in serial.

The files were uploaded sequentially.

And, my bad, the values on the y axis are in kbytes and not bytes as mentionned in comment:378251.

Replying to [zooko](/tahoe-lafs/trac/issues/1045#issuecomment-378254): > François: what is the script used to initiate the 12,000 file uploads? There should be two scripts--one using `tahoe cp` and one using SFTP, right? I want to see how many files are being uploaded in parallel vs. in serial. The files were uploaded sequentially. And, my bad, the values on the y axis are in **kbytes** and not bytes as mentionned in [comment:378251](/tahoe-lafs/trac/issues/1045#issuecomment-378251).

daira commented

2010-05-19 01:42:06 +00:00

It turns out that the SFTP code was logging all of the data going through it to the foolscap log. I've fixed that in the branch, so please pull and try again (if only to eliminate this as a possible cause of the leak).

francois commented

2010-05-19 11:20:20 +00:00

Author

Owner

Attachment tahoe-sftp-smem-2.jpg (24073 bytes) added

**Attachment** tahoe-sftp-smem-2.jpg (24073 bytes) added

tahoe-sftp-smem-2.jpg

24 KiB

francois commented

2010-05-19 11:21:56 +00:00

Author

Owner

Replying to davidsarah:

It turns out that the SFTP code was logging all of the data going through it to the foolscap log. I've fixed that in the branch, so please pull and try again (if only to eliminate this as a possible cause of the leak).

Same test with latest code. The memory leak is probably somewhere else.

Replying to [davidsarah](/tahoe-lafs/trac/issues/1045#issuecomment-378258): > It turns out that the SFTP code was logging all of the data going through it to the foolscap log. I've fixed that in the branch, so please pull and try again (if only to eliminate this as a possible cause of the leak). Same test with latest code. The memory leak is probably somewhere else. ![](attachments/tahoe-sftp-smem-2.jpg)

zooko commented

2010-05-19 12:59:39 +00:00

One way to investigate this would be to take one of the SFTP unit tests and wrap it in a call to pyutil.memutil.check_for_obj_leakage() and make that be a new unit test.

The docstring of check_for_obj_leakage() explains how to (carefully) interpret its results.

One way to investigate this would be to take one of the SFTP unit tests and wrap it in a call to [pyutil.memutil.check_for_obj_leakage()](http://tahoe-lafs.org/trac/pyutil/browser/pyutil/pyutil/memutil.py?rev=202#L47) and make that be a new unit test. The docstring of `check_for_obj_leakage()` explains how to (carefully) interpret its results.

francois commented

2010-05-19 19:45:55 +00:00

Author

Owner

Further testing has shown that the leak can also be reproduced by downloading files from Tahoe (i.e. copying them from the SFTP server to the local system).

tahoe-lafs changed title from ~~Memory leak during massive file upload through SFTP frontend~~ to Memory leak during massive file upload (or download) through SFTP frontend

2010-05-19 19:45:55 +00:00

daira commented

2010-05-26 04:05:30 +00:00

Attachment objects2.png (4716235 bytes) added

Graph of objects possibly leaked by an SFTP upload, and their backreferences

**Attachment** objects2.png (4716235 bytes) added Graph of objects *possibly* leaked by an SFTP upload, and their backreferences

objects2.png

4.5 MiB

daira commented

2010-05-27 16:41:49 +00:00

Hmm, how do we know this is not the same bug as #891 ?

The difference between the behaviour of SFTP and tahoe cp doesn't necessarily imply that it isn't, because the SFTP implementation might be allowing more concurrency. François, are you absolutely sure that each SFTP upload (that is, the upload to storage servers, not just the gateway) is completing before starting the next?

Hmm, how do we know this is not the same bug as #891 ? The difference between the behaviour of SFTP and `tahoe cp` doesn't necessarily imply that it isn't, because the SFTP implementation might be allowing more concurrency. François, are you absolutely sure that each SFTP upload (that is, the upload to storage servers, not just the gateway) is completing before starting the next?

francois commented

2010-06-08 23:34:51 +00:00

Author

Owner

OK, I've been running each SFTP unit test many times in a row to see how increase in memory usage was influenced by each test.

term1 $ trial -u allmydata.test.test_sftp.Handler.test_basic
term2 $ while :; do smem -P test_basi[c] -H; sleep 10; done

Here are the results.

All SFTP tests -> Leak
test_basic -> No leak
test_convert_error -> No leak
test_execCommand_and_openShell -> No leak
test_extendedRequest -> No leak
test_makeDirectory -> No leak
test_not_implemented-> No leak
test_openDirectory_and_attrs -> No leak
test_openFile_read -> Perhaps a very small leak (4.5 MB increase after ~30 iterations)
test_openFile_write -> Huge LEAK (420 MB increase after 110 iterations)
test_removeDirectory -> Small leak (about 3 MB increase after 100 iterations)
test_removeFile -> Small leak (about 2.1 MB increase after 100 iterations)
test_renameFile -> Small leak (5 MB increase after 100 iterations)
test_renameFile_posix -> Small leak (4.5 MB increase after 100 iterations)

So, the main culprit is test_openFile_write!

OK, I've been running each SFTP unit test many times in a row to see how increase in memory usage was influenced by each test. ``` term1 $ trial -u allmydata.test.test_sftp.Handler.test_basic term2 $ while :; do smem -P test_basi[c] -H; sleep 10; done ``` Here are the results. * All SFTP tests -> Leak * test_basic -> No leak * test_convert_error -> No leak * test_execCommand_and_openShell -> No leak * test_extendedRequest -> No leak * test_makeDirectory -> No leak * test_not_implemented-> No leak * test_openDirectory_and_attrs -> No leak * test_openFile_read -> Perhaps a very small leak (4.5 MB increase after ~30 iterations) * test_openFile_write -> **Huge LEAK** (420 MB increase after 110 iterations) * test_removeDirectory -> Small leak (about 3 MB increase after 100 iterations) * test_removeFile -> Small leak (about 2.1 MB increase after 100 iterations) * test_renameFile -> Small leak (5 MB increase after 100 iterations) * test_renameFile_posix -> Small leak (4.5 MB increase after 100 iterations) So, the main culprit is `test_openFile_write`!

francois commented

2010-06-08 23:53:56 +00:00

Author

Owner

Additional testing has shown that the major memory leak comes from the last part on test_openFile_write which begins in test_sftp.py line 887.

Additional testing has shown that the major memory leak comes from the last part on `test_openFile_write` which begins in [test_sftp.py line 887](http://tahoe-lafs.org/trac/tahoe-lafs/browser/src/allmydata/test/test_sftp.py#L887).

francois commented

2010-06-09 09:40:30 +00:00

Author

Owner

Yay! David-Sarah found the cause of the most significant leak in the SFTP frontend and fixed it in changeset:3c44389440097dff.

There are still some minor leaks (two order of magnitude smaller) as mentioned in comment:378264 but we can probably bear with them for 1.7.0-beta.

Yay! David-Sarah found the cause of the most significant leak in the SFTP frontend and fixed it in changeset:3c44389440097dff. There are still some minor leaks (two order of magnitude smaller) as mentioned in [comment:378264](/tahoe-lafs/trac/issues/1045#issuecomment-378264) but we can probably bear with them for 1.7.0-beta.

zooko commented

2010-06-09 14:16:21 +00:00

I reviewed changeset:3c44389440097dff and saw no problems.

zooko commented

2010-06-09 14:28:42 +00:00

I guess we're leaving this ticket open to investigate the smaller ones after 1.7.

daira commented

2010-06-11 19:23:50 +00:00

François: can you reproduce the graph in comment:12 with current trunk?

francois commented

2010-06-12 12:59:14 +00:00

Author

Owner

Attachment tahoe-sftp-smem-3.jpg (21223 bytes) added

**Attachment** tahoe-sftp-smem-3.jpg (21223 bytes) added

tahoe-sftp-smem-3.jpg

21 KiB

francois commented

2010-06-12 13:08:00 +00:00

Author

Owner

Replying to davidsarah:

François: can you reproduce the graph in comment:12 with current trunk?

Here is the result of the test with 1.6.1-r4477. The graph shows that the actual memory leak is not as small as I thought in [comment:378266](/tahoe-lafs/trac/issues/1045#issuecomment-378266). Perhaps functions that are still leaking memory are being called much more often than openFile_write in a typical SFTP session.

Replying to [davidsarah](/tahoe-lafs/trac/issues/1045#issuecomment-378269): > François: can you reproduce the graph in comment:12 with current trunk? Here is the result of the test with 1.6.1-r4477. The graph shows that the actual memory leak is not as small as I thought in [[comment:378266](/tahoe-lafs/trac/issues/1045#issuecomment-378266)](/tahoe-lafs/trac/issues/1045#issuecomment-378266). Perhaps functions that are still leaking memory are being called much more often than `openFile_write` in a typical SFTP session. ![](attachments/tahoe-sftp-smem-3.jpg)

daira modified the milestone from undecided to 1.8.0

2010-07-17 06:08:12 +00:00

zooko commented

2010-07-24 05:34:20 +00:00

This is a serious bug. It is correctly marked "critical" in Priority. What's the next step? I think it is either to use a tool like check_for_obj_leakage in a controlled deterministic unit-test style exercise of the SFTP front-end code, or else for someone to experiment with a live system and try to figure out what sorts of usage patterns trigger the memory consumption.

Any other ideas?

This is a serious bug. It is correctly marked "critical" in Priority. What's the next step? I think it is either to use a tool like [check_for_obj_leakage](http://tahoe-lafs.org/trac/pyutil/browser/trunk/pyutil/memutil.py?rev=218#L47) in a controlled deterministic unit-test style exercise of the SFTP front-end code, or else for someone to experiment with a live system and try to figure out what sorts of usage patterns trigger the memory consumption. Any other ideas?

zooko modified the milestone from 1.8.0 to soon

2010-08-09 21:23:42 +00:00

zooko modified the milestone from soon to 1.9.0

2010-08-09 22:16:10 +00:00

zooko commented

2010-10-22 13:11:12 +00:00

In http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005464.html François says that he also gets a memory leak during tahoe deep-check --add-lease --repair in addition to getting a memory leak while using the sftp frontend. Could there be two leaks? Or is it likely to be the same one in these two cases?

In <http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005464.html> François says that he also gets a memory leak during `tahoe deep-check --add-lease --repair` in addition to getting a memory leak while using the sftp frontend. Could there be two leaks? Or is it likely to be the same one in these two cases?

warner commented

2010-10-22 16:02:41 +00:00

I think his email describes the leak here in #1045, but not necessarily in deep-check. The distinguisher will be if there are lots of MutableFileNodes hanging around. The #1045 leak appears to be related to making lots of changes to a single mutable file, whereas deep-check is going to be reading from lots and lots of files (probably mostly immutable, but possibly some mutable, depending upon how you use directories).

I think his email describes the leak here in #1045, but not necessarily in deep-check. The distinguisher will be if there are lots of `MutableFileNodes` hanging around. The #1045 leak appears to be related to making lots of changes to a single mutable file, whereas deep-check is going to be reading from lots and lots of files (probably mostly immutable, but possibly some mutable, depending upon how you use directories).

warner commented

2010-10-22 16:06:46 +00:00

Looking at the difference between A) upload 10000 files of 1MB each, versus B) upload 10 files of 1GB each, would help distinguish between problems with large files and problems with large/churning directories. And uploading then all into one directory versus spread across 1000 directories would help distinguish between mutable-file-modification in general, and lots-of-generations on a single mutable file.

Oh, Francois, could you mention whether these uploads are all going to the same directory, or if they're going to a variety of directories? I think the "massive" qualifier in the title might best apply to the number of changes being made to a single directory, rather than the total size of the data being uploaded. Looking at the difference between A) upload 10000 files of 1MB each, versus B) upload 10 files of 1GB each, would help distinguish between problems with large files and problems with large/churning directories. And uploading then all into one directory versus spread across 1000 directories would help distinguish between mutable-file-modification in general, and lots-of-generations on a single mutable file.

daira commented

2010-10-23 00:03:12 +00:00

Replying to warner:

... And uploading then all into one directory versus spread across 1000 directories would help distinguish between mutable-file-modification in general, and lots-of-generations on a single mutable file.

Please make this:

upload all into the root directory (of the SFTP user);
upload all into one subdirectory;
upload spread across 1000 subdirectories.

This will test whether it is significant that a reference to the root dirnode is held for as long as the SFTP user session is logged in.

Replying to [warner](/tahoe-lafs/trac/issues/1045#issuecomment-378277): > ... And uploading then all into one directory versus spread across 1000 directories would help distinguish between mutable-file-modification in general, and lots-of-generations on a single mutable file. Please make this: * upload all into the root directory (of the SFTP user); * upload all into one subdirectory; * upload spread across 1000 subdirectories. This will test whether it is significant that [a reference to the root dirnode is held for as long as the SFTP user session is logged in](http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005473.html).

daira commented

2010-10-23 01:27:27 +00:00

Attachment only-cache-last-seen-seqnum.darcs.patch (4395 bytes) added

mutable/common.py: make the ResponseCache only cache shares with the last-seen seqnum for a given storage index. No unit tests; do not apply to trunk yet.

**Attachment** only-cache-last-seen-seqnum.darcs.patch (4395 bytes) added mutable/common.py: make the [ResponseCache](wiki/ResponseCache) only cache shares with the last-seen seqnum for a given storage index. No unit tests; do not apply to trunk yet.

only-cache-last-seen-seqnum.darcs.patch

4.3 KiB

francois commented

2010-10-24 13:57:05 +00:00

Author

Owner

Replying to zooko:

In http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005464.html François says that he also gets a memory leak during tahoe deep-check --add-lease --repair in addition to getting a memory leak while using the sftp frontend. Could there be two leaks? Or is it likely to be the same one in these two cases?

To avoid mixing things up, I have created another ticket about this deep-check leak: #1229.

Replying to [zooko](/tahoe-lafs/trac/issues/1045#issuecomment-378275): > In <http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005464.html> François says that he also gets a memory leak during `tahoe deep-check --add-lease --repair` in addition to getting a memory leak while using the sftp frontend. Could there be two leaks? Or is it likely to be the same one in these two cases? To avoid mixing things up, I have created another ticket about this deep-check leak: #1229.

francois commented

2010-10-24 14:41:11 +00:00

Author

Owner

Replying to [davidsarah]comment:32:

This will test whether it is significant that a reference to the root dirnode is held for as long as the SFTP user session is logged in.

This is implemented in this commit. Unfortunately, it doesn't look sufficient to have ResponseCache correctly gc'ed.

Replying to [davidsarah]comment:32: > This will test whether it is significant that [a reference to the root dirnode is held for as long as the SFTP user session is logged in](http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005473.html). This is implemented in this [commit](http://github.com/ctrlaltdel/tahoe-lafs/commit/aefcd3b03130b6f59973cf87761b8e8ab15f6546). Unfortunately, it doesn't look sufficient to have `ResponseCache` correctly gc'ed.

daira commented

2010-10-24 16:47:45 +00:00

Replying to [francois]comment:34:

Replying to [davidsarah]comment:32:

This will test whether it is significant that a reference to the root dirnode is held for as long as the SFTP user session is logged in.

This is implemented in this commit. Unfortunately, it doesn't look sufficient to have ResponseCache correctly gc'ed.

This change looks correct, but I'd rather not make it if it doesn't solve the underlying problem.

Replying to [francois]comment:34: > Replying to [davidsarah]comment:32: > > > This will test whether it is significant that [a reference to the root dirnode is held for as long as the SFTP user session is logged in](http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005473.html). > > This is implemented in this [commit](http://github.com/ctrlaltdel/tahoe-lafs/commit/aefcd3b03130b6f59973cf87761b8e8ab15f6546). Unfortunately, it doesn't look sufficient to have `ResponseCache` correctly gc'ed. This change looks correct, but I'd rather not make it if it doesn't solve the underlying problem.

daira commented

2010-10-24 17:17:59 +00:00

Discussion of whether the ResponseCache is needed: http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005488.html

Discussion of whether the `ResponseCache` is needed: <http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005488.html>

daira commented

2010-10-24 20:07:13 +00:00

Replying to [francois]comment:33:

Replying to zooko:

In http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005464.html François says that he also gets a memory leak during tahoe deep-check --add-lease --repair in addition to getting a memory leak while using the sftp frontend.

The following test confirms that the size of the ResponseCache (not the number of entries, interestingly) increases every time we download a mutable file:


    def test_response_cache_memory_leak(self):
        d = self.nodemaker.create_mutable_file("contents")
        def _created(n):
            d = n.download_best_version()
            d.addCallback(lambda res: self.failUnlessEqual(res, "contents"))
            d.addCallback(lambda ign: self.failUnless(isinstance(n._cache, ResponseCache)))

            def _check_cache_size(expected):
                # The total size of cache entries should not increase on the second download.
                d2 = n.download_best_version()
                d2.addCallback(lambda ign: self.failUnlessEqual(len(repr(n._cache.cache)), expected))
                return d2
            d.addCallback(lambda ign: _check_cache_size(len(repr(n._cache.cache))))
            return d
        d.addCallback(_created)
        return d
    test_response_cache_memory_leak.todo = "This isn't fixed (see #1045)."

Could there be two leaks? Or is it likely to be the same one in these two cases?

I think we have no evidence for two independent leaks at this point (but we might need to fix the ResponseCache one in order to see whether there is anything else).

review-needed for the above test.

Replying to [francois]comment:33: > Replying to [zooko](/tahoe-lafs/trac/issues/1045#issuecomment-378275): > > > In <http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005464.html> François says that he also gets a memory leak during `tahoe deep-check --add-lease --repair` in addition to getting a memory leak while using the sftp frontend. The following test confirms that the size of the `ResponseCache` (*not* the number of entries, interestingly) increases every time we download a mutable file: ``` def test_response_cache_memory_leak(self): d = self.nodemaker.create_mutable_file("contents") def _created(n): d = n.download_best_version() d.addCallback(lambda res: self.failUnlessEqual(res, "contents")) d.addCallback(lambda ign: self.failUnless(isinstance(n._cache, ResponseCache))) def _check_cache_size(expected): # The total size of cache entries should not increase on the second download. d2 = n.download_best_version() d2.addCallback(lambda ign: self.failUnlessEqual(len(repr(n._cache.cache)), expected)) return d2 d.addCallback(lambda ign: _check_cache_size(len(repr(n._cache.cache)))) return d d.addCallback(_created) return d test_response_cache_memory_leak.todo = "This isn't fixed (see #1045)." ``` > Could there be two leaks? Or is it likely to be the same one in these two cases? I think we have no evidence for two independent leaks at this point (but we might need to fix the `ResponseCache` one in order to see whether there is anything else). `review-needed` for the above test.

zooko commented

2010-10-24 20:50:20 +00:00

pyutil's memutil.check_for_obj_leakage() might be useful, and so might memutil.measure_obj_leakage().

pyutil's [memutil.check_for_obj_leakage()](http://tahoe-lafs.org/trac/pyutil/browser/trunk/pyutil/memutil.py?annotate=blame&rev=218#L47) might be useful, and so might [memutil.measure_obj_leakage()](http://tahoe-lafs.org/trac/pyutil/browser/trunk/pyutil/memutil.py?annotate=blame&rev=218#L101).

francois commented

2010-10-26 00:21:53 +00:00

Author

Owner

Replying to [davidsarah]comment:37:

The following test confirms that the size of the ResponseCache (not the number of entries, interestingly) increases every time we download a mutable file:

Well, the number of entries actually increases in the second dimension of the _cache array. The cache looks like that in a simplified way: _cacheverinfooffset.

review-needed for the above test.

I reviewed your test and it looks good. I also actually tested it, when the cache is activated it fails and when the cache is deactivated (by commenting source:trunk/src/allmydata/mutable/servermap.py#L584) it passes.

Replying to [davidsarah]comment:37: > The following test confirms that the size of the `ResponseCache` (*not* the number of entries, interestingly) increases every time we download a mutable file: Well, the number of entries actually increases in the second dimension of the `_cache` array. The cache looks like that in a simplified way: `_cacheverinfooffset`. > `review-needed` for the above test. I reviewed your test and it looks good. I also actually tested it, when the cache is activated it fails and when the cache is deactivated (by commenting source:trunk/src/allmydata/mutable/servermap.py#L584) it passes.

daira commented

2010-10-26 01:31:34 +00:00

In changeset:59e80b2ec92928bf:

test_mutable.py: add test for ResponseCache memory leak. refs #1045, #1129

In changeset:59e80b2ec92928bf: ``` test_mutable.py: add test for ResponseCache memory leak. refs #1045, #1129 ```

daira commented

2010-10-27 05:00:30 +00:00

Attachment new-responsecache.darcs.patch (19627 bytes) added

make ResponseCache smarter to avoid memory leaks: don't record timestamps, use DataSpans to merge entries, and clear the cache when we see a new seqnum. refs #1045, #1229. (This supercedes only-cache-last-seen-seqnum.darcs.patch.)

**Attachment** new-responsecache.darcs.patch (19627 bytes) added make [ResponseCache](wiki/ResponseCache) smarter to avoid memory leaks: don't record timestamps, use [DataSpans](wiki/DataSpans) to merge entries, and clear the cache when we see a new seqnum. refs #1045, #1229. (This supercedes only-cache-last-seen-seqnum.darcs.patch.)

new-responsecache.darcs.patch

19 KiB

daira modified the milestone from 1.9.0 to 1.8.1

2010-10-27 05:14:07 +00:00

warner commented

2010-10-29 08:23:04 +00:00

attachment:new-responsecache.darcs.patch looks great! r+ from me.

[attachment:new-responsecache.darcs.patch](/tahoe-lafs/trac/attachments/000078ac-ef9c-b1ab-fdb1-3ea54f327d6a) looks great! r+ from me.

warner removed their assignment 2010-10-29 08:23:04 +00:00

daira was assigned by warner

2010-10-29 08:23:04 +00:00

daira commented

2010-10-29 19:43:13 +00:00

In changeset:4061258c85da2960:

make ResponseCache smarter to avoid memory leaks: don't record timestamps, use DataSpans to merge entries, and clear the cache when we see a new seqnum. refs #1045, #1229

In changeset:4061258c85da2960: ``` make ResponseCache smarter to avoid memory leaks: don't record timestamps, use DataSpans to merge entries, and clear the cache when we see a new seqnum. refs #1045, #1229 ```

daira commented

2010-10-30 05:01:48 +00:00

francois: please repeat the graph of comment:12 and comment:23 with current trunk.

francois commented

2010-10-30 10:21:59 +00:00

Author

Owner

Attachment tahoe-smem-4.jpg (40522 bytes) added

**Attachment** tahoe-smem-4.jpg (40522 bytes) added

tahoe-smem-4.jpg

40 KiB

francois commented

2010-10-30 10:33:26 +00:00

Author

Owner

This is much better now!

Thank you very much Brian and David-Sarah for your great work.

This following graph was produced during the upload of about 3.5 GB of audio files (between 1 MB and 10 MB in size) through the SFTP frontend. In this particular workload, a (small) leak of about 4 MB per hour is still visible.

I'd say that we can consider this issue closed but I'll continue to investigate this kind of issue and will open further tickets as necessary.

This is much better now! Thank you very much Brian and David-Sarah for your great work. This following graph was produced during the upload of about 3.5 GB of audio files (between 1 MB and 10 MB in size) through the SFTP frontend. In this particular workload, a (small) leak of about 4 MB per hour is still visible. I'd say that we can consider this issue closed but I'll continue to investigate this kind of issue and will open further tickets as necessary. ![](attachments/tahoe-smem-4.jpg)

francois commented

2010-10-30 10:38:37 +00:00

Author

Owner

Attachment news-1045.dpatch (10841 bytes) added

**Attachment** news-1045.dpatch (10841 bytes) added

news-1045.dpatch

11 KiB

francois commented

2010-10-30 10:40:34 +00:00

Author

Owner