<div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote">On Wed, Aug 17, 2016 at 5:03 PM, Danil Zagoskin <span dir="ltr"><<a href="mailto:z@gosk.in" target="_blank">z@gosk.in</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(204,204,204);padding-left:1ex"><div dir="ltr">After reducing ETS load I see a new lock coming up — now it's one of 1024 pix_lock's:<div><br><div><div><font face="monospace, monospace">(<a href="mailto:flussonic@127.0.0.1" target="_blank">flussonic@127.0.0.1</a>)3> lcnt:apply(timer, sleep, [5000]), lcnt:swap_pid_keys(), lcnt:conflicts([{max_locks, 5}]).</font></div><span class=""><div><font face="monospace, monospace">                         lock   id  #tries  #collisions  collisions [%]  time [us]  duration [%]</font></div></span><span class=""><div><font face="monospace, monospace">                        -----  --- ------- ------------ --------------- ---------- -------------</font></div></span><div><font face="monospace, monospace"> <flussonic@127.0.0.1.7221.0>    6    6403          686         10.7137    5550663      109.9727</font></div><div><font face="monospace, monospace">                     pix_lock 1024    1330            1          0.0752    1481334       29.3490</font></div><div><font face="monospace, monospace">                    run_queue   42 3394894        82843          2.4402     171155        3.3910</font></div><div><font face="monospace, monospace">                      pollset    1  162867        10714          6.5784      88266        1.7488</font></div><div><font face="monospace, monospace">                       db_tab  181  135250          759          0.5612      62164        1.2316</font></div><div><font face="monospace, monospace">ok</font></div></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace"><div>(<a href="mailto:flussonic@127.0.0.1" target="_blank">flussonic@127.0.0.1</a>)5> lcnt:inspect(pix_lock, [{max_locks, 5}]).</div><span class=""><div>     lock  id  #tries  #collisions  collisions [%]  time [us]  duration [%] histogram [log2(us)]</div><div>    ----- --- ------- ------------ --------------- ---------- ------------- ---------------------</div></span><div> pix_lock  53    1284            1          0.0779    1480359       29.3297 |              XX.  ........   |</div><div> pix_lock 895       4            0          0.0000        121        0.0024 |               X              |</div><div> pix_lock 862       4            0          0.0000         92        0.0018 |              X X             |</div><div> pix_lock 270       2            0          0.0000         83        0.0016 |                X             |</div><div> pix_lock 949       2            0          0.0000         70        0.0014 |                X             |</div><div>ok</div><div><br></div><div><div>(<a href="mailto:flussonic@127.0.0.1" target="_blank">flussonic@127.0.0.1</a>)8> lcnt:inspect(pix_lock, [{locations, true}, {combine, true}]).</div><div>lock: pix_lock</div><div>id:   1024</div><div>type: mutex</div><div>                      location  #tries  #collisions  collisions [%]  time [us]  duration [%] </div><div>                     --------- ------- ------------ --------------- ---------- ------------- </div><div> 'beam/erl_process_lock.h':422    1330            1          0.0752    1481334       29.3490 </div><div>                   undefined:0       0            0          0.0000          0        0.0000 </div><div>ok</div></div><div><br></div><div><br></div></font><div><br></div>The previously described proc_link/proc_status lock is still here.</div></div><div><br></div>The thing i find strange about pix_lock is that only one lock of 1024 is used and has a significant duration. Other ones have almost zero tries and duration.<div>The lock id is not constant — it changes over time.</div><div><br></div><div><br></div><div>May long pix_lock be a same problem as proc_link/proc_status?</div><div>Why can this happen?</div><div>What should we see next?<br><div><br></div></div></div></blockquote><div><br></div><div>The pix lock is taken when a contention on a proc_* lock has happened, so to get a conflict there is very rare, but it does happen. I'm not sure why the duration of the conflict is so long, is the result repeatable?<br></div><div><br></div><div>AS for the distribution of the pix_locks tries, the sample you have is quite small so it could just be a statistical anomaly, or something is incorrect in the hashing algo. IIRC it is the PID of the process that gets hashed somehow and used to figure out which pix_lock to take. Of course if it is only one process where all the contention happens, that process will hash to the same slot everytime, so maybe that is what is happening.</div><div> </div></div></div></div>