[Mono-list] Mono runtime Garbage Collection behaviour

Hinne Hettema (DSL AK) HinneH@datacom.co.nz
Fri, 28 Jan 2005 15:33:40 +1300


Hi Mono list

I have a quick question regarding the garbage collection process in
mono. I have a small test case to play around with, and run this with

export GC_PRINT_STATS=3D1
export GC_FIND_LEAK=3D1

The latter flag lets the garbage collector work as a memory leak
detector.

The test program is a simple program straight out of applied Microsoft
.Net framework programming

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
using System;
using System.IO;

class GCTest {
        static void Main() {
                Byte[] bytesToWrite =3D new Byte[] {1,2,3,4,5};

                FileStream fs =3D null;
                try {
                        fs =3D new FileStream("temp.txt",
FileMode.Create);
                        fs.Write(bytesToWrite, 0, bytesToWrite.Length);
                }
                finally {
                        if (fs !=3D null)
                                ((IDisposable) fs).Dispose();
                }
                File.Delete("temp.txt");
        }
}
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D

When I run this test case I get output as follows

root@xxxxxx:/tmp/hinne# export GC_PRINT_STATS=3D1
root@xxxxxx:/tmp/hinne# export GC_FIND_LEAK=3D1
root@xxxxxx:/tmp/hinne# mono --debug GCTest.exe
Increasing heap size by 65536 after 0 allocated bytes
Initiating full world-stop collection 1 after 0 allocd bytes
--> Marking for collection 1 after 0 allocd bytes + 0 wasted bytes
Collection 0 finished ---> heapsize =3D 65536 bytes
World-stopped marking took 10 msecs
Complete collection took 10 msecs
Grew fo table to 1 entries
Increasing heap size by 65536 after 18968 allocated bytes
Grew fo table to 2 entries
Grew fo table to 4 entries
Grew fo table to 8 entries
Increasing heap size by 65536 after 41936 allocated bytes
Initiating full world-stop collection 2 after 43024 allocd bytes
--> Marking for collection 2 after 43024 allocd bytes + 16328 wasted
bytes
Collection 1 finished ---> heapsize =3D 196608 bytes
World-stopped marking took 10 msecs
Complete collection took 10 msecs
Leaked composite object at start: 0x810b000, appr. length: 8208
Leaked composite object at start: 0x8103e60, appr. length: 80
Leaked composite object at start: 0x8102fc0, appr. length: 24
Leaked composite object at start: 0x807ae80, appr. length: 16
Leaked composite object at start: 0x8071f00, appr. length: 24
Leaked composite object at start: 0x8070ff0, appr. length: 8
Leaked composite object at start: 0x8070ff8, appr. length: 8
Leaked composite object at start: 0x806fe40, appr. length: 152
Leaked composite object at start: 0x806e920, appr. length: 16
Leaked composite object at start: 0x806eb90, appr. length: 16
Leaked composite object at start: 0x806d900, appr. length: 48
Leaked composite object at start: 0x806d930, appr. length: 48
Leaked composite object at start: 0x806d960, appr. length: 48
Leaked composite object at start: 0x806d990, appr. length: 48
Leaked composite object at start: 0x806d9c0, appr. length: 48
Leaked composite object at start: 0x806d9f0, appr. length: 48
Leaked composite object at start: 0x806da20, appr. length: 48
Leaked composite object at start: 0x806da50, appr. length: 48
Leaked composite object at start: 0x806da80, appr. length: 48
Leaked composite object at start: 0x806dab0, appr. length: 48
Leaked composite object at start: 0x806dae0, appr. length: 48
Leaked composite object at start: 0x806db40, appr. length: 48
Leaked composite object at start: 0x806db70, appr. length: 48
Leaked composite object at start: 0x806dba0, appr. length: 48
Leaked composite object at start: 0x806dbd0, appr. length: 48
Leaked composite object at start: 0x806dc60, appr. length: 48
Leaked composite object at start: 0x806dc90, appr. length: 48
Leaked composite object at start: 0x806dcc0, appr. length: 48
Leaked composite object at start: 0x806dcf0, appr. length: 48
Leaked composite object at start: 0x806dd20, appr. length: 48
Leaked composite object at start: 0x806dd50, appr. length: 48
Leaked composite object at start: 0x806dd80, appr. length: 48
Leaked composite object at start: 0x806ddb0, appr. length: 48
Leaked composite object at start: 0x806dde0, appr. length: 48
Leaked composite object at start: 0x806de10, appr. length: 48
Leaked composite object at start: 0x806de70, appr. length: 48
Leaked composite object at start: 0x806df00, appr. length: 48
Leaked composite object at start: 0x806cb20, appr. length: 32
Leaked composite object at start: 0x806cb40, appr. length: 32
Leaked composite object at start: 0x806cb60, appr. length: 32
Initiating full world-stop collection 3 after 56 allocd bytes
--> Marking for collection 3 after 56 allocd bytes + 0 wasted bytes
Collection 2 finished ---> heapsize =3D 196608 bytes
World-stopped marking took 10 msecs
Complete collection took 10 msecs
Leaked composite object at start: 0x817ff80, appr. length: 128
Leaked composite object at start: 0x810eea0, appr. length: 312
Leaked composite object at start: 0x810af60, appr. length: 96
Leaked composite object at start: 0x8109f80, appr. length: 32
Leaked composite object at start: 0x8109fa0, appr. length: 32
Leaked composite object at start: 0x8109fc0, appr. length: 32
Leaked composite object at start: 0x8109fe0, appr. length: 32
Leaked composite object at start: 0x8107fe8, appr. length: 8
Leaked composite object at start: 0x8103b40, appr. length: 80
Leaked composite object at start: 0x8103b90, appr. length: 80
Leaked composite object at start: 0x8103be0, appr. length: 80
Leaked composite object at start: 0x8103c30, appr. length: 80
Leaked composite object at start: 0x8103c80, appr. length: 80
Leaked composite object at start: 0x8103cd0, appr. length: 80
Leaked composite object at start: 0x8103d20, appr. length: 80
Leaked composite object at start: 0x8103d70, appr. length: 80
Leaked composite object at start: 0x8103dc0, appr. length: 80
Leaked composite object at start: 0x8103e10, appr. length: 80
Leaked composite object at start: 0x8103eb0, appr. length: 80
Leaked composite object at start: 0x8102eb8, appr. length: 24
Leaked composite object at start: 0x8102ed0, appr. length: 24
Leaked composite object at start: 0x8102ee8, appr. length: 24
Leaked composite object at start: 0x8102f00, appr. length: 24
Leaked composite object at start: 0x8102f18, appr. length: 24
Leaked composite object at start: 0x8102f30, appr. length: 24
Leaked composite object at start: 0x8102f48, appr. length: 24
Leaked composite object at start: 0x8102f60, appr. length: 24
Leaked composite object at start: 0x8102f78, appr. length: 24
Leaked composite object at start: 0x8102f90, appr. length: 24
Leaked composite object at start: 0x8102fa8, appr. length: 24
Leaked composite object at start: 0x8101ed8, appr. length: 40
Leaked composite object at start: 0x8101f00, appr. length: 40
Leaked composite object at start: 0x8101f28, appr. length: 40
Leaked composite object at start: 0x8101f50, appr. length: 40
Leaked composite object at start: 0x8101f78, appr. length: 40
Leaked composite object at start: 0x8101fa0, appr. length: 40
Leaked composite object at start: 0x8100ee0, appr. length: 56
Leaked composite object at start: 0x8100f18, appr. length: 56
Leaked composite object at start: 0x8100f50, appr. length: 56
Leaked composite object at start: 0x80fff00, appr. length: 48

The operating system is Slackware, but I have observed similar behaviour
on Ubuntu, which is a 'version' of Debian.

The background to this problem is that we are deploying a large website
on mono for a customer, and have the server 'freeze' about 1-2 times a
day. At the freeze points mono takes up between 15-55% of memory on the
web server, typically consumes around 3% of CPU, and the website becomes
responsive again if the mono processes are restarted.

The server is a quad CPU machine running Slackware 10 with mono 1.0.5.
We seem to be heading towards a pattern in the freezes, which also
points to the possibility that there is something in crontab that could
interfere with mono.

My questions are:=20

1. Is the above behaviour for mono with this test case normal or
expected? Is this test case supposed to work on mono without the 'Leaked
composite object..' bits?
2. How much memory does mono 'normally' consume in a mod_mono / apache
congfiguration?
3. Are there known instances where other unix processes (such as log
rotation, backups, rsynchs) interfere with mono processes?

Any help would be appreciated.

Regards

Hinne