Re: cloud_controller_ng performance degrades slowly over time
Matt Cholick
Looks like you're right and we're experiencing the same issue as you are
toggle quoted message
Show quoted text
Amit. We're suffering slow DNS lookups. The code is spending all of its time here: /var/vcap/packages/ruby-2.1.6/lib/ruby/2.1.0/net/http.rb.initialize :879 I've experimented some with the environment and, after narrowing things down to DNS, here's some minimal demonstrating the problem: require "net/http" require "uri" # uri = URI.parse("http://uaa.example.com/info") uri = URI.parse("https://www.google.com") i = 0 while true do beginning_time = Time.now response = Net::HTTP.get_response(uri) end_time = Time.now i+=1 puts "#{"%04d" % i} Response: [#{response.code}], Elapsed: #{((end_time - beginning_time)*1000).round} ms" end I see the issue hitting both UAA and just hitting Google. At some point, requests start taking 5 second longer, which I assume is a timeout. One run: 0349 Response: [200], Elapsed: 157 ms 0350 Response: [200], Elapsed: 169 ms 0351 Response: [200], Elapsed: 148 ms 0352 Response: [200], Elapsed: 151 ms 0353 Response: [200], Elapsed: 151 ms 0354 Response: [200], Elapsed: 152 ms 0355 Response: [200], Elapsed: 153 ms 0356 Response: [200], Elapsed: 6166 ms 0357 Response: [200], Elapsed: 5156 ms 0358 Response: [200], Elapsed: 5158 ms 0359 Response: [200], Elapsed: 5156 ms 0360 Response: [200], Elapsed: 5156 ms 0361 Response: [200], Elapsed: 5160 ms 0362 Response: [200], Elapsed: 5172 ms 0363 Response: [200], Elapsed: 5157 ms 0364 Response: [200], Elapsed: 5165 ms 0365 Response: [200], Elapsed: 5157 ms 0366 Response: [200], Elapsed: 5155 ms 0367 Response: [200], Elapsed: 5157 ms Other runs are the same. How many requests it takes before things time out varies considerably (one run started in the 10s and another took 20k requests), but it always happens. After that, lookups take an additional 5 second and never recover to their initial speed. This is why restarting the cloud controller fixes the issue (temporarily). The really slow cli calls (in the 1+min range) are simply due to the amount of paging that a fetching data for a large org does, as that 5 seconds is multiplied out over several calls. Every user is feeling this delay, it's just that it's only unworkable pulling the large datasets from UAA. I was not able to reproduce timeouts using a script calling "dig" against localhost, only inside a ruby code. The re-iterate our setup: we're running 212 without a consul server, just the agents. I also successfully reproduce this problem in completely different 217 install in a different datacenter. This setup also didn't have an actual consul server, just the agent. I don't see anything in the release notes past 217 indicating that this is fixed. Anyone have thoughts? This is definitely creating some real headaches for user management in our larger orgs. Amit: is there a bug we can follow? -Matt On Fri, Oct 9, 2015 at 10:52 AM, Amit Gupta <agupta(a)pivotal.io> wrote:
You may not be running any consul servers, but you may have a consul agent |
|