[IronPython] Bad performance calling .NET method

[Dino Viehland]

Is the perf problem only there when the code is global?  In general we don't try to optimize code which occurs at the top-level of a script - we assume the most significant work will occur inside of function definitions.  In this case the update to "i" through each loop iteration needs to update a global value in a dictionary rather than updating a local on the stack each time which is going to be much more expensive.  Also the reads from the globals instead of parameters will be much more expensive as well.  And while I doubt this is much of the perf problem you're also accessing the Unicode property on encoding each time through in the global case.  There's also the chance depending on what version of IronPython you're running on that we're staying in the interpreter.  I think on 2.6.1 we should compile the global loop eventually but it'll still be slower than the compiled function.

Is there a reason the top-level code needs to be efficient?

From: users-bounces at lists.ironpython.com [mailto:users-bounces at lists.ironpython.com] On Behalf Of Laurion Burchall
Sent: Tuesday, April 20, 2010 11:57 AM
To: Discussion of IronPython
Subject: Re: [IronPython] Bad performance calling .NET method

You were right about the structs. By creating a method with the same type of signature (struct, struct, string, Encoding, enumeration). I got the same slowdown in a trivial DLL. This is with the .NET 2.0 version of IP:

** First, the C# code:

namespace IronPythonInteropPerf
{
    using System.Text;

    public struct Struct1
    {
        internal int i;
    }

    public struct Struct2
    {
        internal int i;
    }

    public enum Enumeration
    {
        Foo,
    }

    public static class Interop
    {
        public static void A(Struct1 a, Struct2 b, string x, Encoding encoding, Enumeration e)
        {
        }
    }
}

** Now the IronPython test:

import System
import System.Diagnostics
import System.Text

from System.Diagnostics import Stopwatch
from System.Text import Encoding

import clr
clr.AddReferenceByPartialName('IronPythonInteropPerf')
from IronPythonInteropPerf import *

N = 1000000

a = Struct1()
b = Struct2()
c = 'hello'
d = Enumeration.Foo

stopwatch = Stopwatch.StartNew()
for i in xrange(N):
    Interop.A(a, b, c, Encoding.Unicode, d)
stopwatch.Stop()
print '    A: %s' % stopwatch.Elapsed

def foo(a1, a2, a3, a4, a5):
    stopwatch = Stopwatch.StartNew()
    for j in xrange(N):
        Interop.A(a1, a2, a3, a4, a5)
    stopwatch.Stop()
    print 'foo.A: %s' % stopwatch.Elapsed

foo(a, b, c, Encoding.Unicode, d)

** Note that I am calling Interop.A twice. This gives very different results -- the call from inside of function foo() is fast (11M calls/second) but the call from the script is slow (50K calls/second):

    A: 00:00:18.6063353
foo.A: 00:00:00.0894888

There isn't a caching effect at work either -- foo() is faster if I call it before the other code.
________________________________
From: users-bounces at lists.ironpython.com [users-bounces at lists.ironpython.com] on behalf of Dino Viehland [dinov at microsoft.com]
Sent: Tuesday, April 20, 2010 11:34 AM
To: Discussion of IronPython
Subject: Re: [IronPython]Bad performance calling .NET method
I assume something is going horribly wrong with our type checks.   Can you attach the repro?  Or at least are these just classes, or are any structs, or maybe weird classes like delegates?

And is this on .NET 2.0 or .NET 4.0?

From: users-bounces at lists.ironpython.com [mailto:users-bounces at lists.ironpython.com] On Behalf Of Laurion Burchall
Sent: Tuesday, April 20, 2010 2:11 AM
To: Discussion of IronPython
Subject: [IronPython] Bad performance calling .NET method

I am getting terrible performance invoking a C# method from IP. I have a static class called Api with this method:

  public static void MakeKey(JET_SESID sesid, JET_TABLEID tableid, string data, Encoding encoding, MakeKeyGrbit grbit)

When I call it directly from C# I get about 3M calls/second. In IronPython I get only 50,000 calls/second -- a 60X slowdown!

The method is overloaded. When I call these overloads I get good performance (~ 1M calls/second):
  public static void MakeKey(JET_SESID sesid, JET_TABLEID tableid, int data, MakeKeyGrbit grbit)
  public static void MakeKey(JET_SESID sesid, JET_TABLEID tableid, float data, MakeKeyGrbit grbit)
  public static void MakeKey(JET_SESID sesid, JET_TABLEID tableid, byte[] data, MakeKeyGrbit grbit)
(for the last overload I passed in the string turned into a byte array with Encoding.GetBytes())

Things I have tried that didn't help:
 - Changing the name of the method so it was unique.
 - Calling the method using Api.MakeKey.Overloads[...]
 - Calling other methods I have that take string arguments. They were fast.

When I profile the code the time shows up in mscorwks.dll (56%) and mscorlib.ni.dll (17%). IronPython is only 8% and my code is 6%.

Can anyone help me work out what is going wrong? I have a short, turn-key repro of this. MakeKey is a very commonly used method so having it be so slow is crippling.

thanks,
--Laurion


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/ironpython-users/attachments/20100420/8b0ba407/attachment.html>