{"action":"created","issue":{"url":"https://api.github.com/repos/dotnet/coreclr/issues/18361","repository_url":"https://api.github.com/repos/dotnet/coreclr","labels_url":"https://api.github.com/repos/dotnet/coreclr/issues/18361/labels{/name}","comments_url":"https://api.github.com/repos/dotnet/coreclr/issues/18361/comments","events_url":"https://api.github.com/repos/dotnet/coreclr/issues/18361/events","html_url":"https://github.com/dotnet/coreclr/issues/18361","id":330462584,"node_id":"MDU6SXNzdWUzMzA0NjI1ODQ=","number":18361,"title":"Performance degradation dotnet core 2.1.300 TieredCompilation","user":{"login":"mrange","id":2491891,"node_id":"MDQ6VXNlcjI0OTE4OTE=","avatar_url":"https://avatars2.githubusercontent.com/u/2491891?v=4","gravatar_id":"","url":"https://api.github.com/users/mrange","html_url":"https://github.com/mrange","followers_url":"https://api.github.com/users/mrange/followers","following_url":"https://api.github.com/users/mrange/following{/other_user}","gists_url":"https://api.github.com/users/mrange/gists{/gist_id}","starred_url":"https://api.github.com/users/mrange/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mrange/subscriptions","organizations_url":"https://api.github.com/users/mrange/orgs","repos_url":"https://api.github.com/users/mrange/repos","events_url":"https://api.github.com/users/mrange/events{/privacy}","received_events_url":"https://api.github.com/users/mrange/received_events","type":"User","site_admin":false},"labels":[{"id":275722914,"node_id":"MDU6TGFiZWwyNzU3MjI5MTQ=","url":"https://api.github.com/repos/dotnet/coreclr/labels/area-VM","name":"area-VM","color":"d4c5f9","default":false},{"id":191917125,"node_id":"MDU6TGFiZWwxOTE5MTcxMjU=","url":"https://api.github.com/repos/dotnet/coreclr/labels/tenet-performance","name":"tenet-performance","color":"c2e0c6","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":9,"created_at":"2018-06-07T22:49:58Z","updated_at":"2018-06-10T18:04:35Z","closed_at":null,"author_association":"NONE","body":"I am very excited about Tiered Compilation in dotnet core so I decided to take it for a spin. Unfortunately in my case I found a performance degradation from 370 ms to 540 ms\r\n\r\n## My dotnet version:\r\n\r\n```\r\n> dotnet --version\r\n2.1.300\r\n```\r\n\r\n##  My use-case\r\n\r\nI am tinkering with a push stream in F#.  Push streams are faster than Pull streams (like LINQ). One area where .NET JIT loses against JVM JIT is that .NET JIT is less keen on inlining. With Tiered Compilation I was hoping to see improved inlining improving performance.\r\n\r\n\r\nEssentially the degradation seems to boil down to that there is an extra jmp in the call chain (as far as I understood this is due to the new jitter introducing an level stub to track stats). I was expected this jmp being eliminated after warmup phase. As the stub don't do any stats tracking it seems to be the final optimized stub to me.\r\n\r\n## Finally time for some assembly code:\r\n\r\n```\r\n; Top level loop, this identical regardless of COMPlus_TieredCompilation\r\n00007ffc`d5d88ece 3bdf            cmp     ebx,edi\r\n00007ffc`d5d88ed0 7f13            jg      00007ffc`d5d88ee5\r\n00007ffc`d5d88ed2 488bce          mov     rcx,rsi\r\n00007ffc`d5d88ed5 8bd3            mov     edx,ebx\r\n00007ffc`d5d88ed7 488b06          mov     rax,qword ptr [rsi]\r\n00007ffc`d5d88eda 488b4040        mov     rax,qword ptr [rax+40h]\r\n; Virtual call to next step in the push stream\r\n00007ffc`d5d88ede ff5020          call    qword ptr [rax+20h]\r\n00007ffc`d5d88ee1 ffc3            inc     ebx\r\n00007ffc`d5d88ee3 ebe9            jmp     00007ffc`d5d88ece\r\n\r\n; The virtual call ends up here which seems left overs from the stats tracking stub.\r\n; This is not present when COMPlus_TieredCompilation=0\r\n00007ffc`d5d88200 e9bb080000      jmp     00007ffc`d5d88ac0\r\n\r\n; The next step in the push stream\r\n00007ffc`d5d88ac0 488b4908        mov     rcx,qword ptr [rcx+8] ds:0000023a`000124c0=0000023a000124a0\r\n00007ffc`d5d88ac4 4863d2          movsxd  rdx,edx\r\n00007ffc`d5d88ac7 488b01          mov     rax,qword ptr [rcx]\r\n00007ffc`d5d88aca 488b4040        mov     rax,qword ptr [rax+40h]\r\n00007ffc`d5d88ace 488b4020        mov     rax,qword ptr [rax+20h]\r\n00007ffc`d5d88ad2 48ffe0          jmp     rax\r\n```\r\n\r\nSo with Tiered compilation I was hoping for the virtual call to be eliminated (as is the case in JVM JIT) instead I got a performance degradation from 370 ms to 540 ms.\r\n\r\nPerhaps I should wait for some more detailed posts on Tiered Compilation as promised here: https://blogs.msdn.microsoft.com/dotnet/2018/05/30/announcing-net-core-2-1/\r\n\r\nHowever, I am quite excited about Tiered Compilation so I wanted to get an early start. Hopefully you tell me I made a mistake.\r\n\r\n## My F# code:\r\n\r\n```\r\nmodule TrivialStream =\r\n  // The trivial stream is a very simplistic push stream that doesn't support\r\n  //  early exits (useful for first)\r\n  //  The trivial stream is useful as basic stream to measure performance against\r\n\r\n  type Receiver<'T> = 'T            -> unit\r\n  type Stream<'T>   = Receiver<'T>  -> unit\r\n\r\n  module Details =\r\n    module Loop =\r\n      // This way to iterate seems to be faster in F#4 than a while loop\r\n      let rec range s e r i = if i <= e then r i; range s e r (i + s)\r\n\r\n  open Details\r\n\r\n  // Sources\r\n\r\n  let inline range b s e : Stream<int> =\r\n    fun r -> Loop.range s e r b\r\n\r\n  // Pipes\r\n\r\n  let inline filter (f : 'T -> bool) (s : Stream<'T>) : Stream<'T> =\r\n    fun r -> s (fun v -> if f v then r v)\r\n\r\n  let inline map (m : 'T -> 'U) (s : Stream<'T>) : Stream<'U> =\r\n    fun r -> s (fun v -> r (m v))\r\n\r\n  // Sinks\r\n\r\n  let inline sum (s : Stream<'T>) : 'T =\r\n    let mutable ss = LanguagePrimitives.GenericZero\r\n    s (fun v -> ss <- ss + v)\r\n    ss\r\n\r\nmodule PerformanceTests =\r\n  open System\r\n  open System.Diagnostics\r\n  open System.IO\r\n\r\n  let now =\r\n    let sw = Stopwatch ()\r\n    sw.Start ()\r\n    fun () -> sw.ElapsedMilliseconds\r\n\r\n  let time n a =\r\n    let inline cc i       = GC.CollectionCount i\r\n\r\n    let v                 = a ()\r\n\r\n    GC.Collect (2, GCCollectionMode.Forced, true)\r\n\r\n    let bcc0, bcc1, bcc2  = cc 0, cc 1, cc 2\r\n    let b                 = now ()\r\n\r\n    for i in 1..n do\r\n      a () |> ignore\r\n\r\n    let e = now ()\r\n    let ecc0, ecc1, ecc2  = cc 0, cc 1, cc 2\r\n\r\n    v, (e - b), ecc0 - bcc0, ecc1 - bcc1, ecc2 - bcc2\r\n\r\n  let trivialTest n =\r\n    TrivialStream.range       0 1 n\r\n    |> TrivialStream.map      int64\r\n    |> TrivialStream.filter   (fun v -> v &&& 1L = 0L)\r\n    |> TrivialStream.map      ((+) 1L)\r\n    |> TrivialStream.sum\r\n\r\n  let imperativeTest n =\r\n    let rec loop s i =\r\n      if i >= 0L then\r\n        if i &&& 1L = 0L then\r\n          loop (s + i + 1L) (i - 1L)\r\n        else\r\n          loop s (i - 1L)\r\n      else\r\n        s\r\n    loop 0L (int64 n)\r\n\r\n  let test (path : string) =\r\n    printfn \"Running performance tests...\"\r\n\r\n    let testCases =\r\n      [|\r\n//        \"imperative\"  , imperativeTest\r\n        \"trivialpush\" , trivialTest\r\n      |]\r\n\r\n    do\r\n      let warmups = 100\r\n      printfn \"Warming up...\"\r\n      for name, a in testCases do\r\n        time warmups (fun () -> a warmups) |> ignore\r\n\r\n    use out                   = new StreamWriter (path)\r\n    let write (msg : string)  = out.WriteLine msg\r\n    let writef fmt            = FSharp.Core.Printf.kprintf write fmt\r\n\r\n    write \"Name\\tTotal\\tOuter\\tInner\\tElapsed\\tCC\\tCC0\\tCC1\\tCC2\\tResult\"\r\n\r\n    let total   = 100000000\r\n    let outers =\r\n      [|\r\n        10\r\n        1000\r\n        1000000\r\n      |]\r\n    for outer in outers do\r\n      let inner = total / outer\r\n      for name, a in testCases do\r\n        printfn \"Running %s with total=%d, outer=%d, inner=%d ...\" name total outer inner\r\n        let v, ms, cc0, cc1, cc2 = time outer (fun () -> a inner)\r\n        let cc = cc0 + cc1 + cc2\r\n        printfn \"  ... %d ms, cc=%d, cc0=%d, cc1=%d, cc2=%d, result=%A\" ms cc cc0 cc1 cc2 v\r\n        writef \"%s\\t%d\\t%d\\t%d\\t%d\\t%d\\t%d\\t%d\\t%d\\t%d\" name total outer inner ms cc cc0 cc1 cc2 v\r\n\r\n    printfn \"Performance tests completed\"\r\n\r\n[<EntryPoint>]\r\nlet main argv =\r\n//  printfn \"Attach debugger and hit a key\"\r\n//  System.Console.ReadKey () |> ignore\r\n  PerformanceTests.test \"perf.tsv\"\r\n  0\r\n```\r\n"},"comment":{"url":"https://api.github.com/repos/dotnet/coreclr/issues/comments/396069004","html_url":"https://github.com/dotnet/coreclr/issues/18361#issuecomment-396069004","issue_url":"https://api.github.com/repos/dotnet/coreclr/issues/18361","id":396069004,"node_id":"MDEyOklzc3VlQ29tbWVudDM5NjA2OTAwNA==","user":{"login":"AndyAyersMS","id":10121823,"node_id":"MDQ6VXNlcjEwMTIxODIz","avatar_url":"https://avatars1.githubusercontent.com/u/10121823?v=4","gravatar_id":"","url":"https://api.github.com/users/AndyAyersMS","html_url":"https://github.com/AndyAyersMS","followers_url":"https://api.github.com/users/AndyAyersMS/followers","following_url":"https://api.github.com/users/AndyAyersMS/following{/other_user}","gists_url":"https://api.github.com/users/AndyAyersMS/gists{/gist_id}","starred_url":"https://api.github.com/users/AndyAyersMS/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/AndyAyersMS/subscriptions","organizations_url":"https://api.github.com/users/AndyAyersMS/orgs","repos_url":"https://api.github.com/users/AndyAyersMS/repos","events_url":"https://api.github.com/users/AndyAyersMS/events{/privacy}","received_events_url":"https://api.github.com/users/AndyAyersMS/received_events","type":"User","site_admin":false},"created_at":"2018-06-10T18:04:35Z","updated_at":"2018-06-10T18:04:35Z","author_association":"MEMBER","body":"A bit more hacking and I can get `trivialTest@66:Invoke(int):ref:this` to inline... inlining below that point is now blocked because this method makes a virtual call via its field. Even though we see the ctor above we can't propagate info down.\r\n\r\nPerf improves slightly:\r\n```\r\nIgnore arg store + allow explicit tail call inline\r\n\r\n  ... 362 ms, cc=0, cc0=0, cc1=0, cc2=0, result=25000010000001L\r\n  ... 362 ms, cc=0, cc0=0, cc1=0, cc2=0, result=2500100001L\r\n  ... 513 ms, cc=26, cc0=26, cc1=0, cc2=0, result=2601L\r\n```\r\nOdd tiering perf might be from using a CHK jit -- it will be slower to rejit and so the faster tier1 code won't get patched in quite as quickly. Will need to redo with a release build ."}}
{"actor":{"display_login":"AndyAyersMS"}}