<div dir="ltr"> Hi Lukas, sorry for responding this late to you. I dont have yet all the information but I ought to send you a reply. <div> See my replies in-line:</div><br><div class="gmail_quote"><div dir="ltr">On Thu, Jul 19, 2018 at 11:51 AM Lukas Larsson <<a href="mailto:lukas@erlang.org">lukas@erlang.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">Hello,<br><br><div class="gmail_quote"><div dir="ltr">On Wed, Jul 18, 2018 at 5:34 AM Marcial Rosales <<a href="mailto:mrosales@pivotal.io" target="_blank">mrosales@pivotal.io</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div><span style="color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;float:none;display:inline">We are experiencing a very high cpu utilization in 3 clustered Erlang VMs running RabbitMQ. We have deployed another cluster in an attempt to reproduce the same behaviour without much success.</span><br></div><div><span style="color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;float:none;display:inline"><br></span></div><div><p style="box-sizing:border-box;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;text-decoration-style:initial;text-decoration-color:initial">Our goals are:</p><ul style="box-sizing:border-box;padding-left:2em;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;text-decoration-style:initial;text-decoration-color:initial"><li style="box-sizing:border-box">Find out where the CPU is being utilized</li><li style="box-sizing:border-box;margin-top:0.25em">Choose the right tools to analyze CPU utilization</li></ul><br class="m_3757868884577647726gmail-m_-6428393931756314844gmail-Apple-interchange-newline"><p style="box-sizing:border-box;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;text-decoration-style:initial;text-decoration-color:initial">Our observations so far:</p><ul style="box-sizing:border-box;padding-left:2em;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;text-decoration-style:initial;text-decoration-color:initial"><li style="box-sizing:border-box">The<span> </span><strong style="box-sizing:border-box;font-weight:600">BAD</strong><span> </span>cluster observes a pretty excessive CPU utilization, both user and system ones, and also network.</li><li style="box-sizing:border-box;margin-top:0.25em">The<span> </span><strong style="box-sizing:border-box;font-weight:600">BAD</strong><span> </span>cluster also observes a higher Erlang scheduler utilization, specially on microstate<span> </span><code style="box-sizing:border-box;font-family:SFMono-Regular,Consolas,"Liberation Mono",Menlo,Courier,monospace;font-size:13.6px;padding:0.2em 0.4em;margin:0px;background-color:rgba(27,31,35,0.05);border-radius:3px">emulator</code><span> </span>and<span> </span><code style="box-sizing:border-box;font-family:SFMono-Regular,Consolas,"Liberation Mono",Menlo,Courier,monospace;font-size:13.6px;padding:0.2em 0.4em;margin:0px;background-color:rgba(27,31,35,0.05);border-radius:3px">other</code>. We are yet to understand what<span> </span><code style="box-sizing:border-box;font-family:SFMono-Regular,Consolas,"Liberation Mono",Menlo,Courier,monospace;font-size:13.6px;padding:0.2em 0.4em;margin:0px;background-color:rgba(27,31,35,0.05);border-radius:3px">other</code><span> </span>could be. According to Erlang documentation is<span> </span><em style="box-sizing:border-box">unaccounted things</em>.</li></ul></div></div></blockquote><div>If you compile Erlang with "./configure --with-microstate-accounting=extra" (as suggested by Danil), the <font face="monospace, monospace">other</font> part will be broken into more granular parts. However, looking at your perf recordings I would guess that most of the other time is time spent spinning before going to sleep.</div><div> </div></div></div></blockquote><div>MR > Thanks! We are going to recompile Erlang with lock counting and extra microstate-accounting. Hopefully we can get more visibility the next time we get a cluster in that bad state.</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div><ul style="box-sizing:border-box;padding-left:2em;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;text-decoration-style:initial;text-decoration-color:initial"><li style="box-sizing:border-box;margin-top:0.25em">The<span> </span><strong style="box-sizing:border-box;font-weight:600">BAD</strong><span> </span>cluster observes a considerably higher number of system calls which we are yet to identify (dunno how) why is that.</li></ul></div></div></blockquote><div>Maybe use strace and then write some small script that counts the different syscall made?</div></div></div></blockquote><div><br></div><div>MR >  The strace reports that 97% of the calls are `futex`, should that helped. </div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div class="gmail_quote"><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div><ul style="box-sizing:border-box;padding-left:2em;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px;text-decoration-style:initial;text-decoration-color:initial"><li style="box-sizing:border-box;margin-top:0.25em">The<span> </span><strong style="box-sizing:border-box;font-weight:600">BAD</strong><span> </span>cluster does not necessarily run higher number of reductions. In fact, the<span> </span><strong style="box-sizing:border-box;font-weight:600">GOOD</strong><span> </span>cluster runs more reductions and yet has a lower scheduler utilization.</li></ul><div><font color="#24292e" face="-apple-system, system-ui, Segoe UI, Helvetica, Arial, sans-serif, Apple Color Emoji, Segoe UI Emoji, Segoe UI Symbol"><span style="font-size:16px"><table style="box-sizing:border-box;border-collapse:collapse;margin-top:0px;margin-bottom:16px;display:block;width:888px;overflow:auto;text-decoration-style:initial;text-decoration-color:initial"><thead style="box-sizing:border-box"><tr style="box-sizing:border-box;background-color:rgb(255,255,255);border-top:1px solid rgb(198,203,209)"><th style="box-sizing:border-box;padding:6px 13px;font-weight:600;border:1px solid rgb(223,226,229)">METRIC</th><th style="box-sizing:border-box;padding:6px 13px;font-weight:600;border:1px solid rgb(223,226,229)">BAD</th><th style="box-sizing:border-box;padding:6px 13px;font-weight:600;border:1px solid rgb(223,226,229)">GOOD</th></tr></thead><tbody style="box-sizing:border-box"><tr style="box-sizing:border-box;background-color:rgb(255,255,255);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#dstat" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">user cpu</a></td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">46% - 57%</td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">19% - 40%</td></tr><tr style="box-sizing:border-box;background-color:rgb(246,248,250);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#dstat" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">system cpu</a></td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">20% - 37%</td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">1% - 10%</td></tr><tr style="box-sizing:border-box;background-color:rgb(255,255,255);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#dstat" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">network traffic</a></td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">6M - 19M</td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">up to 8M</td></tr><tr style="box-sizing:border-box;background-color:rgb(246,248,250);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#dstat" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">system interrupts</a></td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">120k - 196k</td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">10k - 20k</td></tr><tr style="box-sizing:border-box;background-color:rgb(255,255,255);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#syscalls" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">syscalls</a></td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">1.6M - 2.1M</td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">49k - 110k</td></tr><tr style="box-sizing:border-box;background-color:rgb(246,248,250);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#perf-stat" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">task-clock 10sec</a></td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">68255</td><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)">12324</td></tr><tr style="box-sizing:border-box;background-color:rgb(255,255,255);border-top:1px solid rgb(198,203,209)"><td style="box-sizing:border-box;padding:6px 13px;border:1px solid rgb(223,226,229)"><a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841#perf_record_cpu_cycles" style="box-sizing:border-box;background-color:transparent;color:rgb(3,102,214);text-decoration:none" target="_blank">cpu profiling info</a></td></tr></tbody></table></span></font></div><div><br></div></div><div><p style="background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;box-sizing:border-box;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px">We have gathered lots of metrics in attempt to identify why the BAD cluster uses so much CPU. All the information can be found here <a href="https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841" target="_blank">https://gist.github.com/MarcialRosales/226716f0cb9e27cd9ab02eac04702841</a>  along with the environment information.</p><p style="background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;box-sizing:border-box;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px"><br></p></div></div></blockquote><div>In the BAD cluster, would it be possible to see the annotated versions of process_main and scheduler_wait in the "perf record" run?</div></div></div></blockquote><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div class="gmail_quote"><div>There doesn't seem to be any kernel symbols in the BAD cluster perf run, do you know why?</div></div></div></blockquote><div><br></div><div>MR> I dont really know. We are running with the same OS image. Any ideas what could that be?</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div class="gmail_quote"><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div><p style="background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;box-sizing:border-box;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px"></p><p style="background-color:rgb(255,255,255);text-decoration-style:initial;text-decoration-color:initial;box-sizing:border-box;margin-top:0px;margin-bottom:16px;color:rgb(36,41,46);font-family:-apple-system,system-ui,"Segoe UI",Helvetica,Arial,sans-serif,"Apple Color Emoji","Segoe UI Emoji","Segoe UI Symbol";font-size:16px">We appreciate a lot any insights as to what could be causing the issue and/or in relation to additional tools we could use.</p></div></div></blockquote><div>My gut tells me that there is some syscall that is a lot slower on XEN than it is in the KVM. In virtualized environments I always tend to suspect the time source first. Different hypervisors have very different performance for getting the time and the Erlang VM does a lot of time fetching.</div><div><br></div></div></div></blockquote><div>MR> We are in the process of provisioning a cluster in AWS in an attempt to discard or confirm the hypervisor.</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div class="gmail_quote"><div></div><div>Lukas</div></div></div>
</blockquote></div><br clear="all"><div><br></div>-- <br><div dir="ltr" class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr"><div><div dir="ltr"><span style="color:rgb(80,0,80);font-size:12.8000001907349px">Marcial Rosales</span><div style="color:rgb(80,0,80);font-size:12.8000001907349px"><span style="font-size:12.8000001907349px;color:rgb(34,34,34)">Advisory Solution Architect (</span><span style="font-size:12.8000001907349px">Customer Success Organization)</span></div><div style="color:rgb(80,0,80);font-size:12.8000001907349px">Pivotal, Inc.  EMEA</div></div><div dir="ltr"><br><div><br></div></div></div></div></div></div>