Memory leak during massive file upload (or download) through SFTP frontend #1045
Labels
No Label
0.2.0
0.3.0
0.4.0
0.5.0
0.5.1
0.6.0
0.6.1
0.7.0
0.8.0
0.9.0
1.0.0
1.1.0
1.10.0
1.10.1
1.10.2
1.10a2
1.11.0
1.12.0
1.12.1
1.13.0
1.14.0
1.15.0
1.15.1
1.2.0
1.3.0
1.4.1
1.5.0
1.6.0
1.6.1
1.7.0
1.7.1
1.7β
1.8.0
1.8.1
1.8.2
1.8.3
1.8β
1.9.0
1.9.0-s3branch
1.9.0a1
1.9.0a2
1.9.0b1
1.9.1
1.9.2
1.9.2a1
LeastAuthority.com automation
blocker
cannot reproduce
cloud-branch
code
code-dirnodes
code-encoding
code-frontend
code-frontend-cli
code-frontend-ftp-sftp
code-frontend-magic-folder
code-frontend-web
code-mutable
code-network
code-nodeadmin
code-peerselection
code-storage
contrib
critical
defect
dev-infrastructure
documentation
duplicate
enhancement
fixed
invalid
major
minor
n/a
normal
operational
packaging
somebody else's problem
supercritical
task
trivial
unknown
was already fixed
website
wontfix
worksforme
No Milestone
No Assignees
3 Participants
Notifications
Due Date
No due date set.
Reference: tahoe-lafs/trac-2024-07-25#1045
Loading…
Reference in New Issue
No description provided.
Delete Branch "%!s(<nil>)"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
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.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:
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.)
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. :-/
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 withtahoe 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.
Attachment tahoe-cp-smem.jpg (28965 bytes) added
Attachment tahoe-sftp-smem.jpg (29848 bytes) added
For the record, those were the scripts used to generated both graphs.
The gnuplot script.
smem-log.sh
Memory leak during massive file uploadto Memory leak during massive file upload through SFTP frontendFranç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."memory usage, as reported by smem" -- more specifically what does smem report here? resident/virtual-size/ ?
Replying to zooko:
Oh, and I see the graph says "swap/PSS/USS/RSS".
Replying to zooko:
The files were uploaded sequentially.
And, my bad, the values on the y axis are in kbytes and not bytes as mentionned in comment:77329.
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).
Attachment tahoe-sftp-smem-2.jpg (24073 bytes) added
Replying to davidsarah:
Same test with latest code. The memory leak is probably somewhere else.
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.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).
Memory leak during massive file upload through SFTP frontendto Memory leak during massive file upload (or download) through SFTP frontendAttachment objects2.png (4716235 bytes) added
Graph of objects possibly leaked by an SFTP upload, and their backreferences
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?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.
Here are the results.
So, the main culprit is
test_openFile_write
!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.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:77342 but we can probably bear with them for 1.7.0-beta.
I reviewed changeset:3c44389440097dff and saw no problems.
I guess we're leaving this ticket open to investigate the smaller ones after 1.7.
François: can you reproduce the graph in comment:12 with current trunk?
Attachment tahoe-sftp-smem-3.jpg (21223 bytes) added
Replying to davidsarah:
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:77344](/tahoe-lafs/trac-2024-07-25/issues/1045#issuecomment-77344). Perhaps functions that are still leaking memory are being called much more often than
openFile_write
in a typical SFTP session.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?
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?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).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.
Replying to warner:
Please make this:
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.
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.
Replying to zooko:
To avoid mixing things up, I have created another ticket about this deep-check leak: #1229.
Replying to [davidsarah]comment:32:
This is implemented in this commit. Unfortunately, it doesn't look sufficient to have
ResponseCache
correctly gc'ed.Replying to [francois]comment:34:
This change looks correct, but I'd rather not make it if it doesn't solve the underlying problem.
Discussion of whether the
ResponseCache
is needed: http://tahoe-lafs.org/pipermail/tahoe-dev/2010-October/005488.htmlReplying to [francois]comment:33:
The following test confirms that the size of the
ResponseCache
(not the number of entries, interestingly) increases every time we download a mutable file: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.pyutil's memutil.check_for_obj_leakage() might be useful, and so might memutil.measure_obj_leakage().
Replying to [davidsarah]comment:37:
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
.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.
In changeset:59e80b2ec92928bf:
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.)
new-responsecache.darcs.patch looks great! r+ from me.
In changeset:4061258c85da2960:
francois: please repeat the graph of comment:12 and comment:23 with current trunk.
Attachment tahoe-smem-4.jpg (40522 bytes) added
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.
Attachment news-1045.dpatch (10841 bytes) added
Please find attached a ready-to-merge patch to the NEWS file.
source:NEWS entry in changeset:679c090c82cede16. We'll open a new ticket for the smaller leak.