[IronPython] weird performance issue

[Kamil Dworakowski]

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
>