[C#] { } sneller dan zonder?

[Phyxion]

Ik ben op het moment wat bezig met opschonen, en ik kwam iets tegen in dit stukje code

C#:

int count;
while ((count= stream.Read(buffer, 0, BUFFER_SIZE)) > 0)
{
   for (int i = 0; i < count; i++)
   {
       // bla
   }
}

vs

C#:

int count;
while ((count= stream.Read(buffer, 0, BUFFER_SIZE)) > 0)
{
   for (int i = 0; i < count; i++)   
       // bla
}

bla is 1 regel aan code, niet relevant hier wat dat is, maar na wat timingtests blijkt dat met { } sneller is dan zonder. Iemand enig idee waardoor dit komt? Ik had al wat gezocht op Google maar ik kon er eigenlijk niks over vinden. Ik heb dit diverse malen getest en iedere keer dezelfde uitkomst.

[Soultaker]

Tja, het komt natuurlijk op precies hetzelfde neer, dus er is geen reden waarom het ene sneller zou zijn dan het andere.

Begin eens met het dumpen van de gegenereerde bytecode voor beide programma's (ildasm)? Als die hetzelfde is (wat je zou verwachten) dan wordt de code ook exact hetzelfde uitgevoerd door de .NET runtime, en dan zit er dus een fout in je testmethodiek.

[Verwijderd]

ik neem aan dat er in plaats van "// bla" wel *iets* staat?

anders loopt hij alleen bij her eerste voorbeeld

[Phyxion]

Soultaker schreef op zaterdag 30 mei 2009 @ 16:36:
Tja, het komt natuurlijk op precies hetzelfde neer, dus er is geen reden waarom het ene sneller zou zijn dan het andere.

Begin eens met het dumpen van de gegenereerde bytecode voor beide programma's (ildasm)? Als die hetzelfde is (wat je zou verwachten) dan wordt de code ook exact hetzelfde uitgevoerd door de .NET runtime, en dan zit er dus een fout in je testmethodiek.

Die kende ik nog niet, even de functie vergeleken maar de code is niet hetzelfde. Er is eigenlijk vrij weinig verschil behalve twee nop's die extra zijn bij de brackets.
Ik heb het nog een aantal malen getest maar het is echt sneller met de nops en met de brackets dus. Het scheelt te veel om in een foutcorrectie marge te zitten, het scheelt iets van 25%, iedere keer weer.

Verwijderd schreef op zaterdag 30 mei 2009 @ 16:42:
ik neem aan dat er in plaats van "// bla" wel *iets* staat?

anders loopt hij alleen bij her eerste voorbeeld

Ja er staat wel iets hoor bij // bla, er gebeuren hier aantal berekeningen op getallen.

[ Voor 14% gewijzigd door Phyxion op 30-05-2009 16:47 ]

[RayNbow]

C#:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;

namespace ScopeTest
{
    class Program
    {
        static void Main(string[] args)
        {
            NoScope();
            Scope();
        }

        private static void Scope()
        {
            for (int j = 0; j < 10; j++)
            {
                Console.WriteLine("Scope" + j);
            }
        }

        private static void NoScope()
        {
            for (int i = 0; i < 10; i++)
                Console.WriteLine("No scope" + i);
        }
    }
}

ILDASM:

code:

.method private hidebysig static void  NoScope() cil managed
{
  // Code size       41 (0x29)
  .maxstack  2
  .locals init ([0] int32 i,
           [1] bool CS$4$0000)
  IL_0000:  nop
  IL_0001:  ldc.i4.0
  IL_0002:  stloc.0
  IL_0003:  br.s       IL_001f
  IL_0005:  ldstr      "No scope"
  IL_000a:  ldloc.0
  IL_000b:  box        [mscorlib]System.Int32
  IL_0010:  call       string [mscorlib]System.String::Concat(object,
                                                              object)
  IL_0015:  call       void [mscorlib]System.Console::WriteLine(string)
  IL_001a:  nop
  IL_001b:  ldloc.0
  IL_001c:  ldc.i4.1
  IL_001d:  add
  IL_001e:  stloc.0
  IL_001f:  ldloc.0
  IL_0020:  ldc.i4.s   10
  IL_0022:  clt
  IL_0024:  stloc.1
  IL_0025:  ldloc.1
  IL_0026:  brtrue.s   IL_0005
  IL_0028:  ret
} // end of method Program::NoScope

code:

.method private hidebysig static void  Scope() cil managed
{
  // Code size       43 (0x2b)
  .maxstack  2
  .locals init ([0] int32 j,
           [1] bool CS$4$0000)
  IL_0000:  nop
  IL_0001:  ldc.i4.0
  IL_0002:  stloc.0
  IL_0003:  br.s       IL_0021
  IL_0005:  nop
  IL_0006:  ldstr      "Scope"
  IL_000b:  ldloc.0
  IL_000c:  box        [mscorlib]System.Int32
  IL_0011:  call       string [mscorlib]System.String::Concat(object,
                                                              object)
  IL_0016:  call       void [mscorlib]System.Console::WriteLine(string)
  IL_001b:  nop
  IL_001c:  nop
  IL_001d:  ldloc.0
  IL_001e:  ldc.i4.1
  IL_001f:  add
  IL_0020:  stloc.0
  IL_0021:  ldloc.0
  IL_0022:  ldc.i4.s   10
  IL_0024:  clt
  IL_0026:  stloc.1
  IL_0027:  ldloc.1
  IL_0028:  brtrue.s   IL_0005
  IL_002a:  ret
} // end of method Program::Scope

Debug build.

[Invisible_man]

Met die twee nop's (no operation) zou het juist langer moeten duren, bij een nop doet hij een clockcycle niets namelijk. Wat ik me nog kan bedenken is dat door het ontbreken van die brackets variabelen ook buiten de for loop gelden en daardoor meer overhead tijd vraagt van de garbage collector enzo, maar dat is meer een "idee" van mij dan een feit.

[Phyxion]

Invisible_man schreef op zaterdag 30 mei 2009 @ 16:51:
Met die twee nop's (no operation) zou het juist langer moeten duren, bij een nop doet hij een clockcycle niets namelijk. Wat ik me nog kan bedenken is dat door het ontbreken van die brackets variabelen ook buiten de for loop gelden en daardoor meer overhead tijd vraagt van de garbage collector enzo, maar dat is meer een "idee" van mij dan een feit.

Dat dacht ik ook, bij nop skipt ie alleen maar. Ik heb er voor de grap ook nog eens een profiler bijgepakt en die geeft ook hetzelfde beeld weer (Ook dat ie de stream size in bytes aantal over de brackets heen gaat). Heel apart aangezien ik ook had verwacht dat C# dat intern wel wegoptimaliseerd als je bijvoorbeeld

C#:

for (int i = 0; i < 10; i++)
{
  Console.WriteLine(i);
}

het intern wel om zou zetten naar

C#:

for (int i = 0; i < 10; i++)
  Console.WriteLine(i);}

