[IronPython] weird performance issue

[Dino Viehland]

Here's the simplest version of the fix, it's just updating one file so properties get their own call sites.

I'll work on a more involved fix that I'll get into 2.1 soon and probably into 2.0.1 a few days later.

Note this diff is from 2.1 but I've updated the names of things that have changed since 2.0.

File: Descriptors.cs
===================================================================
--- Descriptors.cs;C633889  (server)    12/17/2008 10:43 AM
+++ Descriptors.cs  (local)    12/17/2008 10:43 AM
@@ -21,6 +21,10 @@

 using IronPython.Runtime.Operations;
 using IronPython.Runtime.Types;
+using IronPython.Runtime.Binding;
+using Microsoft.Scripting.Actions;

 namespace IronPython.Runtime {
     [PythonType]
@@ -92,6 +96,7 @@
     [PythonType]
     public class PythonProperty : PythonTypeSlot {
         private object _fget, _fset, _fdel, _doc;
+        private CallSite<Func<CallSite, CodeContext, object, object, object>> _getSite;

         public PythonProperty() {
         }
@@ -177,7 +182,15 @@

         public new object __get__(CodeContext/*!*/ context, object instance, object owner) {
             if (instance == null) return this;
-            if (fget != null) return PythonCalls.Call(context, fget, instance);
+            if (_getSite == null) {
+                _getSite = CallSite<Func<CallSite, CodeContext, object, object, object>>.Create(
+                    new InvokeBinder(
+                        PythonContext.GetContext(context).DefaultBinderState,
+                        new CallSignature(1)
+                    )
+                );
+            }
+            if (fget != null) return _getSite.Target(_getSite, context, fget, instance);
             throw PythonOps.AttributeError("unreadable attribute");
         }



> -----Original Message-----
> From: users-bounces at lists.ironpython.com [mailto:users-
> bounces at lists.ironpython.com] On Behalf Of Kamil Dworakowski
> Sent: Wednesday, December 17, 2008 10:03 AM
> To: Discussion of IronPython
> Subject: Re: [IronPython] weird performance issue
>
> Thanks Dino, it looks like you are right. I print whenever
> _supportAdding == false.
> It happens a lot with the snippet executed, whereas it doesn't happen
> at all with
> the snippet commented out.
>
> We also discovered that the slow down only occurs when we compile code
> to dlls (no _supportAdding == false if runned from sources).
> Still can't come up with a repro though. If you provide us with a
> patch, we can
> test if it solves the problem in our code.
>
> As a short term solution we have removed all the properties from
> decorated functions. This fixed one performance test. We moved to
> other performance tests and we still see that some functions are
> slower when executed from dlls, so the same slow down might be
> triggered by sth else.
>
> On Wed, Dec 17, 2008 at 3:21 AM, Dino Viehland <dinov at microsoft.com>
> wrote:
> > My guess would be that we're pushing the PythonContext._callSplatSite
> outside of the sweet spot in DLR site caches.
> >
> > You could check this by putting a breakpoint in
> PythonContext.Call(object, params object[]).  Then look and see if
> _callSplatSite._rules is an instance of EmptyRuleSet<T> with
> _supportAdding == false.
> >
> > If this is the cause it should be pretty easy to fix - property's
> should probably get their own call site object so it'll be specialized
> to the specific property (maybe we could share a common one of the
> function is a PythonFunction as these generate highly shareable calls
> between multiple function instances).  We're also doing a params call
> today which we could stop doing and get a nice perf boost on
> properties.
> >
> >> -----Original Message-----
> >> From: users-bounces at lists.ironpython.com [mailto:users-
> >> bounces at lists.ironpython.com] On Behalf Of Kamil Dworakowski
> >> Sent: Tuesday, December 16, 2008 11:08 AM
> >> To: users at lists.ironpython.com
> >> Subject: [IronPython] weird performance issue
> >>
> >> We see a very strange side effect of running the follwing code on
> the
> >> performance of recalculations in Resolver One.
> >>
> >> def Dumbcorator(fn):
> >>     def _inner(self, *args):
> >>         return fn(self, *args)
> >>     return _inner
> >>
> >> class Locker(object):
> >>     @property
> >>     @Dumbcorator
> >>     def thing(self):
> >>         return 2
> >>
> >> l = Locker()
> >> l.thing
> >>
> >> Specifically, one of the performance test reports results 4 to 8
> times
> >> worse with this snippet in than without (the clock is turned on
> after
> >> this snippet executes). If I comment out this snippet from the code,
> >> it suddenly runs 4 to 8 times faster. The fact that I can comment it
> >> out means that it is not used in the test, so it is bizzare that it
> >> slows it down.
> >>
> >> We can't reproduce the slow down in a clean example though. I hope
> >> something clicks for somebody and gives me a hint as to what is
> going
> >> on. Tomorrow I'll continue on trying to minimize the code that is
> >> being slowed down, and hopefully come up with some decent repro.
> >> _______________________________________________
> >> Users mailing list
> >> Users at lists.ironpython.com
> >> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
> > _______________________________________________
> > Users mailing list
> > Users at lists.ironpython.com
> > http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
> >
> _______________________________________________
> Users mailing list
> Users at lists.ironpython.com
> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com