https://dev.arvados.org/https://dev.arvados.org/favicon.ico?15576888422015-04-15T21:38:55ZArvadosArvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=235102015-04-15T21:38:55ZWard Vandewegeward@curii.com
<ul><li><strong>Description</strong> updated (<a title="View differences" href="/journals/23510/diff?detail_id=22811">diff</a>)</li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=235132015-04-15T21:40:32ZWard Vandewegeward@curii.com
<ul><li><strong>Description</strong> updated (<a title="View differences" href="/journals/23513/diff?detail_id=22812">diff</a>)</li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=240762015-05-01T17:46:08ZWard Vandewegeward@curii.com
<ul><li><strong>Subject</strong> changed from <i>[Keep] in a scenario where Keep can't write to its disks, it sucks up 100% cpu and becomes really slow after a while</i> to <i>[Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a while</i></li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=241192015-05-02T00:17:19ZWard Vandewegeward@curii.com
<ul></ul><p>This doesn't appear to be related to r/o disks, I have seen it happen on tb05z as well, where all disks can be written.</p>
<p>While it was happening there, datamanager was trying to do its thing, and failing (), and restarting, over and over and over (due to <a class="issue tracker-1 status-3 priority-4 priority-default closed parent" title="Bug: [API] Be careful about memory usage when responding to collections#index queries (Resolved)" href="https://dev.arvados.org/issues/5834">#5834</a>).</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=241862015-05-05T19:28:45ZTom Cleggtom@curii.com
<ul><li><strong>Target version</strong> changed from <i>Bug Triage</i> to <i>2015-05-20 sprint</i></li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=242052015-05-06T14:15:23ZTom Cleggtom@curii.com
<ul><li><strong>Category</strong> set to <i>Keep</i></li><li><strong>Assigned To</strong> set to <i>Tom Clegg</i></li><li><strong>Priority</strong> changed from <i>Normal</i> to <i>High</i></li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=242162015-05-06T17:43:22ZTom Cleggtom@curii.com
<ul><li><strong>Status</strong> changed from <i>New</i> to <i>In Progress</i></li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=242182015-05-06T19:31:54ZTom Cleggtom@curii.com
<ul></ul><a name="a-memory-use-bug"></a>
<h3 >a memory use bug<a href="#a-memory-use-bug" class="wiki-anchor">¶</a></h3>
Currently, keepstore will allocate as many buffers as it has clients. There is no limit on the number of concurrent clients.
<ul>
<li>During a PUT request, the buffer grows (up to 64 mebibytes) while receiving data from the client, and of course has to last long enough to write the block to disk. When -serialize is enabled, this interval includes the "wait for serialize mutex" phase, which can last many seconds.</li>
<li>During a successful GET request, the buffer grows (up to 64 mebibytes) while reading data from disk and lasts long enough to verify the checksum and send the data to the client. Sending the data over the network can take many seconds (e.g., network congestion, slow client, slow network on the client side of a keepproxy).</li>
</ul>
<p>If keepstore gets busy enough to exceed the available disk bandwidth, the PUT requests waiting for the serialize mutex can exhaust available RAM and the kernel will start swapping some buffers out to disk. At this point, each additional request will make all queued requests slower and less likely to finish at all.</p>
<p>Additionally, if a client times out and disconnects while its request is waiting in the queue, keepstore won't notice this: abandoned PUT requests waste memory just by staying in the queue, and (assuming the worst) get swapped in and written to a volume before the dead connection is noticed; meanwhile abandoned GET requests waste disk activity and (albeit for a short time, between reading and the first Write call, which presumably fails) memory.</p>
<a name="proposed-improvement"></a>
<h3 >proposed improvement<a href="#proposed-improvement" class="wiki-anchor">¶</a></h3>
<p>Rather than allocating them on the fly, use a pool<sup><a href="#fn1">1</a></sup> of data buffers. The total number of buffers is configured with a command line flag. Whenever a handler needs a non-trivial buffer to store a data block -- for either PUT or GET -- it gets one from the pool. If the pool is empty, the request waits in a queue to get one.</p>
<p>This should be a reasonable way to limit keepstore's memory without unduly restricting operations that don't need much of it (like index, status, and GET 404).</p>
<p id="fn1" class="footnote"><sup>1</sup> probably based on <a class="external" href="http://golang.org/pkg/sync/#Pool">http://golang.org/pkg/sync/#Pool</a> -- maybe WaitingPool, wrapping Pool with Get() and Put() methods that use a sync.Cond to ensure size never goes above MaxSize.</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=242282015-05-06T20:40:03ZBrett Smithbrett.smith@curii.com
<ul></ul><p>Reviewing <a class="changeset" title="5748: Write index data to http.ResponseWriter, instead of using string concatenation to buffer th..." href="https://dev.arvados.org/projects/arvados/repository/arvados/revisions/4d53c7ea431ad5c20bfed54cd68d4518091574e8">4d53c7e</a>. This is good, just a couple cleanliness things.</p>
<ul>
<li>There are a couple of references to old Index name still lurking around: in the last sentence of the IndexTo doc comment, and in <code>gotCall()</code> in the MockVolume implementation.</li>
<li>In IndexTo, the comment "Print filenames beginning with prefix" seems misplaced right above a condition that skips this loop. Would it improve readability to merge that condition into the previous one? Or if not, move the comment down above the Fprintf?</li>
</ul>
<p>Assuming those are all patched straightforwardly, I'm happy to see this merged. Thanks.</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=243172015-05-08T14:22:15ZPeter Amstutzpeter.amstutz@curii.com
<ul></ul><p>Reviewing 5748-max-buffers <a class="changeset" title="5748: Return the real decoder error for unparseable trash and pull requests." href="https://dev.arvados.org/projects/arvados/repository/arvados/revisions/978afd40f92951aa2952ef4ad9ccbc07d2bf4a3e">978afd4</a></p>
<ul>
<li>The default <code>maxBuffers = 128</code> seems excessive (that's 8 GiB). With <code>serialize=true</code>, it should probably be a small multiple of the number of volumes (between 2 and 4 buffers per volume) since we can't do more concurrent work than we have volumes, and the goal here is to prevent keepstore from over committing on the number of requests it can handle at once (since it Gets the block from the buffer pool <strong>before</strong> taking the volume serialize lock).</li>
</ul>
<ul>
<li>Suggest moving bufferpool into the Go SDK, it might be useful for other services such as keepproxy.</li>
</ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=243272015-05-08T17:00:52ZTom Cleggtom@curii.com
<ul></ul><p>Peter Amstutz wrote:</p>
<blockquote>
<p>Reviewing 5748-max-buffers <a class="changeset" title="5748: Return the real decoder error for unparseable trash and pull requests." href="https://dev.arvados.org/projects/arvados/repository/arvados/revisions/978afd40f92951aa2952ef4ad9ccbc07d2bf4a3e">978afd4</a></p>
<ul>
<li>The default <code>maxBuffers = 128</code> seems excessive (that's 8 GiB). With <code>serialize=true</code>, it should probably be a small multiple of the number of volumes (between 2 and 4 buffers per volume) since we can't do more concurrent work than we have volumes, and the goal here is to prevent keepstore from over committing on the number of requests it can handle at once (since it Gets the block from the buffer pool <strong>before</strong> taking the volume serialize lock).</li>
</ul>
</blockquote>
<p>Not exactly. The goal here is to limit memory use, and memory (unlike the serialize lock) stays occupied longer when clients send/receive slowly. If you have 8 GiB of RAM, and you are waiting for 100 clients to receive the response data for their GET requests, you've got 6.4GiB of block data stored in buffers but the serialize locks are all free. Similarly, while you are waiting to receive PUT body content from 100 clients, you need buffers but you don't need any serialize locks yet. Essentially the minimum buffers:spindles ratio corresponds to the diskspeed:networkspeed ratio, and (especially since keepproxy pipelines reads instead of buffering them) that ratio can easily be much higher than 2 or 4. (If we could assume/detect that the network bottleneck is the keepstore node itself, it would be reasonable to stall new clients to help older clients finish, but we can't/don't.)</p>
<p>I thought "total system RAM ÷ block size" would be a good default, and a way to specify "50%" like sort(1) (perhaps based on <a class="external" href="https://godoc.org/github.com/cloudfoundry/gosigar#Mem.Get">https://godoc.org/github.com/cloudfoundry/gosigar#Mem.Get</a>) would probably be handy, but rather than overthink/predict this I figured we should start with a simple config knob and a probably-not-too-low default, and get operational feedback.</p>
<p>I figured it would be better to err on the "too big" side because the sysadmin story "keepstore is using too much ram" seems easier to understand than "clients are starved but keepstore looks idle". (Hm, perhaps the "waiting..." message should recommend increasing -max-buffers?)</p>
<blockquote>
<ul>
<li>Suggest moving bufferpool into the Go SDK, it might be useful for other services such as keepproxy.</li>
</ul>
</blockquote>
<p>True. I thought about this too, but figured we can do those things together (move it to SDK and adopt it in keepproxy) / we might confirm how well it works before we arrange too much more code around it...</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=243312015-05-08T17:27:49ZPeter Amstutzpeter.amstutz@curii.com
<ul></ul><p>Tom Clegg wrote:</p>
<blockquote>
<p>I figured it would be better to err on the "too big" side because the sysadmin story "keepstore is using too much ram" seems easier to understand than "clients are starved but keepstore looks idle". (Hm, perhaps the "waiting..." message should recommend increasing -max-buffers?)</p>
</blockquote>
<p>That's true, it's easy enough to configure the usage, the important thing will be to communicate to our admins that setting <code>-max-buffers</code> is not really optional, if it's not going to be smart about adjusting its default buffers to the RAM size of the system.</p>
<blockquote><blockquote>
<ul>
<li>Suggest moving bufferpool into the Go SDK, it might be useful for other services such as keepproxy.</li>
</ul>
</blockquote>
<p>True. I thought about this too, but figured we can do those things together (move it to SDK and adopt it in keepproxy) / we might confirm how well it works before we arrange too much more code around it...</p>
</blockquote>
<p>Ok, we should file a separate story for that, I think there have been some issues with memory usage of Keepproxy as well.</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=243602015-05-08T18:09:12ZTom Cleggtom@curii.com
<ul></ul><p>Peter Amstutz wrote:</p>
<blockquote>
<p>That's true, it's easy enough to configure the usage, the important thing will be to communicate to our admins that setting <code>-max-buffers</code> is not really optional, if it's not going to be smart about adjusting its default buffers to the RAM size of the system.</p>
</blockquote>
<p>True. Added a note to <a class="external" href="http://doc.arvados.org/install/install-keepstore.html">http://doc.arvados.org/install/install-keepstore.html</a>. (Probably a good idea to point this out even if/when we do default to total system RAM, in case the node is expected to have memory available for anything else.)</p>
<blockquote>
<p>Ok, we should file a separate story for that, I think there have been some issues with memory usage of Keepproxy as well.</p>
</blockquote>
<p>Added <a class="issue tracker-2 status-1 priority-4 priority-default" title="Feature: [Keep] Use bufferpool in keepproxy to limit memory use when there are many concurrent PUTs (New)" href="https://dev.arvados.org/issues/5962">#5962</a>.</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=243732015-05-08T18:49:30ZTom Cleggtom@curii.com
<ul><li><strong>Status</strong> changed from <i>In Progress</i> to <i>Feedback</i></li></ul> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=243782015-05-08T18:51:52ZPeter Amstutzpeter.amstutz@curii.com
<ul><li><strong>Status</strong> changed from <i>Feedback</i> to <i>In Progress</i></li></ul><p>aside from above comments LGTM, please merge</p> Arvados - Bug #5748: [Keep] sometimes, Keep sucks up 100% cpu and becomes really slow after a whilehttps://dev.arvados.org/issues/5748?journal_id=249272015-05-20T19:08:17ZTom Cleggtom@curii.com
<ul><li><strong>Status</strong> changed from <i>In Progress</i> to <i>Resolved</i></li></ul>