[RayNbow]

Invisible_man schreef op zaterdag 30 mei 2009 @ 16:51:
Wat ik me nog kan bedenken is dat door het ontbreken van die brackets variabelen ook buiten de for loop gelden[...]

Nee, de variabelen bestaan niet buiten de for loop.

(Ik zie nu trouwens dat ik de 2 functies beter Block en NoBlock had kunnen noemen )

[CoolGamer]

Invisible_man schreef op zaterdag 30 mei 2009 @ 16:51:
Met die twee nop's (no operation) zou het juist langer moeten duren, bij een nop doet hij een clockcycle niets namelijk. Wat ik me nog kan bedenken is dat door het ontbreken van die brackets variabelen ook buiten de for loop gelden en daardoor meer overhead tijd vraagt van de garbage collector enzo, maar dat is meer een "idee" van mij dan een feit.

Zoals aangegeven is dit een debug-versie. Mogelijk zitten die nop's erin zodat je op die regels een breakpoint kan zetten.

[Invisible_man]

RayNbow schreef op zaterdag 30 mei 2009 @ 16:55:
[...]

Nee, de variabelen bestaan niet buiten de for loop.

(Ik zie nu trouwens dat ik de 2 functies beter Block en NoBlock had kunnen noemen )

Dat leek mij ook, was ook meer een brainstorm idee

[Phyxion]

Net even nieuw project gemaakt en opnieuw compiled, als ik het nu op Release bouw zijn beide versies hetzelfde, met het oude project verschillen ze met nops (Ook op Release). Hoe dan ook blijft het vreemd dat met nop sneller is dan zonder.

[ Voor 198% gewijzigd door Phyxion op 30-05-2009 17:07 ]

[RobIII]

