3

I have very simple trivial C# code compiled to .NET exe assmebly:

using System;
class Program
{
    public static void Main()
    {
        Console.WriteLine("test");
    }
}

The compiled assembly runs on my desktop Windows 8.1 machine for about 0.02 seconds every time, but on the production Windows Server 2012 R2 it runs for 1.05 seconds.

Here is the PowerShell I am testing with:

$sw = [Diagnostics.Stopwatch]::StartNew()
for ($i=1; $i -le 10; $i++)
{
    .\cs.exe
}
$sw.Stop()
$sw.Elapsed

Output on my local machine:

TotalMinutes      : 0.00391715666666667
TotalSeconds      : 0.2350294
TotalMilliseconds : 235.0294

.NET versions on my local machine:

PSChildName                                                 Version
-----------                                                 -------
v2.0.50727                                                  2.0.50727.4927
v3.0                                                        3.0.30729.4926
Windows Communication Foundation                            3.0.4506.4926
Windows Presentation Foundation                             3.0.6920.4902
v3.5                                                        3.5.30729.4926
Client                                                      4.5.51641
Full                                                        4.5.51641
Client                                                      4.0.0.0

Output on the server:

TotalMinutes      : 0.172228565
TotalSeconds      : 10.3337139
TotalMilliseconds : 10333.7139

.NET version on server:

PSChildName                                                 Version
-----------                                                 -------
Client                                                      4.5.51650
Full                                                        4.5.51650
Client                                                      4.0.0.0

Environment variables on server:

Name                           Value
----                           -----
ALLUSERSPROFILE                C:\ProgramData
APPDATA                        C:\Users\*********\AppData\Roaming
CLIENTNAME                     *********
CommonProgramFiles             C:\Program Files\Common Files
CommonProgramFiles(x86)        C:\Program Files (x86)\Common Files
CommonProgramW6432             C:\Program Files\Common Files
COMPUTERNAME                   *********
ComSpec                        C:\Windows\system32\cmd.exe
COR_ENABLE_PROFILING           7
COR_PROFILER                   {8019fee9-9590-4bd4-b2c9-815628f80f0f}
CORECLR_ENABLE_PROFILING       0
FP_NO_HOST_CHECK               NO
HOMEDRIVE                      C:
HOMEPATH                       \Users\*********
JAVA_HOME                      C:\Progra~1\Java\jdk1.8.0_45
LOCALAPPDATA                   C:\Users\*********\AppData\Local
LOGONSERVER                    \\*********
NUMBER_OF_PROCESSORS           12
OS                             Windows_NT
Path                           C:\ProgramData\Oracle\Java\javapath;C:\Windows\system32;C:\Windows;C:\Windows\System3...
PATHEXT                        .COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.CPL
PROCESSOR_ARCHITECTURE         AMD64
PROCESSOR_IDENTIFIER           Intel64 Family 6 Model 63 Stepping 2, GenuineIntel
PROCESSOR_LEVEL                6
PROCESSOR_REVISION             3f02
ProgramData                    C:\ProgramData
ProgramFiles                   C:\Program Files
ProgramFiles(x86)              C:\Program Files (x86)
ProgramW6432                   C:\Program Files
PSModulePath                   C:\Users\*********\Documents\WindowsPowerShell\Modules;C:\Program Files\WindowsPow...
PUBLIC                         C:\Users\Public
SESSIONNAME                    RDP-Tcp#126
SystemDrive                    C:
SystemRoot                     C:\Windows
TEMP                           C:\Users\ACADWE~1\AppData\Local\Temp\2
TMP                            C:\Users\ACADWE~1\AppData\Local\Temp\2
USERDOMAIN                     *********
USERDOMAIN_ROAMINGPROFILE      *********
USERNAME                       *********
USERPROFILE                    C:\Users\*********
windir                         C:\Windows

What can cause this slowness of 1 second?

Is the JIT compiler the problem?

Is there any CLR-related service that should be ran in the server?

Are there any application validation checks that can be disabled?

This problem happens only to .NET exe files. Simple executables compiled with C++ run for 0.01 seconds

Edit:

I've tried to run ngen.exe ExecuteQueuedItems as suggested in the comments but nothing changed. Here is the result from the command:

