Analysis compiled MSIL (Part 2)
This is a follow-up article to the (Analysis compiled MSIL (Part 1)) I thought I would explore the whole concept of how the compiler works, and what is generated by different languages. I thought I would explore how to optimize the code using the common objects provided by the .NET framework.
The Concept
The applications from the previous article were updated to make use of the .NET framework's StringBuilder class. This was primarily done to illustrate the efficiency of this class of performing string concatenations. It has often been suggested to use the string builder class to do string concatenation work, but I wondered whether anybody had actually seen the proof of efficiency this class offers.
Some additional optimization techniques followed in this article are to deal with the VB application. These techniques/tests include changing the default module, supplied by VS.NET to a class just to see if the compiler sees a difference between the two classes. I also changed a couple of the project settings.
- Although not an optimization technique, but more of a test to see if there is actually any difference between classes and modules in the VB compiler, I decided to change the default declaration of Module1 from Module to Class
- Removed integer overflow checks in Project properties compile tab(This can be found under advanced settings)
- Switched Option Strict on
To really test these optimizations, I thought I would let both the methods run together, and print out to the console, the length of time each took to process just to compare how long each took. I thought I would also change one item in each of the old applications, and change the declarations of the "strSomeString" variable from supplying an empty quotes i.e "" to using the .NET framework's string.empty. This was primarily to see what was generated by the compiler.
The Code
VB
<code>Imports System.Diagnostics
Class Module1
Shared Sub Main()
Dim sbSomeString As New System.Text.StringBuilder
Dim sw As New Stopwatch
sw.Start()
For i As Integer = 0 To 1000
sbSomeString.Append("Test ")
Next
sw.Stop()
Console.WriteLine(sbSomeString.ToString)
Console.WriteLine("Time Taken :" & sw.ElapsedMilliseconds)
OldCode()
End Sub
Shared Sub OldCode()
Dim strSomeString As String = String.Empty
Dim sw As New Stopwatch
sw.Start()
For i As Integer = 0 To 1000
strSomeString += "Test "
Next
sw.Stop()
Console.WriteLine(strSomeString)
Console.WriteLine("Time Taken :" & sw.ElapsedMilliseconds)
Console.ReadLine()
End Sub
End Class
C#
<code>using System;
using System.Diagnostics;
namespace ConsoleCSharp
{
class Program
{
static void Main(string[] args)
{
System.Text.StringBuilder sbSomeString = new System.Text.StringBuilder();
Stopwatch sw = new Stopwatch();
sw.Start();
for (int i = 0; i < 1000; i++)
{
sbSomeString.Append("Test ");
}
sw.Stop();
Console.WriteLine(sbSomeString.ToString());
Console.WriteLine("Time Taken :" + sw.ElapsedMilliseconds);
OldCode();
}
static void OldCode()
{
string strSomeString = string.Empty;
Stopwatch sw = new Stopwatch();
sw.Start();
for (int i = 0; i < 1000; i++)
{
strSomeString += "Test ";
}
sw.Stop();
Console.WriteLine(strSomeString);
Console.WriteLine("Time Taken :" + sw.ElapsedMilliseconds);
Console.ReadLine();
}
}
}
J#
<code>package ConsoleJSharp;
import System.*;
import System.Diagnostics.*;
public class Program
{
public static void main(String[] args)
{
System.Text.StringBuilder sbSomeString = new System.Text.StringBuilder();
Stopwatch sw = new Stopwatch();
sw.Start();
for (int i = 0; i < 1000; i++)
{
sbSomeString.Append("Test ");
}
sw.Stop();
Console.WriteLine(sbSomeString.ToString());
Console.WriteLine("Time Taken :" + sw.get_ElapsedMilliseconds());
OldCode();
}
public static void OldCode()
{
String strSomeString = String.Empty;
Stopwatch sw = new Stopwatch();
sw.Start();
for (int i = 0; i < 1000; i++)
{
strSomeString += "Test ";
}
sw.Stop();
Console.WriteLine(strSomeString);
Console.WriteLine("Time Taken :" + sw.get_ElapsedMilliseconds());
Console.ReadLine();
}
}
C++
<code>
#include "stdafx.h"
#using <mscorlib.dll>
using namespace System;
using namespace System::Diagnostics;
void OldCode();
int main(array<System::String ^> ^args)
{
System::Text::StringBuilder^ sbSomeString = gcnew System::Text::StringBuilder();
Stopwatch^ sw = gcnew Stopwatch;
sw->Start();
for (int i = 0;i< 1000 ;i++)
{
sbSomeString->Append("Test ");
}
sw->Stop();
Console::WriteLine(sbSomeString->ToString());
Console::WriteLine("Time Taken :" + sw->ElapsedMilliseconds);
OldCode();
return 0;
}
void OldCode()
{
String^ strSomeString = String::Empty;
Stopwatch^ sw = gcnew Stopwatch;
sw->Start();
for (int i = 0;i< 1000 ;i++)
{
strSomeString += "Test ";
}
sw->Stop();
Console::WriteLine(strSomeString);
Console::WriteLine("Time Taken :" + sw->ElapsedMilliseconds);
Console::ReadLine();
}
The MSIL
VB
<code>
.method public static void Main() cil managed
{
.entrypoint
.custom instance
void [mscorlib]System.STAThreadAttribute::.ctor() = ( 01 00 00 00 )
// Code size 103 (0x67)
.maxstack 2
.locals init ([0] class [mscorlib]System.Text.StringBuilder sbSomeString,
[1] class [System]System.Diagnostics.Stopwatch sw,
[2] int32 i,
[3] int32 VB$CG$t_i4$S0)
IL_0000: nop
IL_0001: newobj instance void [mscorlib]System.Text.StringBuilder::.ctor()
IL_0006: stloc.0
IL_0007: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_000c: stloc.1
IL_000d: ldloc.1
IL_000e: callvirt instance void [System]System.Diagnostics.Stopwatch::Start()
IL_0013: nop
IL_0014: ldc.i4.0
IL_0015: stloc.2
IL_0016: ldloc.0
IL_0017: ldstr "Test "
IL_001c: callvirt instance class [mscorlib]System.Text.StringBuilder
[mscorlib]System.Text.StringBuilder::Append(string)
IL_0021: pop
IL_0022: nop
IL_0023: ldloc.2
IL_0024: ldc.i4.1
IL_0025: add.ovf
IL_0026: stloc.2
IL_0027: ldloc.2
IL_0028: ldc.i4 0x3e8
IL_002d: stloc.3
IL_002e: ldloc.3
IL_002f: ble.s IL_0016
IL_0031: ldloc.1
IL_0032: callvirt
instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_0037: nop
IL_0038: ldloc.0
IL_0039: callvirt
instance string [mscorlib]System.Text.StringBuilder::ToString()
IL_003e: call void [mscorlib]System.Console::WriteLine(string)
IL_0043: nop
IL_0044: ldstr "Time Taken :"
IL_0049: ldloc.1
IL_004a: callvirt instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_004f: call string
[Microsoft.VisualBasic]
Microsoft.VisualBasic.CompilerServices.Conversions::ToString(int64)
IL_0054: call string [mscorlib]System.String::Concat(string,
string)
IL_0059: call void [mscorlib]System.Console::WriteLine(string)
IL_005e: nop
IL_005f: call void VBConsole.Module1::OldCode()
IL_0064: nop
IL_0065: nop
IL_0066: ret
} // end of method Module1::Main
.method public static void OldCode() cil managed
{
// Code size 98 (0x62)
.maxstack 2
.locals init ([0] string strSomeString,
[1] class [System]System.Diagnostics.Stopwatch sw,
[2] int32 i,
[3] int32 VB$CG$t_i4$S0)
IL_0000: nop
IL_0001: ldsfld string [mscorlib]System.String::Empty
IL_0006: stloc.0
IL_0007: newobj instance void
[System]System.Diagnostics.Stopwatch::.ctor()
IL_000c: stloc.1
IL_000d: ldloc.1
IL_000e: callvirt instance void
[System]System.Diagnostics.Stopwatch::Start()
IL_0013: nop
IL_0014: ldc.i4.0
IL_0015: stloc.2
IL_0016: ldloc.0
IL_0017: ldstr "Test "
IL_001c: call string [mscorlib]System.String::Concat(string,
string)
IL_0021: stloc.0
IL_0022: nop
IL_0023: ldloc.2
IL_0024: ldc.i4.1
IL_0025: add.ovf
IL_0026: stloc.2
IL_0027: ldloc.2
IL_0028: ldc.i4 0x3e8
IL_002d: stloc.3
IL_002e: ldloc.3
IL_002f: ble.s IL_0016
IL_0031: ldloc.1
IL_0032: callvirt instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_0037: nop
IL_0038: ldloc.0
IL_0039: call void [mscorlib]System.Console::WriteLine(string)
IL_003e: nop
IL_003f: ldstr "Time Taken :"
IL_0044: ldloc.1
IL_0045: callvirt instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_004a: call string [Microsoft.VisualBasic]
Microsoft.VisualBasic.CompilerServices.Conversions::ToString(int64)
IL_004f: call string [mscorlib]System.String::Concat(string,
string)
IL_0054: call void [mscorlib]System.Console::WriteLine(string)
IL_0059: nop
IL_005a: call string [mscorlib]System.Console::ReadLine()
IL_005f: pop
IL_0060: nop
IL_0061: ret
} // end of method Module1::OldCode
C#
<code>
.method private hidebysig static void Main(string[] args) cil managed
{
.entrypoint
.maxstack 2
.locals init ([0] class [mscorlib]System.Text.StringBuilder sbSomeString,
[1] class [System]System.Diagnostics.Stopwatch sw,
[2] int32 i,
[3] bool CS$4$0000)
IL_0000: nop
IL_0001: newobj instance void [mscorlib]System.Text.StringBuilder::.ctor()
IL_0006: stloc.0
IL_0007: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_000c: stloc.1
IL_000d: ldloc.1
IL_000e: callvirt instance void [System]System.Diagnostics.Stopwatch::Start()
IL_0013: nop
IL_0014: ldc.i4.0
IL_0015: stloc.2
IL_0016: br.s IL_002a
IL_0018: nop
IL_0019: ldloc.0
IL_001a: ldstr "Test "
IL_001f: callvirt instance class
[mscorlib]System.Text.StringBuilder
[mscorlib]System.Text.StringBuilder::Append(string)
IL_0024: pop
IL_0025: nop
IL_0026: ldloc.2
IL_0027: ldc.i4.1
IL_0028: add
IL_0029: stloc.2
IL_002a: ldloc.2
IL_002b: ldc.i4 0x3e8
IL_0030: clt
IL_0032: stloc.3
IL_0033: ldloc.3
IL_0034: brtrue.s IL_0018
IL_0036: ldloc.1
IL_0037: callvirt instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_003c: nop
IL_003d: ldloc.0
IL_003e: callvirt instance string [mscorlib]System.Object::ToString()
IL_0043: call void [mscorlib]System.Console::WriteLine(string)
IL_0048: nop
IL_0049: ldstr "Time Taken :"
IL_004e: ldloc.1
IL_004f: callvirt instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_0054: box [mscorlib]System.Int64
IL_0059: call string [mscorlib]System.String::Concat(object,
object)
IL_005e: call void [mscorlib]System.Console::WriteLine(string)
IL_0063: nop
IL_0064: call void ConsoleCSharp.Program::OldCode()
IL_0069: nop
IL_006a: ret
}
.method private hidebysig static void OldCode() cil managed
{
.maxstack 2
.locals init ([0] string strSomeString,
[1] class [System]System.Diagnostics.Stopwatch sw,
[2] int32 i,
[3] bool CS$4$0000)
IL_0000: nop
IL_0001: ldsfld string [mscorlib]System.String::Empty
IL_0006: stloc.0
IL_0007: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_000c: stloc.1
IL_000d: ldloc.1
IL_000e: callvirt instance void [System]System.Diagnostics.Stopwatch::Start()
IL_0013: nop
IL_0014: ldc.i4.0
IL_0015: stloc.2
IL_0016: br.s IL_002a
IL_0018: nop
IL_0019: ldloc.0
IL_001a: ldstr "Test "
IL_001f: call string [mscorlib]System.String::Concat(string,
string)
IL_0024: stloc.0
IL_0025: nop
IL_0026: ldloc.2
IL_0027: ldc.i4.1
IL_0028: add
IL_0029: stloc.2
IL_002a: ldloc.2
IL_002b: ldc.i4 0x3e8
IL_0030: clt
IL_0032: stloc.3
IL_0033: ldloc.3
IL_0034: brtrue.s IL_0018
IL_0036: ldloc.1
IL_0037: callvirt instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_003c: nop
IL_003d: ldloc.0
IL_003e: call void [mscorlib]System.Console::WriteLine(string)
IL_0043: nop
IL_0044: ldstr "Time Taken :"
IL_0049: ldloc.1
IL_004a: callvirt instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_004f: box [mscorlib]System.Int64
IL_0054: call string [mscorlib]System.String::Concat(object,
object)
IL_0059: call void [mscorlib]System.Console::WriteLine(string)
IL_005e: nop
IL_005f: call string [mscorlib]System.Console::ReadLine()
IL_0064: pop
IL_0065: ret
}
J#
<code>
.method public hidebysig static void main(string[] args) cil managed
{
.entrypoint
.maxstack 2
.locals init ([0] class [mscorlib]System.Text.StringBuilder sbSomeString,
[1] class [System]System.Diagnostics.Stopwatch sw,
[2] int32 i)
IL_0000: ldtoken [vjslib]com.ms.vjsharp.lang.ObjectImpl
IL_0005: call void
[mscorlib] System.Runtime.CompilerServices.
RuntimeHelpers::RunClassConstructor
(valuetype [mscorlib]System.RuntimeTypeHandle)
IL_000a: newobj instance void [mscorlib]System.Text.StringBuilder::.ctor()
IL_000f: stloc.0
IL_0010: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_0015: stloc.1
IL_0016: ldloc.1
IL_0017: callvirt instance void [System]System.Diagnostics.Stopwatch::Start()
IL_001c: ldc.i4.0
IL_001d: stloc.2
IL_001e: br.s IL_0030
IL_0020: ldloc.0
IL_0021: ldstr "Test "
IL_0026: callvirt instance class [mscorlib]System.Text.StringBuilder
[mscorlib]System.Text.StringBuilder::Append(string)
IL_002b: pop
IL_002c: ldloc.2
IL_002d: ldc.i4.1
IL_002e: add
IL_002f: stloc.2
IL_0030: ldloc.2
IL_0031: ldc.i4 0x3e8
IL_0036: blt.s IL_0020
IL_0038: ldloc.1
IL_0039: callvirt instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_003e: ldloc.0
IL_003f: callvirt instance string [mscorlib]System.Text.StringBuilder::ToString()
IL_0044: call void [mscorlib]System.Console::WriteLine(string)
IL_0049: newobj instance void [vjslib]java.lang.StringBuffer::.ctor()
IL_004e: ldstr "Time Taken :"
IL_0053: callvirt instance class
[vjslib]java.lang.StringBuffer
[vjslib]java.lang.StringBuffer::append(string)
IL_0058: ldloc.1
IL_0059: callvirt instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_005e: callvirt instance class
[vjslib]java.lang.StringBuffer
[vjslib]java.lang.StringBuffer::append(int64)
IL_0063: callvirt instance string [vjslib]java.lang.StringBuffer::ToString()
IL_0068: call void [mscorlib]System.Console::WriteLine(string)
IL_006d: call void ConsoleJSharp.Program::OldCode()
IL_0072: call void
[vjslib]com.ms.vjsharp.util.Utilities::cleanupAfterMainReturns()
IL_0077: br.s IL_0079
IL_0079: ret
}
.method public hidebysig static void OldCode() cil managed
{
.maxstack 2
.locals init ([0] string strSomeString,
[1] class [System]System.Diagnostics.Stopwatch sw,
[2] int32 i)
IL_0000: ldsfld string [mscorlib]System.String::Empty
IL_0005: stloc.0
IL_0006: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_000b: stloc.1
IL_000c: ldloc.1
IL_000d: callvirt instance void [System]System.Diagnostics.Stopwatch::Start()
IL_0012: ldc.i4.0
IL_0013: stloc.2
IL_0014: br.s IL_0035
IL_0016: newobj instance void [vjslib]java.lang.StringBuffer::.ctor()
IL_001b: ldloc.0
IL_001c: callvirt instance class [vjslib] java.lang.StringBuffer
[vjslib]java.lang.StringBuffer::append(string)
IL_0021: ldstr "Test "
IL_0026: callvirt instance class [vjslib]java.lang.StringBuffer
[vjslib]java.lang.StringBuffer::append(string)
IL_002b: callvirt instance string [vjslib]java.lang.StringBuffer::ToString()
IL_0030: stloc.0
IL_0031: ldloc.2
IL_0032: ldc.i4.1
IL_0033: add
IL_0034: stloc.2
IL_0035: ldloc.2
IL_0036: ldc.i4 0x3e8
IL_003b: blt.s IL_0016
IL_003d: ldloc.1
IL_003e: callvirt instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_0043: ldloc.0
IL_0044: call void [mscorlib]System.Console::WriteLine(string)
IL_0049: newobj instance void [vjslib]java.lang.StringBuffer::.ctor()
IL_004e: ldstr "Time Taken :"
IL_0053: callvirt instance class [vjslib]java.lang.StringBuffer
[vjslib]java.lang.StringBuffer::append(string)
IL_0058: ldloc.1
IL_0059: callvirt instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_005e: callvirt instance class
[vjslib]java.lang.StringBuffer
[vjslib]java.lang.StringBuffer::append(int64)
IL_0063: callvirt instance string [vjslib]java.lang.StringBuffer::ToString()
IL_0068: call void [mscorlib]System.Console::WriteLine(string)
IL_006d: call string [mscorlib]System.Console::ReadLine()
IL_0072: pop
IL_0073: br.s IL_0075
IL_0075: ret
}
C++
<code>
.method assembly static int32 main(string[] args) cil managed
{
.maxstack 2
.locals ([0] class [System]System.Diagnostics.Stopwatch sw,
[1] int32 i,
[2] class [mscorlib]System.Text.StringBuilder sbSomeString,
[3] int32 V_3)
IL_0000: ldc.i4.0
IL_0001: stloc.3
IL_0002: ldnull
IL_0003: stloc.2
IL_0004: ldnull
IL_0005: stloc.0
IL_0006: newobj instance void [mscorlib]System.Text.StringBuilder::.ctor()
IL_000b: stloc.2
IL_000c: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_0011: stloc.0
IL_0012: ldloc.0
IL_0013: call instance void [System]System.Diagnostics.Stopwatch::Start()
IL_0018: ldc.i4.0
IL_0019: stloc.1
IL_001a: br.s IL_0020
IL_001c: ldloc.1
IL_001d: ldc.i4.1
IL_001e: add
IL_001f: stloc.1
IL_0020: ldloc.1
IL_0021: ldc.i4 0x3e8
IL_0026: bge.s IL_0036
IL_0028: ldloc.2
IL_0029: ldstr "Test "
IL_002e: call instance class
[mscorlib]System.Text.StringBuilder
[mscorlib]System.Text.StringBuilder::Append(string)
IL_0033: pop
IL_0034: br.s IL_001c
IL_0036: ldloc.0
IL_0037: call instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_003c: ldloc.2
IL_003d: callvirt instance string [mscorlib]System.Text.StringBuilder::ToString()
IL_0042: call void [mscorlib]System.Console::WriteLine(string)
IL_0047: ldstr "Time Taken :"
IL_004c: ldloc.0
IL_004d: call instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_0052: box [mscorlib]System.Int64
IL_0057: call string [mscorlib]System.String::Concat(object,
object)
IL_005c: call void [mscorlib]System.Console::WriteLine(string)
IL_0061: call void modopt( [mscorlib]System.Runtime.CompilerServices.CallConvCdecl)
OldCode()
IL_0066: ldc.i4.0
IL_0067: stloc.3
IL_0068: ldloc.3
IL_0069: ret
}
.method assembly static void modopt ([mscorlib]System.Runtime.CompilerServices.CallConvCdecl)
OldCode() cil managed
{
.vtentry 1 : 1
.maxstack 2
.locals ([0] class [System]System.Diagnostics.Stopwatch sw,
[1] string strSomeString,
[2] int32 i)
IL_0000: ldnull
IL_0001: stloc.1
IL_0002: ldnull
IL_0003: stloc.0
IL_0004: ldsfld string [mscorlib]System.String::Empty
IL_0009: stloc.1
IL_000a: newobj instance void [System]System.Diagnostics.Stopwatch::.ctor()
IL_000f: stloc.0
IL_0010: ldloc.0
IL_0011: call instance void [System]System.Diagnostics.Stopwatch::Start()
IL_0016: ldc.i4.0
IL_0017: stloc.2
IL_0018: br.s IL_001e
IL_001a: ldloc.2
IL_001b: ldc.i4.1
IL_001c: add
IL_001d: stloc.2
IL_001e: ldloc.2
IL_001f: ldc.i4 0x3e8
IL_0024: bge.s IL_0034
IL_0026: ldloc.1
IL_0027: ldstr "Test "
IL_002c: call string [mscorlib]System.String::Concat(string,
string)
IL_0031: stloc.1
IL_0032: br.s IL_001a
IL_0034: ldloc.0
IL_0035: call instance void [System]System.Diagnostics.Stopwatch::Stop()
IL_003a: ldloc.1
IL_003b: call void [mscorlib]System.Console::WriteLine(string)
IL_0040: ldstr "Time Taken :"
IL_0045: ldloc.0
IL_0046: call instance int64
[System]System.Diagnostics.Stopwatch::get_ElapsedMilliseconds()
IL_004b: box [mscorlib]System.Int64
IL_0050: call string [mscorlib]System.String::Concat(object,
object)
IL_0055: call void [mscorlib]System.Console::WriteLine(string)
IL_005a: call string [mscorlib]System.Console::ReadLine()
IL_005f: pop
IL_0060: ret
}
Conclusion
I have not included all the assembly code that the compiler generates. I have only included what I think is worth noting, i.e. I have only included the code of the functions.
It is interesting to note that the StringBuilder class is able to perform the string concatenation in 0ms whereas the string concatenation takes much longer in the legacy method, on average 17ms
History
- 06-10-06: Draft Version 1 Part 2 Uploaded
- 09-10-06: Updated content, formatting and changed article title
