[darcs-users] Re: [BK] upgrade will be needed

Ralph Corderoy ralph at inputplus.co.uk
Sat Feb 26 23:02:09 UTC 2005


Hi David,

> > Perhaps, on Linux, just saving the contents of /proc/$darcspid/maps
> > at 1Hz whilst darcs takes a minute to do its thing would give enough
> > information to find out what to monitor next.
> 
> Attached are the results on the darcs repository from three runs:
> 
> darcs get localhost:darcs /tmp/foo &
> darcs check --no-test &
> darcs optimize --checkpoint &
> pid=$!
> while kill -0 $pid; do
>     cat /proc/$pid/maps
>     echo
>     date
>     sleep 1
> done >/tmp/darcs.maps

I'll attach the lumps of shell script that I used to analyse in case
they're useful for others to understand exactly what's been measured or
use again next time.

Of the three commands run, only `darcs get' gave a /proc/self/maps that
changed over time as far as the 1Hz snapshots saw.

    Command       Number readings        Unique readings
    check               37                      1
    checkpoint          21                      1
    get                196                    110

Summing up the regions with a device of 00:00 is a quick way of totting
up the memory that isn't backed by files.  If a snapshot has the same
sum as its predecessor it isn't shown.

    check.000 999424
    checkpoint.000 999424

So both these allocate the same, 999424 bytes, or 976KiB exactly.
`darcs get', however, goes through spurts of changing with quiet
periods, shown by a gap in the get.??? snapshot numbers.  The third
column is the difference compared to the previous sum for that command.

    get.000     94208
    get.001   1310720  1216512
    get.019   2359296  1048576
    get.023   4456448  2097152
    get.067   5505024  1048576
    get.068  10747904  5242880
    get.069  17039360  6291456
    get.075  18087936  1048576
    get.079  18210816   122880
    get.080  18112512   -98304
    get.128  18374656   262144
    get.129  18112512  -262144
    get.141  18243584   131072
    get.143  18112512  -131072
    get.145  18239488   126976
    get.148  18112512  -126976
    get.158  18116608     4096
    get.159  18243584   126976
    get.160  18374656   131072
    get.164  18505728   131072
    get.165  18636800   131072
    get.171  18767872   131072
    get.172  20865024  2097152
    get.178  21913600  1048576
    get.186  22962176  1048576
    get.192  23224320   262144   [maximum]
    get.193  22306816  -917504

23224320 bytes, the maximum, is 22,680KiB exactly.

The stack appears to be contiguous and end at 0xc0000000.  Summing just
those and showing changes gives

    check.000 20480
    checkpoint.000 20480
    get.000 8192
    get.001 24576 16384

So `darcs get' needs more, but it's too piddling to be concerned over, 24KiB.

As pointed out in an earlier email, maps shows the same pathname, but
with a different inode number, mapped multiple times, e.g. 18.

     18 get.072 /tmp/foo/Patch.lhs
     10 get.195 /tmp/foo/ChangeLog
     10 get.151 /tmp/foo/External.hs

In message-id <20050225130736.GF12342 at abridgegame.org>, from another
thread, David wrote:
> It's reasonable if the garbage collector hasn't run recently.  Darcs
> only unmaps files on GC, and when a file gets modified, darcs creates
> a new inode and then (when it wants to read the modified version)
> mmaps the file again.
> 
> It may be that we should trigger the GC manually to ensure that
> mmapped files are released in a timely manner, but on the other hand,
> we don't want to waste time garbage collecting if we can avoid it.

Does darcs ever want to read that old version again?  I guess not,
because it doesn't exist by pathname anymore, only by an inode with zero
links.  Is it not possible in Haskell to say `GC this one thing', or do
you always have to say `OK, scour around and GC whatever you want'?
Is there the option of having Haskell not manage the item at all and to
manually allocate and deallocate it like in the good old days?  What do
you mean by `waste time'?

Without wishing to offend anyone, but coming from a background of being
hired to examine performance issues, I find the lack of control over
resources for the programmer, coupled with my lack of understanding
about what RTS will do and when, frustrating.  It's irksome that these
unused things just sit there for a while.  The language may GC them but
meanwhile they're influencing other areas of the machine that don't know
they're no longer needed.  Not much, in this case, maybe, but it still
causes new inodes to be allocated because old ones haven't yet been
freed, for example.  Those inodes are still hanging onto file contents
that means that disc space can't be re-used and other areas have to be
allocated, etc.

The benefits of Haskell, and other GC languages, may be many, including
speeding development of darcs's algorithms, but given darcs's
implementation pushes both CPU time and memory I wonder if future
darcs-compatible SCMs will be possible in other, more portable,
languages like C once the development has slowed down and the hard
work's been done.  That's if anyone can understand David's achievement!
:-)

Anyway, going back to the size and changes in non-file-backed regions in
the maps given above, there's some of interest.  These two

    get.128  18374656   262144
    get.129  18112512  -262144

