c# - Curiosidad: ¿Por qué Expression<...> cuando se compila se ejecuta más rápido que un mínimo DynamicMethod?

profiling reflection.emit

Question

Actualmente estoy haciendo algunas optimizaciones de última medida, principalmente por diversión y aprendizaje, y descubrí algo que me dejó un par de preguntas.

Primero, las preguntas:

1. Cuando construyo un método en la memoria mediante el uso de DynamicMethod y utilizo el depurador, ¿hay alguna forma de que entre en el código ensamblador generado al visualizar el código en la vista del desensamblador? El depurador parece pasar por alto todo el método para mí
2. O, si eso no es posible, ¿es posible para mí guardar de alguna manera el código IL generado en el disco como un ensamblaje, para poder inspeccionarlo con Reflector ?
3. ¿Por qué la versión Expression<...> de mi método de adición simple (Int32 + Int32 => Int32) se ejecuta más rápido que una versión mínima de DynamicMethod?

Aquí hay un programa corto y completo que demuestra. En mi sistema, el resultado es:

DynamicMethod: 887 ms
Lambda: 1878 ms
Method: 1969 ms
Expression: 681 ms

Esperaba que las llamadas lambda y método tuvieran valores más altos, pero la versión DynamicMethod es consistentemente aproximadamente 30-50% más lenta (variaciones probablemente debido a Windows y otros programas). Alguien sabe el motivo?

Aquí está el programa:

using System;
using System.Linq.Expressions;
using System.Reflection.Emit;
using System.Diagnostics;
namespace Sandbox
{
public class Program
{
public static void Main(String[] args)
{
DynamicMethod method = new DynamicMethod("TestMethod",
typeof(Int32), new Type[] { typeof(Int32), typeof(Int32) });
var il = method.GetILGenerator();
il.Emit(OpCodes.Ldarg_0);
il.Emit(OpCodes.Ldarg_1);
il.Emit(OpCodes.Add);
il.Emit(OpCodes.Ret);
Func<Int32, Int32, Int32> f1 =
(Func<Int32, Int32, Int32>)method.CreateDelegate(
typeof(Func<Int32, Int32, Int32>));
Func<Int32, Int32, Int32> f2 = (Int32 a, Int32 b) => a + b;
Func<Int32, Int32, Int32> f3 = Sum;
Expression<Func<Int32, Int32, Int32>> f4x = (a, b) => a + b;
Func<Int32, Int32, Int32> f4 = f4x.Compile();
for (Int32 pass = 1; pass <= 2; pass++)
{
// Pass 1 just runs all the code without writing out anything
// to avoid JIT overhead influencing the results
Time(f1, "DynamicMethod", pass);
Time(f2, "Lambda", pass);
Time(f3, "Method", pass);
Time(f4, "Expression", pass);
}
}
private static void Time(Func<Int32, Int32, Int32> fn,
String name, Int32 pass)
{
Stopwatch sw = new Stopwatch();
sw.Start();
for (Int32 index = 0; index <= 100000000; index++)
{
Int32 result = fn(index, 1);
}
sw.Stop();
if (pass == 2)
Debug.WriteLine(name + ": " + sw.ElapsedMilliseconds + " ms");
}
private static Int32 Sum(Int32 a, Int32 b)
{
return a + b;
}
}
}

Answer 1

El método creado a través de DynamicMethod atraviesa dos procesos, mientras que el método creado a través de Expression<> no pasa por ninguno.

Así es como funciona. Aquí está la secuencia de invocación para invocar fn(0, 1) en el método Time (codifiqué los argumentos a 0 y 1 para facilitar la depuración):

00cc032c 6a01 push 1 // 1 argument
00cc032e 8bcf mov ecx,edi
00cc0330 33d2 xor edx,edx // 0 argument
00cc0332 8b410c mov eax,dword ptr [ecx+0Ch]
00cc0335 8b4904 mov ecx,dword ptr [ecx+4]
00cc0338 ffd0 call eax // 1 arg on stack, two in edx, ecx

Para la primera invocación que investigué, DynamicMethod , la línea call eax aparece así:

00cc0338 ffd0 call eax {003c2084}
0:000> !u 003c2084
Unmanaged code
003c2084 51 push ecx
003c2085 8bca mov ecx,edx
003c2087 8b542408 mov edx,dword ptr [esp+8]
003c208b 8b442404 mov eax,dword ptr [esp+4]
003c208f 89442408 mov dword ptr [esp+8],eax
003c2093 58 pop eax
003c2094 83c404 add esp,4
003c2097 83c010 add eax,10h
003c209a ff20 jmp dword ptr [eax]

Esto parece estar haciendo algunos swizzling de la pila para reorganizar los argumentos. Opino que se debe a la diferencia entre los delegados que usan el argumento implícito "este" y los que no.

Ese salto al final se resuelve así:

003c209a ff20 jmp dword ptr [eax] ds:0023:012f7edc=0098c098
0098c098 e963403500 jmp 00ce0100

El resto del código en 0098c098 parece un thunk JIT, cuyo inicio se reescribió con un jmp después del JIT. Solo después de este salto alcanzamos el código real:

0:000> !u eip
Normal JIT generated code
DynamicClass.TestMethod(Int32, Int32)
Begin 00ce0100, size 5
>>> 00ce0100 03ca add ecx,edx
00ce0102 8bc1 mov eax,ecx
00ce0104 c3 ret

