[IronPython] Performance Issue

Wilfredo Lugo wilfredo.lugo at gmail.com
Thu Nov 13 15:12:13 CET 2008


Definitely is something on VS.  If I run the created application from
command line (inside the release folder) here is the output:
11/13/2008 10:08:26 AM
WARNING: desired starting time (Tue Jan 01 00:00:21 2008) prior to time of
first
 data point (Tue Jan 01 00:00:32 2008), current line: 9411
 series: 3D
force==False, exiting..
0
11/13/2008 10:08:31 AM

Since the issue is not with IronPython itself, I will look for answers on
other places.  Thanks for all your help.

regards,

Wilfredo

On Thu, Nov 13, 2008 at 9:59 AM, Wilfredo Lugo <wilfredo.lugo at gmail.com>wrote:

> Interesting thing.
> When I run the program on release mode without the profile the performance
> issue remains:
> 11/13/2008 9:50:19 AM
> WARNING: desired starting time (Tue Jan 01 00:00:21 2008) prior to time of
> first
>  data point (Tue Jan 01 00:00:32 2008), current line: 9411
>  series: 3D
> force==False, exiting..
> 0
> 11/13/2008 9:53:07 AM
>
> However, when I run the program using the VS profiler, this is what I get:
>
> 11/13/2008 9:55:31 AM
> WARNING: desired starting time (Tue Jan 01 00:00:21 2008) prior to time of
> firs
>  data point (Tue Jan 01 00:00:32 2008), current line: 9411
>  series: 3D
> force==False, exiting..
> 0
> 11/13/2008 9:55:35 AM
>
> Inside the profiler, the code is executed as in ipy.exe (near 4 seconds).
>  Why the execution using the profiler will run faster than in Release mode?
>  Since the profiler execution is normal, I don't think there is not much
> information I could provide.
>
> This is the latest code:
>
>         [STAThread]
>         static void Main(string[] args)
>         {
>             ScriptEngine engine = Python.CreateEngine();
>             ScriptSource source =
> engine.CreateScriptSourceFromFile("interpolate.py");
>             PythonCompilerOptions options = (PythonCompilerOptions)
> engine.GetCompilerOptions();
>             options.Module |= ModuleOptions.Optimized;
>             options.Module |= ModuleOptions.ModuleBuiltins;
>             Console.WriteLine(DateTime.Now);
>             CompiledCode compiled = source.Compile(options);
>             compiled.Execute();
>             ScriptScope scope = compiled.DefaultScope;
>             Microsoft.Func<string, string, string, string, int, int> func =
> scope.GetVariable<Microsoft.Func<string, string, string, string, int,
> int>>("interpolate_start");
>             Console.WriteLine(func("3-day-data.txt", "3-day-output.txt",
> "2008-01-01 00:00:21","2008-01-03 23:59:08",60).ToString());
>             Console.WriteLine(DateTime.Now);
>             Console.ReadLine();
>         }
>
>
> On Wed, Nov 12, 2008 at 11:16 PM, Dino Viehland <dinov at microsoft.com>wrote:
>
>>  I don't think either of those would cause such a large difference.  I/O
>> should be the same.  Two other differences I've noticed but again I wouldn't
>> expect them to matter.  The first is a lack of [STAThread] attribute on
>> Main.  The 2nd is you don't need the ScriptRuntime runtime =
>> Python.CreateRuntime(); call.  CreateEngine will create a runtime and return
>> you the Python engine associated with it.
>>
>>
>>
>> I'll try and take a look at the differences between the code we generate
>> for the two scenarios tomorrow to see if I can see anything that is
>> different.  If that doesn't I might need a repro or if you have a profiler
>> that would work well.  Given the huge difference in the runtimes 10-20
>> random stack traces during the running of the program might be enough to
>> figure it out.
>>
>>
>>
>> *From:* users-bounces at lists.ironpython.com [mailto:
>> users-bounces at lists.ironpython.com] *On Behalf Of *Wilfredo Lugo
>> *Sent:* Wednesday, November 12, 2008 3:24 PM
>>
>> *To:* Discussion of IronPython
>> *Subject:* Re: [IronPython] Performance Issue
>>
>>
>>
>> I set the ModuleBuiltins compiler option but the behavior is the same.
>>  The only difference from the command line is that I am calling a python
>> function from the DLR, and on the command line I am just calling the method
>> from __main__.  Do you think could be an issue?  The other thing is that the
>> python script relies heavily on I/O, input file is in the range of 18Mb and
>> the data is stored on another file.  Does the DLR handles I/O differently
>> than the command line?
>>
>>
>>
>> regards,
>>
>>
>>
>> wilfredo
>>
>> On Wed, Nov 12, 2008 at 5:39 PM, Dino Viehland <dinov at microsoft.com>
>> wrote:
>>
>> The only thing that immediately pops out at me as being different is we
>> also set ModuleOptions.ModuleBuiltins in the command line case – but I
>> wouldn't expect it to make such a large difference.  But try setting that
>> option as well and let's see what happens.
>>
>>
>>
>> *From:* users-bounces at lists.ironpython.com [mailto:
>> users-bounces at lists.ironpython.com] *On Behalf Of *Wilfredo Lugo
>> *Sent:* Wednesday, November 12, 2008 12:16 PM
>>
>>
>> *To:* Discussion of IronPython
>> *Subject:* Re: [IronPython] Performance Issue
>>
>>
>>
>> Thanks.  Performance improved, but still over two minutes.  Here is the
>> latest code:
>>
>>
>>
>>         static void Main(string[] args)
>>
>>         {
>>
>>             ScriptRuntime runtime = Python.CreateRuntime();
>>
>>             ScriptEngine engine = Python.CreateEngine();
>>
>>             ScriptSource source =
>> engine.CreateScriptSourceFromFile("interpolate.py");
>>
>>             PythonCompilerOptions options = (PythonCompilerOptions)
>> engine.GetCompilerOptions();
>>
>>             options.Module |= ModuleOptions.Optimized;
>>
>>             Console.WriteLine(DateTime.Now);
>>
>>             CompiledCode compiled = source.Compile(options);
>>
>>             compiled.Execute();
>>
>>             ScriptScope scope = compiled.DefaultScope;
>>
>>             Microsoft.Func<string, string, string, string, int, int> func
>> = scope.GetVariable<Microsoft.Func<string, string, string, string, int,
>> int>>("interpolate_start");
>>
>>             Console.WriteLine(func("3-day-data.txt", "3-day-output.txt",
>> "2008-01-01 00:00:21","2008-01-03 23:59:08",60).ToString());
>>
>>             Console.WriteLine(DateTime.Now);
>>
>>             Console.ReadLine();
>>
>>         }
>>
>>
>>
>> Output :
>>
>> 11/12/2008 4:10:10 PM
>>
>> WARNING: desired starting time (Tue Jan 01 00:00:21 2008) prior to time of
>> first
>>
>>  data point (Tue Jan 01 00:00:32 2008), current line: 9411
>>
>>  series: 3D
>>
>> force==False, exiting..
>>
>> 0
>>
>> 11/12/2008 4:12:45 PM
>>
>>
>>
>>
>>
>> On Wed, Nov 12, 2008 at 4:01 PM, Dino Viehland <dinov at microsoft.com>
>> wrote:
>>
>> Oh, sorry, I missed a step…  You'll need to call
>> ScriptEngine.GetCompilerOptions().  Cast that to a PythonCompilerOptions,
>> and then do options.Module |= ModuleOptions.Optimized;  Finally do
>> source.Compile(options) and then it should give you the optimized code.
>>
>>
>>
>> *From:* users-bounces at lists.ironpython.com [mailto:
>> users-bounces at lists.ironpython.com] *On Behalf Of *Wilfredo Lugo
>> *Sent:* Wednesday, November 12, 2008 11:45 AM
>>
>>
>> *To:* Discussion of IronPython
>> *Subject:* Re: [IronPython] Performance Issue
>>
>>
>>
>> Thanks!.
>>
>>
>>
>> I was able to get the default scope from CompiledCode, but I am still
>> getting the same performance.  Here is the latest code :
>>
>>         static void Main(string[] args)
>>
>>         {
>>
>>             ScriptRuntime runtime = Python.CreateRuntime();
>>
>>             ScriptEngine engine = Python.CreateEngine();
>>
>>             ScriptSource source =
>> engine.CreateScriptSourceFromFile("interpolate.py");
>>
>>             Console.WriteLine(DateTime.Now);
>>
>>             CompiledCode compiled = source.Compile();
>>
>>             compiled.Execute();
>>
>>             ScriptScope scope = compiled.DefaultScope;
>>
>>             Microsoft.Func<string, string, string, string, int, int> func
>> = scope.GetVariable<Microsoft.Func<string, string, string, string, int,
>> int>>("interpolate_start");
>>
>>             Console.WriteLine(func("3-day-data.txt", "3-day-output.txt",
>> "2008-01-01 00:00:21","2008-01-03 23:59:08",60).ToString());
>>
>>             Console.WriteLine(DateTime.Now);
>>
>>             Console.ReadLine();
>>
>>         }
>>
>>
>>
>> This is the latest output :
>>
>>    11/12/2008 3:13:01 PM
>>
>>    WARNING: desired starting time (Tue Jan 01 00:00:21 2008) prior to time
>> of first
>>
>>     data point (Tue Jan 01 00:00:32 2008), current line: 9411
>>
>>     series: 3D
>>
>>     force==False, exiting..
>>
>>     0
>>
>> 11/12/2008 3:16:41 PM
>>
>>
>>
>> Is there could be a problem on how I am calling the interpolation
>> function?  I mean from python.exe I do something like this:
>>
>>
>>
>> if __name__ == '__main__':
>>
>>    Interpolate('3-day-data.txt', '3-day-output-original.txt', '2008-01-01
>> 00:00:
>>
>> 21', '2008-01-03 23:59:08', intvl=60, maxgap = 5, stacked = True,
>> stackedCol = 2
>>
>> , tformat = '%Y-%m-%d %H:%M:%S', debug = False).start()
>>
>>
>>
>> To be able to call the script from the DLR I have something like this:
>>
>>
>>
>> def interpolate_start(inFile, outFile, startDate, endDate, intvl):
>>
>>    Interpolate(inFile, outFile,startDate,endDate,intvl, maxgap = 5,
>> stacked = Tr
>>
>> ue, stackedCol = 2, tformat = '%Y-%m-%d %H:%M:%S', debug = False).start()
>>
>>    return 0
>>
>>
>>
>> That's the only difference I found on how the script is called from python
>> and DLR.
>>
>>
>>
>> Any comments?
>>
>>
>>
>> regards,
>>
>>
>>
>> wilfredo
>>
>>
>>
>> On Wed, Nov 12, 2008 at 2:56 PM, Dino Viehland <dinov at microsoft.com>
>> wrote:
>>
>> CompiledCode exposes the default scope it executes in via the DefaultScope
>> property.  So hold onto the result of source.Compile and after executing the
>> code you can grab the scope and use it to get your variable.
>>
>>
>>
>> *From:* users-bounces at lists.ironpython.com [mailto:
>> users-bounces at lists.ironpython.com] *On Behalf Of *Wilfredo Lugo
>> *Sent:* Wednesday, November 12, 2008 10:25 AM
>> *To:* Discussion of IronPython
>>
>>
>> *Subject:* Re: [IronPython] Performance Issue
>>
>>
>>
>> Thanks.
>>
>>
>>
>> But then If I don't use my defined scope, how I could fill my function
>> delegate?
>>
>>
>>
>> Right now I am using :
>>
>>
>>
>> Microsoft.Func<string, string, string, string, int, int> func =
>> scope.GetVariable<Microsoft.Func<string, string, string, string, int,
>> int>>("interpolate_start");
>>
>>
>>
>> If I use engine.GetVariables<Func<....>() I still need to pass a
>> ScriptScope to it.  How do I get the default scope (from ScriptEngine or
>> ScriptSource) to be able to get the delegate?
>>
>>
>>
>> regards,
>>
>>
>>
>> wilfredo
>>
>> On Wed, Nov 12, 2008 at 2:01 PM, Dino Viehland <dinov at microsoft.com>
>> wrote:
>>
>> Instead of doing:
>>
>>
>>
>>             ScriptScope scope = engine.CreateScope();
>>
>>             Console.WriteLine(DateTime.Now);
>>
>>             source.Execute(scope);
>>
>>
>>
>> do:
>>
>>
>>
>>                 source.Compile().Execute()
>>
>>
>>
>> and your code should then run in an optimized default scope for the code –
>> just like it does at the command line.
>>
>>
>>
>> *From:* users-bounces at lists.ironpython.com [mailto:
>> users-bounces at lists.ironpython.com] *On Behalf Of *Wilfredo Lugo
>> *Sent:* Wednesday, November 12, 2008 9:29 AM
>> *To:* users at lists.ironpython.com
>> *Subject:* Re: [IronPython] Performance Issue
>>
>>
>>
>>
>>
>> I run the script directly from ipy.exe and it basically behaves pretty
>> similar to python.exe (it always took one second more, but I could live with
>> that).  Here is the output:
>>
>>
>>
>> $ date +%M:%S;./ipy.exe interpolate.py;date +%M:%S
>>
>> 17:36
>>
>> WARNING: desired starting time (Tue Jan 01 00:00:21 2008) prior to time of
>> first
>>
>>  data point (Tue Jan 01 00:00:32 2008), current line: 9411
>>
>>  series: 3D
>>
>> force==False, exiting..
>>
>> 17:41
>>
>>
>>
>> So, the problem is on the DLR side.  Any clues?
>>
>>
>>
>> -------------------------------------------------------------------------
>>
>> How does python.exe compare directly to ipy.exe?  That is, try running
>> "date +%M:%S;ipy.exe interpolate.py;date +%M:%S" instead of using the DLR
>> hosting APIs.
>>
>> Thanks,
>>
>>
>>
>> Dave
>>
>> From: users-bounces at lists.ironpython.com <http://lists.ironpython.com/listinfo.cgi/users-ironpython.com> [mailto:users-bounces at lists.ironpython.com <http://lists.ironpython.com/listinfo.cgi/users-ironpython.com>] On Behalf Of Wilfredo Lugo
>>
>> Sent: Wednesday, November 12, 2008 8:32 AM
>>
>> To: users at lists.ironpython.com <http://lists.ironpython.com/listinfo.cgi/users-ironpython.com>
>>
>> Subject: [IronPython] Performance Issue
>>
>>
>> _______________________________________________
>> 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
>>
>>
>>
>>
>> _______________________________________________
>> 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
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/ironpython-users/attachments/20081113/08f814f0/attachment.html>


More information about the Ironpython-users mailing list