Absurd memory usage with bitten-master

[asmodai@…]

With r316 of bitten starting bitten-master completes a few builds and then fails with:

Exception in thread Create snapshot tendra-trunk_r783.zip:
Traceback (most recent call last):
  File "/usr/local/lib/python2.4/threading.py", line 442, in __bootstrap
    self.run()
  File "/usr/local/lib/python2.4/threading.py", line 422, in run
    self.__target(*self.__args, **self.__kwargs)
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 238, in _create
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 202, in _add_entry
  File "build/bdist.freebsd-4.11-STABLE-i386/egg/bitten/snapshot.py", line 217, in _add_entry
  File "/usr/local/lib/python2.4/zipfile.py", line 463, in writestr
    zlib.DEFLATED, -15)
MemoryError: Can't allocate memory for compression object

Looking at top I see:

  PID USERNAME   PRI NICE  SIZE    RES STATE    TIME   WCPU    CPU COMMAND
59113 root         2   0   522M   492M poll     1:55  0.59%  0.59% python

492MB resident memory used seems a bit absurd and would explain the MemoryError.

[cmlenz]

Yeah, that's bad :-/

[anonymous]

The bitten-master process starts around 10MB.

When it starts to initiate a build the memory consumption for my project grows to 427MB RSS. And it ends at 'prepared snapshot archive'.

Next build it wants to initiate will increase memory usage even more.

NOTE: Dima Dorfman pointed me to the PYMALLOC usage. Recompiling Python 2.4 now with PYMALLOC turned off (it was turned on in my setup) to see if it makes a difference.

[asmodai@…]

No, turning PYMALLOC on or off does not seem to matter. I again get 427M RSS.

[cmlenz]

I guess this is because the zipfile module that the build master uses to create the snapshot archive keeps the entire archive in memory. Probably should switch back to bzip2 tar files.

[asmodai@…]

Further comments by Dima Dorfman:

a = []; a.append(a) -- creates a cycle. simple refcounting will never deallocate a. Python has a cyclic GC that will break the cycle, but it does not run after every instruction.
If it's easy, try running gc.collect() at the "end" of the procedure. that should break all the cycles and deallocate all unreachable objects.
It will be run eventually anyway, but it's not always easy to predict when.
Usually, Python memory management is easy to predict--either something has a reference to the object, or it doesn't, and it gets deallocated. when cycles are involved, you get the same problem as with any other GC'd language--you don't know when the GC will run.

[cmlenz]

asmodai, how large would a zip of the svn exported directory be? How large is that directory itself?

I think this isn't a memory leak, but simply the nature of how zipfile works.

[asmodai@…]

The files that are created in snapshots are around 6MB:

$ ll -h

 7104 -rw-r--r--  1 root  trac  -      6M Nov 19 21:42 tendra-trunk_r783.zip
    2 -rw-r--r--  1 root  trac  -     55B Nov 19 21:42 tendra-trunk_r783.zip.md5
 7152 -rw-r--r--  1 root  trac  -      6M Nov 19 21:22 tendra-trunk_r785.zip
    2 -rw-r--r--  1 root  trac  -     55B Nov 19 21:22 tendra-trunk_r785.zip.md5
 7152 -rw-r--r--  1 root  trac  -      6M Nov 19 21:18 tendra-trunk_r807.zip
    2 -rw-r--r--  1 root  trac  -     55B Nov 19 21:18 tendra-trunk_r807.zip.md5

A checked out trunk would be around 74-75 MB. The zipfile's contents comes to:

$ du -sh tendra-trunk_r807 
 27M    tendra-trunk_r807

[cmlenz]

Change archive format to tar.bz2

[cmlenz]

Can you please check with the patch I just attached?

[asmodai@…]

Much better!

Initiating build of "tendra-trunk" on slave tendra
Prepared snapshot archive at /usr/local/trac/snapshots/tendra-trunk_r807.tar.bz2
Slave tendra started build 55 ("tendra-trunk" as of [807])

 7471 root         2   0 34040K 29420K poll     0:37 30.81% 30.81% python

But then when it created the next snapshot to test I get:

Step failed
Slave tendra completed build 55 ("tendra-trunk" as of [807]) with status FAILURE
Initiating build of "tendra-trunk" on slave tendra
Prepared snapshot archive at /usr/local/trac/snapshots/tendra-trunk_r785.tar.bz2
Slave tendra started build 35 ("tendra-trunk" as of [785])

 7471 root         2   0   519M   432M poll     1:54 51.56% 51.56% python

Which doesn't make sense given the first one's results. At least there seems to be some progress.

[cmlenz]

Well, it does make some sense, although it's still wrong.

The build master in trunk now attempts to build new archives based on already existing archives, only reading file contents from the repository if they have actually changed since the revision that the old archive was created from. This is done because I got reports about the archive creation taking extremely long, especially with large files in the repository. So the strategy was to simply copy everything over from a previous archive, and only read the files from the repository that actually changed.

So, the creation of the second archive is probably using a somewhat different code path than the creation of the first. Will need to look into this some more.

[cmlenz]

Disable incremental archive creation

[cmlenz]

I've added the same patch again, but this time with the incremental building of snapshot archives (as described in my previous comment) disabled. Can you please check that and report whether the memory usage normalizes? Then I can at least be sure what the problem is.

[asmodai@…]

This patchset keeps the memory use around 20-30 MB for 2 builds. So you're on the right track.

[cmlenz]

[356] explicitly removes some refs and closes a file-like object in the problematic code. If anyone can test whether this actually helps with the memory usage, that'd be great.

[joel@…]

I have just started evaluating Bitten, and it looks very promising as a replacement for Tinderbox. I am very eager to have it working well!

I'm using r363 from svn (which appears to include the patch attached here). I can confirm that the memory problem is not fixed.

After one snapshot was created, top shows:

32063 apache    14   0  416M 416M  3704 S     0.3 82.6   0:02 bitten-master

Stopping & restarting bitten-master, and restarting one slave, it uses only 8 megs.

  377 apache     9   0  8004 8004  2624 S     0.0  1.5   0:01 bitten-master

After the previously-generated snapshot is sent to the slave, 2 megs more are used:

  377 apache     9   0 10360  10M  3584 S     0.0  2.0   0:02 bitten-master

After committing a change to the repository, and generating another snapshot, the memory usage quickly skyrockets:

  377 apache    11   0  421M 421M  3728 S     0.0 83.8   0:04 bitten-master

My snapshot files are about 8 megs compressed.

Hope this helps. I'll help in whatever way I can, though I have never programmed in Python before.

[joel@…]

Going back to Bitten 0.5.3 seems to remedy the memory problem.

[TYatsurak@…]

The code in svn (r378) still has this problem.

[TYatsurak@…]

I guess not everybody has this problem, so I provide general environment info where leaks occur.

FedoraCore 6

Python 2.4.4 (#1, Oct 23 2006, 13:58:00)

[GCC 4.1.1 20061011 (Red Hat 4.1.1-30)] on linux2

svn, version 1.4.2 (r22196)

trac 0.10.3

Bitten r378

[cmlenz]

This code is no longer in use in the HTTP branch, which will be the basis for the next release.