La secuencia de invocación para el método creado a través de Expression<> es diferente: falta el código swizzling de la pila. Aquí está, desde el primer salto a través de eax :

00cc0338 ffd0 call eax {00ce00a8}
0:000> !u eip
Normal JIT generated code
DynamicClass.lambda_method(System.Runtime.CompilerServices.ExecutionScope, Int32, Int32)
Begin 00ce00a8, size b
>>> 00ce00a8 8b442404 mov eax,dword ptr [esp+4]
00ce00ac 03d0 add edx,eax
00ce00ae 8bc2 mov eax,edx
00ce00b0 c20400 ret 4

Ahora, ¿cómo llegaron las cosas así?

1. El swizzling de la pila no era necesario (el primer argumento implícito del delegado se utiliza realmente, es decir, no como un delegado vinculado a un método estático)
2. El JIT debe haber sido forzado por la lógica de compilación LINQ para que el delegado tenga la dirección de destino real en lugar de la dirección falsa.

No sé cómo el LINQ forzó el JIT, pero sí sé cómo forzar un JIT, llamando a la función al menos una vez. ACTUALIZACIÓN: Encontré otra forma de forzar un JIT: use el argumento restrictedSkipVisibility para el constructor y pase true . Entonces, aquí está el código modificado que elimina el swizzling de la pila al usar el parámetro "this" implícito, y usa el constructor alternativo para precompilar de modo que la dirección atada sea la dirección real, en lugar del thunk:

using System;
using System.Linq.Expressions;
using System.Reflection.Emit;
using System.Diagnostics;
namespace Sandbox
{
public class Program
{
public static void Main(String[] args)
{
DynamicMethod method = new DynamicMethod("TestMethod",
typeof(Int32), new Type[] { typeof(object), typeof(Int32),
typeof(Int32) }, true);
var il = method.GetILGenerator();
il.Emit(OpCodes.Ldarg_1);
il.Emit(OpCodes.Ldarg_2);
il.Emit(OpCodes.Add);
il.Emit(OpCodes.Ret);
Func<Int32, Int32, Int32> f1 =
(Func<Int32, Int32, Int32>)method.CreateDelegate(
typeof(Func<Int32, Int32, Int32>), null);
Func<Int32, Int32, Int32> f2 = (Int32 a, Int32 b) => a + b;
Func<Int32, Int32, Int32> f3 = Sum;
Expression<Func<Int32, Int32, Int32>> f4x = (a, b) => a + b;
Func<Int32, Int32, Int32> f4 = f4x.Compile();
for (Int32 pass = 1; pass <= 2; pass++)
{
// Pass 1 just runs all the code without writing out anything
// to avoid JIT overhead influencing the results
Time(f1, "DynamicMethod", pass);
Time(f2, "Lambda", pass);
Time(f3, "Method", pass);
Time(f4, "Expression", pass);
}
}
private static void Time(Func<Int32, Int32, Int32> fn,
String name, Int32 pass)
{
Stopwatch sw = new Stopwatch();
sw.Start();
for (Int32 index = 0; index <= 100000000; index++)
{
Int32 result = fn(index, 1);
}
sw.Stop();
if (pass == 2)
Console.WriteLine(name + ": " + sw.ElapsedMilliseconds + " ms");
}
private static Int32 Sum(Int32 a, Int32 b)
{
return a + b;
}
}
}

Aquí están los tiempos de ejecución en mi sistema:

DynamicMethod: 312 ms
Lambda: 417 ms
Method: 417 ms
Expression: 312 ms

ACTUALIZADO PARA AGREGAR :

Intenté ejecutar este código en mi nuevo sistema, que es un Core i7 920 que ejecuta Windows 7 x64 con .NET 4 beta 2 instalado (mscoree.dll ver. 4.0.30902), y los resultados son, bueno, variables.

csc 3.5, /platform:x86, runtime v2.0.50727 (via .config)
Run #1
DynamicMethod: 214 ms
Lambda: 571 ms
Method: 570 ms
Expression: 249 ms
Run #2
DynamicMethod: 463 ms
Lambda: 392 ms
Method: 392 ms
Expression: 463 ms
Run #3
DynamicMethod: 463 ms
Lambda: 570 ms
Method: 570 ms
Expression: 463 ms

Quizás esto es Intel SpeedStep que afecta los resultados, o posiblemente Turbo Boost. En cualquier caso, es muy molesto.

csc 3.5, /platform:x64, runtime v2.0.50727 (via .config)
DynamicMethod: 428 ms
Lambda: 392 ms
Method: 392 ms
Expression: 428 ms
csc 3.5, /platform:x64, runtime v4
DynamicMethod: 428 ms
Lambda: 356 ms
Method: 356 ms
Expression: 428 ms
csc 4, /platform:x64, runtime v4
DynamicMethod: 428 ms
Lambda: 356 ms
Method: 356 ms
Expression: 428 ms
csc 4, /platform:x86, runtime v4
DynamicMethod: 463 ms
Lambda: 570 ms
Method: 570 ms
Expression: 463 ms
csc 3.5, /platform:x86, runtime v4
DynamicMethod: 214 ms
Lambda: 570 ms
Method: 571 ms
Expression: 249 ms

Muchos de estos resultados serán accidentes de tiempo, lo que sea que esté causando las aceleraciones aleatorias en el escenario C # 3.5 / runtime v2.0. Tendré que reiniciar para ver si SpeedStep o Turbo Boost son responsables de estos efectos.