show one snapshot increasing by 256KiB and the next decreasing by the
same.  Here's the first change in detail.

    = get.127 get.128
    3c3
    < 08293000-082c5000 rw-p 08293000 00:00 0 
    ---
    > 08293000-08305000 rw-p 08293000 00:00 0 
    5a6,17
    > b7472000-b747a000 r--s 00000000 03:01 834496     /tmp/foo/darcs.lhs
    > b747a000-b7482000 r--s 00000000 03:01 834516     /tmp/foo/DarcsArguments.lhs
    > b7482000-b748a000 r--s 00000000 03:01 834488     /tmp/foo/darcs.lhs
    > b748a000-b7492000 r--s 00000000 03:01 834412     /tmp/foo/darcs.lhs
    > b7492000-b7498000 r--s 00000000 03:01 834512     /tmp/foo/ChangeLog
    > b7498000-b749e000 r--s 00000000 03:01 834431     /tmp/foo/Repository.lhs
    > b749e000-b74a6000 r--s 00000000 03:01 834495     /tmp/foo/DarcsArguments.lhs
    > b74a6000-b74ac000 r--s 00000000 03:01 834407     /tmp/foo/ChangeLog
    > b74ac000-b74b1000 r--s 00000000 03:01 834462     /tmp/foo/ChangeLog
    > b74b1000-b74b9000 r--s 00000000 03:01 834369     /tmp/foo/DarcsArguments.lhs
    > b74b9000-b74c1000 r--s 00000000 03:01 834453     /tmp/foo/DarcsArguments.lhs
    > b74c1000-b74c9000 r--s 00000000 03:01 834384     /tmp/foo/darcs.lhs

The increase in non-file-backed memory was accompanied by 12 files being
mapped.  The decrease has the same region shrinking to its old start and
end addresses.  The 12 new files are also axed, along with some that
have sneaked in between snapshots, and been replaced by a couple of
others.

    = get.128 get.129
    3c3
    < 08293000-08305000 rw-p 08293000 00:00 0 
    ---
    > 08293000-082c5000 rw-p 08293000 00:00 0 
    6,21c6,7
    < b7472000-b747a000 r--s 00000000 03:01 834496     /tmp/foo/darcs.lhs
    < b747a000-b7482000 r--s 00000000 03:01 834516     /tmp/foo/DarcsArguments.lhs
    < b7482000-b748a000 r--s 00000000 03:01 834488     /tmp/foo/darcs.lhs
    < b748a000-b7492000 r--s 00000000 03:01 834412     /tmp/foo/darcs.lhs
    < b7492000-b7498000 r--s 00000000 03:01 834512     /tmp/foo/ChangeLog
    < b7498000-b749e000 r--s 00000000 03:01 834431     /tmp/foo/Repository.lhs
    < b749e000-b74a6000 r--s 00000000 03:01 834495     /tmp/foo/DarcsArguments.lhs
    < b74a6000-b74ac000 r--s 00000000 03:01 834407     /tmp/foo/ChangeLog
    < b74ac000-b74b1000 r--s 00000000 03:01 834462     /tmp/foo/ChangeLog
    < b74b1000-b74b9000 r--s 00000000 03:01 834369     /tmp/foo/DarcsArguments.lhs
    < b74b9000-b74c1000 r--s 00000000 03:01 834453     /tmp/foo/DarcsArguments.lhs
    < b74c1000-b74c9000 r--s 00000000 03:01 834384     /tmp/foo/darcs.lhs
    < b74c9000-b74ce000 r--s 00000000 03:01 834500     /tmp/foo/SelectChanges.lhs
    < b74ce000-b74d3000 r--s 00000000 03:01 834377     /tmp/foo/Record.lhs
    < b74d3000-b74db000 r--s 00000000 03:01 834352     /tmp/foo/DarcsArguments.lhs
    < b74db000-b74e0000 r--s 00000000 03:01 834393     /tmp/foo/Apply.lhs
    ---
    > b74b9000-b74c0000 r--s 00000000 03:01 834416     /tmp/foo/Repository.lhs
    > b74c0000-b74e0000 r--s 00000000 03:01 834494     /tmp/foo/Patch.lhs

I guess that's GC at work since I'd assume that malloc's area isn't
shrinked if the end of the arena becomes free.  Perhaps a Haskellian can
confirm that the RTS will shrink a mmap'd region?

This grow/shrink accompanied by a churn in files mapped is repeated
elsewhere, e.g.

    get.141  18243584   131072
    get.143  18112512  -131072

Other than that, I don't think you can tell which of the regions are
mapped by RTS and which by libc because of malloc.  libc's happy to map
a new region if the old one can't expand due to mapped files getting in
the way.  RTS's bound to do the same.

So, I don't think this has answered the question "How much memory's
allocated by all the C code, including libraries, versus RTS?", but it's
shed a little light, for me at least, and seems to give one way to
snapshot memory usage.

The other way is to strace all the relevant system calls and keep track
of non-file-backed regions.  That's what the attached Perl script
attempts, although it's had hardly any testing.  Perhaps one of the
people more keen on Perl would give it the once over?  Usage can be
something like

    bash$ strace -e trace=old_mmap,mmap2,munmap -o >(./mmappeak) \
    bash>     darcs whatsnew >/dev/null    
    ignored: --- SIGVTALRM Virtual timer expired ---
    2412544
    $