quote: http://msdn.microsoft.com/en-us/library/aa289509.aspx

Debugging and nop Instructions

Visual Basic .NET allows you to set breakpoints on non-executing lines of code such as End If, End Sub, and Dim statements. To facilitate this popular debugging technique, the compiler inserts nop instructions as placeholders for the non-executing lines of code (since non-executing lines are not translated into IL instructions). The nop instruction is a "no operation" instruction—it does not perform any meaningful work yet can consume a processing cycle.

You can observe this if you launch Visual Studio .NET, create a new Visual Basic .NET application, compile it using the default Debug configuration, and then view the assembly with the MSIL Disassembler (Ildasm.exe).

code:

.method public static void  Main() cil managed
{
  .entrypoint
  .custom instance void [mscorlib]System.STAThreadAttribute::.ctor() = ( 01 00 00 00 ) 
  // Code size       14 (0xe)
  .maxstack  8
  IL_0000:  nop
  IL_0001:  ldstr   "Hello World"
  IL_0006:  call    void [mscorlib]System.Console::WriteLine(string)
  IL_000b:  nop
  IL_000c:  nop
  IL_000d:  ret
} // end of method Module1::Main

By default, the Visual Basic .NET compiler (vbc.exe) does not generate nop instructions. They are only generated when the /debug option for the compiler is explicitly set, which is exactly what the Debug configuration in Visual Studio .NET does. When you compile using the Release configuration in Visual Studio .NET, the /debug option is not used so the nop instructions are not generated.

In contrast, the C# compiler does not produce as many nop instructions even when compiling with the /debug option. Since the Visual Basic .NET and C# compilers do not behave equivalently when used with the /debug option, you should compile using the Release configuration mode when comparing compilers, especially for performance comparisons.

Dat is het enige betekenisvolle dat ik er zo snel over kan vinden maar verklaart nog steeds niet waarom het sneller zou zijn mét NOP's

[ Voor 3% gewijzigd door RobIII op 30-05-2009 17:10 ]

[Soultaker]

Ah, dat verklaart inderdaad het verschil in gegenereerde bytecode.

@TS: benchmark je wel de release builds? (Of hoe werkt dat precies in .NET?)

[Herko_ter_Horst]

Zit het verschil niet in je meetmethode? Hoe meet je? Hoe vaak heb je het experiment herhaald? Hoe groot is het verschil eigenlijk?

Gaat dit over het inladen van een file? Is het verschil niet te verklaren uit het al dan niet in de filesystem cache zitten van die file?

[whoami]

Hoe benchmark je ?

Doe eens eerst NoScope, en daarna Scope ...
Volgens mij heeft dit gewoon te maken met het feit dat de JIT bij het opstarten nog even werk heeft ....

[BugBoy]

Ik verwacht niet dat die haken het verschil gaan maken. Die vallen al weg in het parse-proces, dus daar weet de code generator waarschijnlijk niets meer van. Haal ze eens weg in Scope en ik denk dat je hetzelfde resultaat krijgt. Overigens zou ik release mode gaan testen. Lijkt me wat meer realistisch.

[Phyxion]

Herko_ter_Horst schreef op zaterdag 30 mei 2009 @ 18:16:
Zit het verschil niet in je meetmethode? Hoe meet je? Hoe vaak heb je het experiment herhaald? Hoe groot is het verschil eigenlijk?

Gaat dit over het inladen van een file? Is het verschil niet te verklaren uit het al dan niet in de filesystem cache zitten van die file?

Gewoon met een timer, DateTime.Now - vorige DateTime.Now Verder heel vaak herhaalt, iedere keer hetzelfde resultaat. Verschil ligt tussen de 20 en 25%. Onder release build is het nu wel hetzelfde, maar debug build nog steeds hetzelfde, vind het heel raar dat dat door een paar nops komt.

[RobIII]

C#:

using System;
using System.Diagnostics;

namespace ConsoleApplication1
{
    class Program
    {
        static void Main(string[] args)
        {
            const int measurements = 10;
            const int iterations = 100000000;

            Stopwatch sa = new Stopwatch();
            Stopwatch sna = new Stopwatch();

            for (int l = 0; l < measurements; l++)
            {
                //With accolades
                sa.Reset();
                sa.Start();
                for (int i = 0; i < iterations; i++)
                {
                    Math.Sin(Math.Cos(i));
                }
                sa.Stop();

                //Without accolades
                sna.Reset();
                sna.Start();
                for (int i = 0; i < iterations; i++)
                    Math.Sin(Math.Cos(i));
                sna.Stop();

                Trace.WriteLine(
                    string.Format("With accolades: {0}, without: {1}. Winner: {2} (Difference: {3})",
                    sa.ElapsedTicks,
                    sna.ElapsedTicks,
                    sa.ElapsedTicks > sna.ElapsedTicks ? "Without" : "With",
                    Math.Abs(sa.ElapsedTicks - sna.ElapsedTicks))
                );
            }
        }
    }
}

