<div dir="ltr">Hi,<div>are you using +sbt? If not, try use +sbt with default +sbwt. If you observe CPU cost but without drop of latencies, there is possibilitty, that your load characteristic with busy wait provoke some pathologcal scheduler migration (perfomed by OS) which results in your latency problems. It is just blind guess but worth to try.</div><div>Hynek</div></div><div class="gmail_extra"><br><div class="gmail_quote">On Tue, Sep 1, 2015 at 9:16 AM, Paul Davis <span dir="ltr"><<a href="mailto:paul.joseph.davis@gmail.com" target="_blank">paul.joseph.davis@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hey everyone,<br>
<br>
Lately at IBM/Cloudant we've been doing cluster upgrades from R14B01<br>
to 17.5 (don't ask) and we've been noticing a fairly decent increase<br>
in total CPU usage. The recent upgrades have actually included a two<br>
step upgrade between three versions which I'll call A, B, and C.<br>
Version A is our most recent production release on R14B01, version B<br>
is a compatibility release with minor changes that still runs on<br>
R14B01, and version C is exactly version B code except for the upgrade<br>
to the 17.5 emulator. Each upgrade in the series involves a rolling<br>
reboot of the entire cluster which involves anywhere from three to<br>
twenty or so nodes at this point.<br>
<br>
What we've observed is that each step in the upgrade process tends to<br>
increase the CPU usage across the cluster noticeably. There's some<br>
obvious CPU issues with a rolling reboot in our clusters that we<br>
expect but the end result as been a significant jump in system CPU<br>
usage between A and C. Generally speaking we're seeing A running<br>
around 6-12% system CPU and version C running around 50% system CPU<br>
usage.<br>
<br>
When I first saw this my first thought was that it was just the busy<br>
wait scheduling that has been discussed occasionally on this list.<br>
Testing had shown a slight decrease in performance between R14B01 and<br>
17.5 but it was roughly within in the margin of error as well as not<br>
being the most awesome representation of real user load. Given that we<br>
pushed through some less busy clusters and everything appeared to<br>
match with my expectations, namely increased CPU usage without any<br>
observable effects to the outside world.<br>
<br>
Unfortunately we had two clusters that had previously been running<br>
fairly hot and after the upgrade response latencies jumped<br>
significantly. Internal metrics showed latencies increasing by an<br>
order of magnitude as well as having significantly higher variance.<br>
<br>
On one cluster we ended up rolling back from C to A to try and undo<br>
the latency issues which ended up having little effect on total<br>
latencies. We did manage to change which parts of the database were<br>
having latency issues but overall it was an unfun operational<br>
experience.<br>
<br>
So that's the background, here are some obvservations that I've been<br>
collecting to try and narrow down the issue.<br>
<br>
Our first data point was to try and look at strace. What we noticed<br>
was that scheduler threads seemed to spend an inordinate amount of<br>
time in futex system calls. An strace run on a scheduler thread showed<br>
more than 50% of time in futex sys calls.<br>
<br>
On one of our dedicated clusters we ended up disabling the async<br>
thread pool (brilliant idea via Adam Kocoloski). While this had a<br>
super awesome impact on observed latencies for the cluster, CPU usage<br>
remained roughly the same with ~50% of CPU usage attributed to system<br>
CPU. Of note this cluster is a 9 node cluster with dual hex cores with<br>
hyperthreading for a total of 24 scheduler threads as well as a four<br>
SSD RAID 10 array for disk. My general thought here was that while it<br>
didn't necessarily fix the underlying issue, SSDs without an async<br>
thread pool made things fast enough to get back to roughly normal on<br>
this cluster.<br>
<br>
The second major data point was a similarly spec'ed cluster except<br>
that instead of SSD's it had HDDs in the same RAID configuration.<br>
Attempting to help fix latencies we made the same change to disable<br>
the async thread pool. The change appeared to make the cluster faster<br>
but there wasn't a significant change in latencies for the cluster.<br>
There was an observable increase in throughput for the entire cluster<br>
but as in all distributed systems it was a bit hard to deconvolve the<br>
various signals.<br>
<br>
Given these two data points I decided to try looking at the VM flags<br>
that might be major behavior changes between R14B01 and 17.5. The<br>
flags I decided to try setting were "+sbwt none +secio false +sws<br>
legacy" (from memory). I applied those to one node on the MT cluster<br>
and it resulted in an immediate change from roughly fifty to six-ish<br>
percent on CPU usage.<br>
<br>
Once I saw the drastic change in CPU I replaced the change to just<br>
"+sbwt none" and saw no change in CPU usage which suggested that the<br>
sbwt change was entirely responsible for the change. After letting the<br>
cluster run I also tried using "+sbwt very_low" which resulted in a<br>
noticeable increase in system CPU but nowhere near the ~50% system CPU<br>
default.<br>
<br>
The MT cluster I did the initial +sbwt change on was the multi-tenant<br>
cluster so its hard to make too many conclusions given the roughly<br>
random work load. What I did do was check that very_low increased the<br>
system CPU usage noticeably and that default put it back to 50%.<br>
During these experiments our various latency metrics seemed to respond<br>
but distributed systems, so its hard to draw direct conclusions.<br>
<br>
However, given my observations I was pretty certain that the +sbwt<br>
setting was directly affecting system CPU usage. The general theory<br>
I've been working on is that something with Erlang's elevated system<br>
CPU usage is causing my observed latencies to increase. Given that, I<br>
set +sbwt none to one of our problematic clusters. The initial<br>
response to this change was a significant increase in throughput of<br>
background tasks on the cluster. Once those cleared out the cluster<br>
latencies have settled back into the previous R14B01 levels.<br>
<br>
My general question at this point is wether scheduler busy wait has an<br>
intrinsic cost that's not reflected in the documentation. From what<br>
I've seen is that we end up with a large amount of system CPU usage<br>
that dampens user CPU usage of beam.smp which in our case affects<br>
system latencies. We have a fairly intense port/file driver usage<br>
which may affect the issue. Disabling busy wait fixes things and that<br>
confuses me.<br>
<br>
Any thoughts or similar observations would be awesomely appreciated. I<br>
think I can see how +sbwt values affect a VM but I'm fairly confused<br>
why reverting back to R14 didn't rectify things. I'm really hoping<br>
someone remembers a scheduler bug around this area for that part of<br>
the story.<br>
<br>
I'll buy many beers at the next conference for anyone that makes me<br>
think I'm not insane in all this.<br>
_______________________________________________<br>
erlang-questions mailing list<br>
<a href="mailto:erlang-questions@erlang.org">erlang-questions@erlang.org</a><br>
<a href="http://erlang.org/mailman/listinfo/erlang-questions" rel="noreferrer" target="_blank">http://erlang.org/mailman/listinfo/erlang-questions</a><br>
</blockquote></div><br></div>