Subject: RE: Performance Problem: malloc() is calling madvise()
To: None <current-users@netbsd.org>
From: Bill Dorsey <dorsey@lila.lila.com>
List: current-users
Date: 05/19/2000 12:39:58
Hi,

David Brownlee wrote:
> 	(Reply-to set to current-users as netbsd-ports is for porting to
> 	new platforms)
>
Apologies for posting to the wrong group...
 
> 	What happens if you set MALLOC_OPTIONS to 'h' in the environment
> 	with the new libc?
>
I tried this.  Performance improves significantly but my
application still runs 14% slower than it did with the old libc
(from 1.4.2_Alpha) so there is still something not right
about it.  I tried ktrace again, however, and noted that
madvise() is no longer being called.

In order to track down what's impacting performance, I tried
compiling with '-pg' and ran the program.  In the past, I
have had problems with core-dumps on programs I compiled with
profiling, but perhaps this has been fixed as it worked this
time!  :-)  Anyway, with the old libc (libc.so.40), malloc
eats 9.1% of my application's CPU.  With the new libc (libc.so.61),
malloc eats 37.5% of my application's CPU.  That's with
MALLOC_OPTIONS set to 'h'.

Here's the output from gprof:

libc.so.40:

index % time    self  children    called     name
                0.00    0.00       1/5125        new_eh_context [25]
                0.00    0.00       1/5125        __smakebuf [26]
                0.00    0.00    5123/5125        __builtin_new [11]
[7]      9.1    0.00    0.00    5125         malloc [7]
                0.00    0.00    5125/5126        imalloc <cycle 1> [29]
                0.00    0.00       1/1           malloc_init [28]

libc.so.61:

index % time    self  children    called     name
                                                 <spontaneous>
[1]     37.5    0.00    0.00                 __builtin_new [1]
                0.00    0.00    5123/5125        malloc [3]


> On Fri, 19 May 2000, Bill Dorsey wrote:
> 
> > Hi,
> > 
> > I upgraded to the 20000505 snapshot yesterday (1.4Y) and noticed
> > a serious performance loss when running one of my programs.
> > 
> > The program I was running is a number-crunching program that
> > uses malloc() pretty heavily (via the C++ new function).
> > Between the 1.4.2_Alpha release I was running and the 1.4Y
> > release I upgraded to, the program slowed down by a factor
> > of 4 on my Personal Workstation!!!
> > 
> > Looking at top, I had my first clue as to what the problem
> > was.  It was showing about 33% of the CPU time being spent
> > running my program and 66% of the time in the system.  I
> > proceeded to run a ktrace on the program and was rewarded
> > with data at the rate of more than 1 megabyte per second
> > being written to ktrace.out!
> > 
> > After stopping the ktrace, I ran kdump to see what was going
> > on.  The madvise() system call was being called millions of
> > times per second from what I could see.
> > 
> > Investigating further, I discovered that madvise() is called
> > by malloc in libc.so.  When I switched the libc.so with an
> > older version (from 1.4.2_Alpha), the performance returned to
> > normal.
> > 
> > If this hasn't been fixed in -current, I'd be pleased if someone
> > would look into it.  I don't understand why you'd want to make
> > a system call in malloc() anyway given the obvious performance
> > implications so I assume this is in error.
> > 
> > In the meantime, I have noticed no ill effects from replacing
> > the libc.so file with the older one from 1.4.2_Alpha and I'll
> > continue to do so until this is addressed.
> > 
> > --
> > Bill Dorsey
> > 
> > 
>