p99 ×4 после деплоя на ровном месте: как Dynamic PGO в .NET 9 роняет ваш сервис по первым 30 вызовам

[vvdev]

Под 10.0.9 оба варианта прогрева дают одинаковое время выполнения нагрузки.
"На моей машине [не] работает", короче ;)
Windows 11 (10.0.26200.8655/25H2/2025Update/HudsonValley2)
12th Gen Intel Core i9-12900HK 2.50GHz, 1 CPU, 20 logical and 14 physical cores
.NET SDK 10.0.301
[Host] : .NET 10.0.9 (10.0.9, 10.0.926.27113), X64 RyuJIT x86-64-v3

АСМ пока вдумчиво не читал, гляну позже.

[vvdev]

...да и под 9.0.17 и 8.0.28 разницы во времени исполнения нет.
RyuJIT, вероятно, самый свежий работает, вне зависимости от таргета?

АСМ всё ещё не читал.

[vvdev]

В общем, при варм-апе в 50 итераций, повторить поведение не удалось:

   1: JIT compiled Program:<Main>$(System.String[]) [Instrumented Tier0, IL size=173, code size=543]
   2: JIT compiled Dispatcher:.ctor() [Tier0, IL size=7, code size=31]

Warming up...

   3: JIT compiled FastHandler:.ctor() [Tier0, IL size=7, code size=31]
   4: JIT compiled Dispatcher:Process(IHandler,int) [Instrumented Tier0, IL size=26, code size=213]
   5: JIT compiled FastHandler:Handle(int) [Tier0, IL size=4, code size=18]

Warmup done. Starting the test...

   6: JIT compiled SlowHandler:.ctor() [Tier0, IL size=7, code size=31]
   7: JIT compiled Utils:Test(Dispatcher,IHandler) [Instrumented Tier0, IL size=65, code size=291]
   8: JIT compiled Utils:PrintProgress(int) [Tier0, IL size=67, code size=161]
   9: JIT compiled System.Threading.Thread:GetThreadStaticsBase() [Tier0, IL size=18, code size=34]
Progress: 0
  10: JIT compiled SlowHandler:Handle(int) [Tier0, IL size=11, code size=84]
  11: JIT compiled Utils:Test(Dispatcher,IHandler) [Tier1-OSR @0x26 with Synthesized PGO, IL size=65, code size=464]
Progress: 10 000
  12: JIT compiled Dispatcher:Process(IHandler,int) [Instrumented Tier0, IL size=26, code size=213]
  13: JIT compiled Utils:PrintProgress(int) [Instrumented Tier0, IL size=67, code size=191]
  14: JIT compiled SlowHandler:Handle(int) [Instrumented Tier0, IL size=11, code size=84]
  15: JIT compiled Dispatcher:Process(IHandler,int) [Tier1 with Synthesized PGO, IL size=26, code size=200]
Progress: 20 000
  16: JIT compiled Utils:PrintProgress(int) [Tier1 with Synthesized PGO, IL size=67, code size=240]
  17: JIT compiled SlowHandler:Handle(int) [Tier1, IL size=11, code size=44]
Progress: 30 000
Progress: 40 000
Progress: 50 000
Progress: 60 000
Progress: 70 000

Как видно, Instrumented Tier0 Process компилируется сильно позже окончания варм-апа, и ещё позже - Tier1 with Synthesized PGO.

И код получается такой:

; Assembly listing for method Dispatcher:Process(IHandler,int):int:this (Tier1)
; Emitting BLENDED_CODE for generic X64 + VEX on Windows
; Tier1 code
; optimized code
; optimized using Synthesized PGO
; rsp based frame
; fully interruptible
; with Synthesized PGO: fgCalledCount is 111728
; 0 inlinees with PGO data; 1 single block inlinees; 0 inlinees without PGO data

G_M000_IG01:
       push     rdi
       push     rsi
       push     rbp
       push     rbx
       sub      rsp, 40
Progress: 20 000rsi, rdx

       mov      ebx, r8d

G_M000_IG02:
       xor      edi, edi
       xor      ebp, ebp
       test     ebx, ebx
       jle      SHORT G_M000_IG06

G_M000_IG03:
       test     rsi, rsi
       je       SHORT G_M000_IG08

G_M000_IG04:
       mov      rcx, 0xD1FFAB1E
       cmp      qword ptr [rsi], rcx
       jne      SHORT G_M000_IG08
       align    [0 bytes for IG05]