PS C:\Windows\system32> C:\Windows\Microsoft.NET\Framework\v4.0.30319\ngen.exe ExecuteQueuedItems
Microsoft (R) CLR Native Image Generator - Version 4.0.30319.33440
Copyright (c) Microsoft Corporation.  All rights reserved.
All compilation targets are up to date.
Nikolay Kostov
  • 16,433
  • 23
  • 85
  • 123
  • What makes you think this is a meaningful benchmark at all? – fk2 Jul 13 '15 at 15:02
  • @fk2 The times are persistent and the differences are huge. :) – Nikolay Kostov Jul 13 '15 at 15:03
  • "How to Ask. Is your question about programming? We prefer questions that can be answered, not just discussed. Provide details. Share your research." Unfortunately, this question does not appear to be about programming, but about a specific environment. Also, there is nigh anything that we could do to reproduce the issue you are experiencing. – maxwellb Jul 13 '15 at 15:08
  • 1
    Its not meaningful because its a single run. Run it in a loop a few thousand times and ignore the first run value (during jitting), I'm sure the values will be very similar. – Ron Beyer Jul 13 '15 at 15:08
  • The question is related to /NET CLR and its execution (probably related to JIT compiler/app verification or something similar). It is 100% related to programming. – Nikolay Kostov Jul 13 '15 at 15:09
  • @NikolayKostov So? Your benchmark doesn't really do anything unless you determine whether or not the perfomance hit scales. On a program like this it's a big deal but on a program that runs for 30 minutes the one second additional loading time is meaningless. And your benchmark doesn't even determine if the performance hit is loading time or execution time – fk2 Jul 13 '15 at 15:10
  • 1
    @RonBeyer Note that the initial jitting may actually be part of the problem here - the question is about the whole process from start to stop, not just the actual .net code that's running. – James Thorpe Jul 13 '15 at 15:10
  • @JamesThorpe, yes I believe so. I guess even ignoring the first run won't do it, it jits every time you run it. – Ron Beyer Jul 13 '15 at 15:12
  • @Ron Beyer, I've edited my tests with loop that iterates 10 times and the results are the same (view my edited question). – Nikolay Kostov Jul 13 '15 at 15:13
  • 1
    @NikolayKostov I'm sure your problem is related to the jitting process on the server and having to do with verification as you said, but if you think you are going to be running this a lot, why not turn it into a long-running service? Or you can ngen the assembly. – Ron Beyer Jul 13 '15 at 15:15
  • @Ron Beyer, I am executing client executables tens of times every second so every penalty to the running time is a huge problem in my case. – Nikolay Kostov Jul 13 '15 at 15:17
  • Both the server and local machine are on 0% CPU load. And as I mentioned in the question *This problem happens only to .NET exe files. Simple executables compiled with C++ run for 0.01 seconds* – Nikolay Kostov Jul 13 '15 at 15:23
  • 1
    @NikolayKostov then try ngen: https://msdn.microsoft.com/en-us/library/6t9t5wcf(v=vs.110).aspx – Ron Beyer Jul 13 '15 at 15:28
  • 1
    Sounds like the *framework* is not ngened. No need to ngen the main method. It's just one method, takes 1ms to JIT. Run ngen. `executequeueditem` or whatever it is called. – usr Jul 13 '15 at 15:42
  • @usr tried it but still no luck. See my edited question. – Nikolay Kostov Jul 13 '15 at 16:09
  • 1
    It could be a certificate check. Did you Authenticode sign your exe and are you running < .NET 4.0 and has your server no internet connection? If yes check this out: http://stackoverflow.com/questions/19766914/disabling-certificate-revocation-checking-for-an-application-on-windows – Alois Kraus Jul 13 '15 at 16:21
  • @Alois Kraus, thank you but it didn't help – Nikolay Kostov Jul 13 '15 at 16:27
  • Are you having some environment variable set like COM_PLUSxxxx. Some profilers set these variables which can cause it to dismiss all ngenned binaries. If yes delete these variables from your user and system Environment. – Alois Kraus Jul 14 '15 at 03:33
  • No variable like `COM_PLUSxxxx` was found in environment variables list. See my full list in the edited question. – Nikolay Kostov Jul 14 '15 at 07:27

1 Answers1

2

I have found the problem.

It seemed that the server had dotMemory installed.

Also there were the following environment variables set:

COR_ENABLE_PROFILING           7
COR_PROFILER                   {8019fee9-9590-4bd4-b2c9-815628f80f0f}
CORECLR_ENABLE_PROFILING       0

After uninstalling dotMemory and deleting these environment variables everything is working as expected (0.02 seconds per C# application run)

Nikolay Kostov
  • 16,433
  • 23
  • 85
  • 123
  • And of course thank you all for the help in comments! :) – Nikolay Kostov Jul 14 '15 at 07:37
  • 1
    These variables are set in order to run IIS or windows service under profiling. Also dotMemory uses it in mode "profile any .net process". It seems that you terminated dotMemory process during profiling and, of course, it did not clean these variables up. There is a clean up tool, supplied with dotMemory, CleanUpProfiler.x64(x86).exe. Also if you ran profiling session once again and allowed dotMemory finishing normally, it cleaned up these variables as well. – Ed Pavlov Jul 16 '15 at 07:28
  • I knew it was a profiler ;-). I wonder how you can actually find bugs with such stuff if the profiler itself makes things so much slower. Did you find the issue with the profiler? ;-) – Alois Kraus Jul 17 '15 at 18:01
  • Ed.ward explained the problem more precisely :) – Nikolay Kostov Jul 18 '15 at 07:30