Roslyn: Simple hello world script slow run with csi.exe

[hickford]

I wrote a simple 'hello world' script hello.csx

 Console.WriteLine("hello");

And ran it with C# Interactive csi.exe

csi hello.csx

It took several seconds to print hello. Measured with ptime Execution time: 4.854 s

What's going on? A hello world script in Python is much faster (less than 1 second)

I'm using

Microsoft (R) Visual C# Interactive Compiler version 1.2.0.60317

[hickford]

I also tried a script that threw an exception

 throw new Exception("boom");

[0xd4d]

Python 2.7: 0.03 s

csi 1.2: 0.45-0.47 s

Compiled C#: 0.02 s

csi is 15-16x slower than Python in this simple hello world script.

Python has probably been optimized to execute scripts. :smile: C# scripting is a nice feature they added, but it's not been optimized for fast execution of smaller scripts. The code gets parsed, IL code gets generated and written to an assembly, which is then loaded and finally executed. Also, at the moment, all generated assemblies are debug optimized. They'll probably add an option to change this to release optimization in some future version.

[tenor]

There are a bunch of spin-up and tear down tasks that the scripting engine has to do to execute a script, however, if you are executing a bunch of scripts after the spin up phase, it's actually pretty fast.

[leppie]

NGEN will probably help, IronScheme startup speeds up between 10 and 30 times with it. Slow JIT (especially the old 64-bit one) has always been a let down...

[ManishJayaswal]

We do have a workitem to speedup the very first evaluation.

[KevinH-MS]

Hi @hickford, >4 seconds seems really bad. As @leppie suggests, I would expect much better performance if csi.exe (and its dependencies) are ngen'ed. Can you check to make sure the VS install succeeded in doing that? If you type:

> ngen display csi

do you see the following?

Microsoft (R) CLR Native Image Generator - Version 4.6.1038.0
Copyright (c) Microsoft Corporation.  All rights reserved.

NGEN Roots:

C:\Program Files (x86)\MSBuild\14.0\Bin\csi.exe

NGEN Roots that depend on "csi":

C:\Program Files (x86)\MSBuild\14.0\Bin\csi.exe

Native Images:

csi, Version=1.2.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35

[leppie]

echo Console.WriteLine("hello world"); | csi

Takes less than a second for me. csi is NGEN'd.

Perhaps you just have a very slow machine?

[hickford]

Thanks for your replies. Curiously csi runs fine on my home computer Execution time: 0.404 s. I'll try again at work later and post the ngen output.

[hickford]

On work computer that's slow:

>"C:\Windows\Microsoft.NET\Framework64\v4.0.30319\ngen.exe" display csi
Microsoft (R) CLR Native Image Generator - Version 4.6.1055.0
Copyright (c) Microsoft Corporation.  All rights reserved.
Error: The specified assembly is not installed.

[hickford]

Aha! After running

>"C:\Windows\Microsoft.NET\Framework64\v4.0.30319\ngen.exe" install  "C:\Program Files (x86)\MSBuild\14.0\Bin\csi.exe"

Now csi is faster

Execution time: 1.386 s

[hickford]

Relevant?

>"C:\Windows\Microsoft.NET\Framework64\v4.0.30319\ngen.exe" queue status
Microsoft (R) CLR Native Image Generator - Version 4.6.1055.0
Copyright (c) Microsoft Corporation.  All rights reserved.

Service name is: clr_optimization_v4.0.30319_64
The .NET Runtime Optimization Service is stopped.

[leppie]

@hickford No, it normally runs on demand, but something might have skipped it.

[hickford]

Thanks for your help. fsi.exe also needed to be ngen'd and won a similar speed up. I'll close this issue.

[KevinH-MS]

Good to hear! I'm not sure exactly what may have happened to leave you in a state where ngen was queued but not executed (the Update 2 installer is supposed to ngen csi.exe with "priority 1", which means "execute immediately"). Running either "ngen eqi" or "ngen queue continue" should push things along.