It prints the highest number of bytes it saw allocated to
non-file-backed regions.  It rounds all allocations up to the nearest
whole page, 4KiB.  Hopefully, the strace overhead isn't too much of a
problem.

Cheers,


Ralph.

-------------- next part --------------
# Ensure David's *.maps are in the cwd.

# Delete the dates, they break the uniformity of the data.
perl -i -ne '/ 2005$/ or print' *.maps

# Delete the blank line at the end of the file to avoid the empty file
# from csplit.
perl -0777 -i -pe 's/\n\Z//s' *.maps

# Make looping over test data easier.
tests=$(ls *.maps | sed 's/\.maps$//')

# Place each /proc/*/maps reading into a separate file and give the
# number of samples.
echo == number of readings
for f in $tests; do
    csplit -f $f. -n 3 -s $f.maps '/^$/' '{*}'
    ls $f.[0-9][0-9][0-9] | wc -l | sed "s/^/$f /"
done

# Delete the blank lines, they break the uniformity of the data.
perl -i -lne 'length and print' *.[0-9][0-9][0-9]

# Summarise the number of lines in each file.
false && for t in $tests; do
    for f in $t.[0-9][0-9][0-9]; do
        printf '%-20s %d\n' $t $(wc -l <$f)
    done
done |
uniq -c

# Show the number of unique readings for each test.
echo == unique readings
for t in $tests; do
    md5sum $t.[0-9][0-9][0-9] |
    sed 's/ .*//' |
    uniq -c |
    wc -l |
    sed "s/^/$t /"
done

# Show non-file-backed memory usage for each snapshot.
echo == sum of 00:00 maps
for t in $tests; do
    for f in $t.[0-9][0-9][0-9]; do
        grep ' 00:00 ' $f |
        sed 's/^\(........\)-\(........\) .*/s += \2 - \1/' |
        (echo ibase=16; tr a-f A-F; echo s) |
        bc -l |
        sed "s/^/$f /"
    done |
    awk '
        NR > 1 { d = $2 - s; $0 = $0 " " d }
        { s = $2 }
        NR == 1 || d
    '
done

# Stack size and change.
echo == stack size
for t in $tests; do
    for f in $t.[0-9][0-9][0-9]; do
        grep '^........-c0000000 ' $f |
        sed 's/^\(........\)-\(........\) .*/s += \2 - \1/' |
        (echo ibase=16; tr a-f A-F; echo s) |
        bc -l |
        sed "s/^/$f /"
    done |
    awk '
        NR > 1 { d = $2 - s; $0 = $0 " " d }
        { s = $2 }
        NR == 1 || d
    '
done

# A repository file can be mapped more than once at the same time.
echo == duplicate file mappings
for t in $tests; do
    for f in $t.[0-9][0-9][0-9]; do
        sed -n 's at .* \(/tmp/foo/\)@\1 at p' $f |
        sed "s/^/$f /"
    done |
    sort |
    uniq -c |
    awk '$1 > 1' |
    sort -nr
done

# diff each pair of readings.
echo == diff pairs
for t in $tests; do
    ls $t.[0-9][0-9][0-9] |
    awk 'NR > 1 { print l, $0 } { l = $0 }' |
    while read old new; do
        cmp -s $old $new && continue
        echo = $old $new
        diff $old $new
    done
done
-------------- next part --------------
#! /usr/bin/perl

$PAGE_SIZE = 4 * 1024;
$map = '';
$peak = 0;

while (<>) {
    chomp;
    y/(,) / /s;

    @f = split;
    if ($f[0] =~ /^(?:old_mmap|mmap2)$/) {
        &add(@f[8, 2, 5]);
        ($s = &sum_map()) > $peak and $peak = $s;
    } elsif ($f[0] eq 'munmap') {
        &del(@f[4, 1, 2]);
    } else {
        warn "ignored: $_\n";
    }
}
print $peak * $PAGE_SIZE, "\n";

exit;

sub add
{
    my($addr, $len, $fd) = @_;

    $addr =~ /^0/ and $addr = oct $addr;
    $addr == -1 and return;
    $fd != -1 and return;    # Only want non-file regions.

    &alter_map($addr, $len, 1);
}

sub del
{
    my($ret, $addr, $len) = @_;

    $addr =~ /^0/ and $addr = oct $addr;
    $ret != 0 and return;

    &alter_map($addr, $len, 0);
}

sub alter_map
{
    my($start, $len, $datum) = @_;
    my($end, $p);

    $start /= $PAGE_SIZE;
    $len = int(($len + $PAGE_SIZE - 1) / $PAGE_SIZE);
    for ($p = $start, $end = $start + $len; $p < $end; $p++) {
        vec($map, $p, 1) = $datum;
    }
}

sub sum_map
{
    return unpack("%32b*", $map);
}


More information about the darcs-users mailing list