Re: Help with analysing JIT perf report

Hi

PAUSE instruction is probably part of the spinlock. This would imply that a
spinlock is busy-waiting a lot

Jaka

On Wed, 23 Jun 2021 at 11:00, Max Lapshin <[email protected]> wrote:

> I've clicked 'a' on this erts_schedule and see following:
>
>
> Percent│        mov    erts_msacc_enabled,%eax
>        │        movq   $0x0,0x20(%rsp)
>        │        test   %eax,%eax
>        │      ↓ je     7e3
>        │        mov    erts_msacc_key,%edi
>        │      → callq  ethr_tsd_get
>        │        mov    %rax,0x20(%rsp)
>        │ 7e3:   test   %ebx,%ebx
>        │        movl   $0x1,0x18(%rsp)
>        │      ↓ jne    1702
>        │ 7f3:   mov    0xb0(%r14),%eax
>        │        test   %eax,%eax
>        │      ↓ je     1660
>        │        movabs $0x7fffffffffffffff,%r13
>        │        xor    %ebx,%ebx
>        │ 80e:   mov    $0x64,%edx
>        │      ↓ jmp    826
>   4.73 │ 815:   subl   $0x1,0x2c(%rsp)
>   1.64 │        mov    0x2c(%rsp),%eax
>   1.31 │     ┌──test   %eax,%eax
>        │     ├──jle    15a0
>   0.03 │ 826:│  mov    0x18(%rbp),%r12d
>   0.01 │     │  mov    %r12d,%eax
>        │     │  and    $0x9,%eax
>   0.67 │     │  cmp    $0x9,%eax
>        │     │↓ jne    15a0
>  86.62 │     │  pause
>   0.06 │     │  sub    $0x1,%edx
>   3.92 │     │↑ jne    815
>   0.16 │     │→ callq  sched_yield@plt
>   0.00 │     │  test   %eax,%eax
>        │     │  mov    $0x64,%edx
>
>
>
>
> 82% on some instruction pause
>
> I will try to run this again on non-lcnt beam, but seems that this is
> somewhere around spinlock?
>
> On Wed, Jun 23, 2021 at 11:39 AM Max Lapshin <[email protected]>
> wrote:
> >
> > Perf report shows me things that I cannot analyse:
> >
> >
> > +   63.85%    51.25%  streamer  beam.lcnt.smp           [.] erts_schedule
> > +   59.99%     0.02%  streamer  beam.lcnt.smp           [.]
> > erts_dirty_process_main
> > +   29.50%     0.04%  streamer  jitted-881027-8664.so   [.]
> > gen_server:handle_msg/6
> > +   25.66%     0.04%  streamer  jitted-881027-34178.so  [.]
> > mpts_reader:handle_info/2
> >
> >
> > mpts_reader is my code and thanks for pointing out to me that it seems
> > to be the CPU eater.
> >
> > I cannot understand what means that erts_schedule takes 63 / 51% of time.
> > Is erts_schedule a container to all functions below?
>