[IronPython] Performance of IronPython 2 Beta 4 and IronPython 1

[Michael Foord]

It looks like I've found the slowdown in our execution framework. It is 
caused by extra overhead in the IronPython engine API.

If I created a compiled code object and execute it in a module with 
IronPython 1 a million times (code shown below) - it takes 1.5 seconds.

The equivalent (please check the code in case it *isn't* the equivalent) 
takes 115 seconds in IronPython 2!

IP1 code:
from System import DateTime
import clr
clr.AddReference('IronPython')
from IronPython.Hosting import PythonEngine
   
engine = PythonEngine()
engine.DefaultModule.Globals['__name__'] = '__main__'
module = engine.DefaultModule

code = 'a = 3\nb = a\n'
compiled = engine.Compile(code, 'module')

def test(s):
    for i in xrange(1000000):
        compiled.Execute(module)
    return (DateTime.Now - s).TotalMilliseconds
   
print test(DateTime.Now)



Equivalent for IronPython 2:

from System import DateTime
import clr
clr.AddReference('Microsoft.Scripting')
clr.AddReference('Microsoft.Scripting.Core')
from System.Scripting import SourceCodeKind
from Microsoft.Scripting.Hosting import ScriptRuntime

runtime = ScriptRuntime.Create()
engine = runtime.GetEngine("py")
scope = engine.CreateScope()

scope.SetVariable('__name__', '__main__')

code = 'a = 3\nb = a\n'
source = engine.CreateScriptSourceFromString(code, 
SourceCodeKind.Statements)
compiled = source.Compile()

def test(s):
    for i in xrange(1000000):
        compiled.Execute(scope)
    return (DateTime.Now - s).TotalMilliseconds
   
print test(DateTime.Now)


If there is a better way to do this in IP 2 then please let me know... :-)

Michael


Michael Foord wrote:
> Hello all,
>
> I've ported Resolver One to run on IronPython 2 Beta 4 to check for 
> any potential problems (we will only do a *proper* port once IP 2 is 
> out of beta).
>
> The basic porting was straightforward and several bugs have been fixed 
> since IP 2 B3 - many thanks to the IronPython team.
>
> The good news is that Resolver One is only 30-50% slower than Resolver 
> One on IronPython 1! (It was 300 - 400% slower on top of IP 2 B3.) 
> Resolver One is fairly heavily optimised around the performance 
> hotspots of IronPython 1, so we expect to have to do a fair bit of 
> profiling and refactoring to readjust to the performance profile of IP 2.
>
> Having said that, there are a few oddities (and the areas that slow 
> down vary tremendously depending on which spreadsheet we use to 
> benchmark it - making it fairly difficult to track down the hotspots).
>
> We have one particular phase of spreadsheet calculation that takes 
> 0.4seconds on IP1 and around 6 seconds on IP2, so I have been doing 
> some micro-benchmarking to try and identify the hotspot. I've 
> certainly found part of the problem.
>
> For those that are interested I've attached the very basic 
> microbenchmarks I've been using. The nice thing is that in *general* 
> IP2 does outperform IP1.
>
> The results that stand out in the other direction are:
>
> Using sets with custom classes (that define '__eq__', '__ne__' and 
> '__hash__') seems to be 6 times slower in IronPython 2.
>
> Adding lists together is about 50% slower.
>
> Defining functions seems to be 25% slower and defining old style 
> classes about 33% slower. (Creating instances of new style classes is 
> massively faster though - thanks!)
>
> The code I used to test sets (sets2.py) is as follows:
>
> from System import DateTime
>
> class Thing(object):
>    def __init__(self, val):
>        self.val = val
>      def __eq__(self, other):
>        return self.val == other.val
>
>    def __neq__(self):
>        return not self.__eq__(other)
>          def __hash__(self):
>        return hash(self.val)
>             def test(s):
>    a = set()
>    for i in xrange(100000):
>        a.add(Thing(i))
>        a.add(Thing(i+1))
>        Thing(i) in a
>        Thing(i+2) in a
>    return (DateTime.Now -s).TotalMilliseconds
>   s = DateTime.Now
> print test(s)
>
>
> Interestingly the time taken is exactly the same if I remove the 
> definition of '__hash__'.
>
> The full set of results below:
>
> Results in milliseconds with a granularity of about 15ms and so an 
> accuracy of +/- ~60ms.
> All testing with 10 000 000 operations unless otherwise stated.
>
> Empty loop (overhead):
>    IP1: 421.9
>    IP2: 438
>   Create instance newstyle:
>    IP1: 20360
>    IP2: 1109
>   Create instance oldstyle:
>    IP1: 3766
>    IP2: 3359
>   Function call:
>    IP1: 937
>    IP2: 906
>   Create function: 25% slower
>    IP1: 2828
>    IP2: 3640
>   Define newstyle (1 000 000):
>    IP1: 42047
>    IP2: 20484
>   Define oldstyle (1 000 000): 33% slower
>    IP1: 1781
>    IP2: 2671
>
> Comparing (== and !=):
>    IP1: 278597
>    IP2: 117662
>   Sets (with numbers):
>    IP1: 37095
>    IP2: 30860
>
> Lists (10 000): 50% slower
>    IP1: 10422
>    IP2: 16109
>
> Recursion (10 000):
>    IP1: 1125
>    IP2: 1000
>  
> Sets2 (100 000): 600% slower
>    IP1: 4984
>    IP2: 30547
>
>
> I'll be doing more as the 600% slow down for sets and the 50% slow 
> down for lists accounts for some of the dependency analysis problem 
> but not all of it.
>
> Many Thanks
>
> Michael Foord
> -- 
> http://www.resolversystems.com
> http://www.ironpythoninaction.com
>
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Users mailing list
> Users at lists.ironpython.com
> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com


-- 
http://www.ironpythoninaction.com/
http://www.voidspace.org.uk/
http://www.trypython.org/
http://www.ironpython.info/
http://www.resolverhacks.net/
http://www.theotherdelia.co.uk/