Output (Release mode):

With accolades: 700906185, without: 700149690. Winner: Without (Difference: 756495)
With accolades: 700437132, without: 703174752. Winner: With (Difference: -2737620)
With accolades: 700127136, without: 700321617. Winner: With (Difference: -194481)
With accolades: 701027973, without: 700240257. Winner: Without (Difference: 787716)
With accolades: 700198497, without: 702466893. Winner: With (Difference: -2268396)
With accolades: 701066196, without: 700391556. Winner: Without (Difference: 674640)
With accolades: 700194897, without: 701030781. Winner: With (Difference: -835884)
With accolades: 700373961, without: 700319403. Winner: Without (Difference: 54558)
With accolades: 701689743, without: 701044803. Winner: Without (Difference: 644940)
With accolades: 700753014, without: 700402473. Winner: Without (Difference: 350541)

Output (Debug mode):

With accolades: 835360947, without: 811710432. Winner: Without (Difference: 23650515)
With accolades: 837613278, without: 810627120. Winner: Without (Difference: 26986158)
With accolades: 838503945, without: 813787245. Winner: Without (Difference: 24716700)
With accolades: 837426222, without: 815839443. Winner: Without (Difference: 21586779)
With accolades: 834574581, without: 810887022. Winner: Without (Difference: 23687559)
With accolades: 834683697, without: 809994681. Winner: Without (Difference: 24689016)
With accolades: 836210412, without: 812255859. Winner: Without (Difference: 23954553)
With accolades: 834788529, without: 810610353. Winner: Without (Difference: 24178176)
With accolades: 839362311, without: 814297347. Winner: Without (Difference: 25064964)
With accolades: 834458130, without: 813483153. Winner: Without (Difference: 20974977)

So far lijkt de verklaring van MS dus te kloppen... Ik ben toch wel benieuwd naar de exacte code van Phyxion...

[ Voor 28% gewijzigd door RobIII op 30-05-2009 20:47 . Reden: Inderdaad even Stopwatch gebruikt. ]

[whoami]

Phyxion schreef op zaterdag 30 mei 2009 @ 19:22:
[...]

Gewoon met een timer, DateTime.Now - vorige DateTime.Now Verder heel vaak herhaalt, iedere keer hetzelfde resultaat. Verschil ligt tussen de 20 en 25%. Onder release build is het nu wel hetzelfde, maar debug build nog steeds hetzelfde, vind het heel raar dat dat door een paar nops komt.

StopWatch gebruiken om te meten ....

[Data-base]

RobIII schreef op zaterdag 30 mei 2009 @ 17:09:
[...]

Dat is het enige betekenisvolle dat ik er zo snel over kan vinden maar verklaart nog steeds niet waarom het sneller zou zijn mét NOP's

De bytecode wordt nog heel hard geoptimaliseerd door de JIT-compiler. Steker nog, bijna alle optimalisaties worden door de JIT compiler gedaan, en zijn dus niet zichtbaar in de bytecode.

Je zou eens met ngen echte native assemblies moeten doorstippen en kijken hoe en wat.

[Zoijar]

RobIII schreef op zaterdag 30 mei 2009 @ 17:09:
Dat is het enige betekenisvolle dat ik er zo snel over kan vinden maar verklaart nog steeds niet waarom het sneller zou zijn mét NOP's

Wellicht door andere alignment

[RobIII]

Zoijar schreef op zondag 31 mei 2009 @ 00:48:
[...]

Wellicht door andere alignment

Hmm, makes (some) sense. Maar zou dat dan zo veel schelen? Ik heb nu geen tijd maar het zou inderdaad helpen native images naast elkaar te leggen in zo'n geval, hoewel ik niet weet of NOP's in zo'n geval misschien nog wel "weggecompileerd" worden...

[ Voor 32% gewijzigd door RobIII op 31-05-2009 03:11 ]