G_M000_IG05:
       vxorps   xmm0, xmm0, xmm0
       vcvtsi2sd xmm0, xmm0, ebp
       vsqrtsd  xmm0, xmm0, xmm0
       vcmpordsd xmm1, xmm0, xmm0
       vandpd   xmm1, xmm1, xmm0
       mov      ecx, 0xD1FFAB1E
       vcvttsd2si edx, xmm1
       vucomisd xmm0, qword ptr [reloc @RWD00]
       cmovb    ecx, edx
       inc      ecx
       add      edi, ecx
       inc      ebp
       cmp      ebp, ebx
       jl       SHORT G_M000_IG05

G_M000_IG06:
       mov      eax, edi

G_M000_IG07:
       add      rsp, 40
       pop      rbx
       pop      rbp
       pop      rsi
       pop      rdi
       ret

G_M000_IG08:
       mov      rcx, 0xD1FFAB1E
       cmp      qword ptr [rsi], rcx
       jne      SHORT G_M000_IG10
       vxorps   xmm0, xmm0, xmm0
       vcvtsi2sd xmm0, xmm0, ebp
       vsqrtsd  xmm0, xmm0, xmm0
       vcmpordsd xmm1, xmm0, xmm0
       vandpd   xmm1, xmm1, xmm0
       mov      ecx, 0xD1FFAB1E
       vcvttsd2si edx, xmm1
       vucomisd xmm0, qword ptr [reloc @RWD00]
       cmovb    ecx, edx
       inc      ecx

G_M000_IG09:
       add      edi, ecx
       inc      ebp
       cmp      ebp, ebx
       jl       SHORT G_M000_IG08
       jmp      SHORT G_M000_IG06

G_M000_IG10:
       mov      rcx, rsi
       mov      edx, ebp
       mov      r11, 0xD1FFAB1E
       call     [r11]IHandler:Handle(int):int:this
       mov      ecx, eax
       jmp      SHORT G_M000_IG09

RWD00   dq      41E0000000000000h

; Total bytes of code 194

  15: JIT compiled Dispatcher:Process(IHandler,int) [Tier1 with Synthesized PGO, IL size=26, code size=194]

При варм-апе в 100 000 итераций лог и код такой же:

   1: JIT compiled Program:<Main>$(System.String[]) [Instrumented Tier0, IL size=186, code size=557]
   2: JIT compiled Dispatcher:.ctor() [Tier0, IL size=7, code size=31]

Warming up...

   3: JIT compiled FastHandler:.ctor() [Tier0, IL size=7, code size=31]
   4: JIT compiled Dispatcher:Process(IHandler,int) [Instrumented Tier0, IL size=26, code size=213]
   5: JIT compiled FastHandler:Handle(int) [Tier0, IL size=4, code size=18]
   6: JIT compiled Program:<Main>$(System.String[]) [Tier1-OSR @0x3a with Synthesized PGO, IL size=186, code size=3197]

Warmup done. Starting the test...

   7: JIT compiled Utils:Test(Dispatcher,IHandler) [Instrumented Tier0, IL size=65, code size=291]
   8: JIT compiled Utils:PrintProgress(int) [Tier0, IL size=67, code size=161]
   9: JIT compiled System.Threading.Thread:GetThreadStaticsBase() [Tier0, IL size=18, code size=34]
Progress: 0
  10: JIT compiled SlowHandler:Handle(int) [Tier0, IL size=11, code size=84]
  11: JIT compiled Utils:Test(Dispatcher,IHandler) [Tier1-OSR @0x26 with Synthesized PGO, IL size=65, code size=464]
Progress: 10 000
  12: JIT compiled Dispatcher:Process(IHandler,int) [Instrumented Tier0, IL size=26, code size=213]
  13: JIT compiled Utils:PrintProgress(int) [Instrumented Tier0, IL size=67, code size=191]
  14: JIT compiled SlowHandler:Handle(int) [Instrumented Tier0, IL size=11, code size=84]
  15: JIT compiled Dispatcher:Process(IHandler,int) [Tier1 with Synthesized PGO, IL size=26, code size=194]
Progress: 20 000
  16: JIT compiled Utils:PrintProgress(int) [Tier1 with Synthesized PGO, IL size=67, code size=240]
  17: JIT compiled SlowHandler:Handle(int) [Tier1, IL size=11, code size=44]

[vvdev]

...а статья отличная, люблю такое, спасибо.