[Mono-devel-list] Mono performance problem

[Paolo Molaro]

On 02/20/04 Namit Dhameja wrote:
> We recently ported our server code to Linux (Mono) from Windows
> (MS.Net). The problem is that there is a huge performance hit. A
> particular transcation on MS.Net takes ~2sec, on Mono the same takes
> around ~10-12ms.

Wow, mono is 200 times faster? :-)
Anyway: there are still many areas of mono that have not yet been
optimized, we appreciate reports about particular workloads in which we
are significantly slower than the MS runtime. Please tell us aolaso
which version of Mono you're using.

> To find out the reason I ran Mono with '--profile' option and got
> a 510KB file. If you know of any software (UI)  which would take this
> file and give me some sort of easily digestable information that would
> be really appreciated.

Sadly there is no GUI yet to look at the profiling data: we hope to
provide one for our 1.0 release, but nobody volunteered yet:-)
At the top of the file you'll find the list of methods where most of the
time has been spent. It looks like this:

Time(ms) Count   P/call(ms) Method name
########################
 47863.442       1  47863.442   .T::Main(object,intptr,intptr)
  Callers (with count) that contribute at least for 1%:
########################
 47861.575       1  47861.575   .T::Main()
  Callers (with count) that contribute at least for 1%:
           1  100 % .T::Main(object,intptr,intptr)
########################
 26721.975       1  26721.975   .T::use_activator()
  Callers (with count) that contribute at least for 1%:
           1  100 % .T::Main()
########################
 26245.512 1000000    0.026   System.Activator::CreateInstance(Type)
  Callers (with count) that contribute at least for 1%:
     1000000  100 % .T::use_activator()
########################
 25663.816 1000000    0.026
System.Activator::CreateInstance(Type,bool)
  Callers (with count) that contribute at least for 1%:
     1000000  100 % System.Activator::CreateInstance(Type)
########################
 22373.921 2000000    0.011
System.Reflection.ConstructorInfo::Invoke(object[])
  Callers (with count) that contribute at least for 1%:
     1000000  50 % System.Activator::CreateInstance(Type,bool)
     1000000  50 % .T::use_ctor()

For each method you get how many milliseconds were spent in all the
invocations of that method, how many times it was called and the mean
invocation time for call. You also get a list of the callers with a
count of how many times each caller called the method.
In this example, ConstructorInfo::Invoke(object[]) was called 2000000
times, 1000000 from the T::use_ctor() method and 1000000 from the
Activator::CreateInstance(Type,bool) method.
We can also see that roughly half of the time in the benchmark run as
spent inside ConstructorInfo::Invoke(object[]) (22 seconds out of 48
seconds): this means that method probably needs some speedups in mono...

So, given the above info, you can try to look at the data and report
where most of time is spent. Or you can send me the file in private
email and I'll try to sumamrize it and see if there are obvious spots in
mono that need improvement.
If you can distribute the source of your app we can try and run with
profiling ourself, otherwise, please provide us the data from the
profiler or, given the data, send us possibly small programs that
execute the same kind of code, so we can try and optimize their
execution.
Thanks!

lupus

-- 
-----------------------------------------------------------------
lupus at debian.org                                     debian/rules
lupus at ximian.com                             Monkeys do it better