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.