schneems
commented
8 years ago What do your production logs say? Did you go through the steps in https://github.com/schneems/derailed_benchmarks#running-in-production-locally?
Closed obromios closed 7 years ago
schneems
commented
8 years ago What do your production logs say? Did you go through the steps in https://github.com/schneems/derailed_benchmarks#running-in-production-locally?
obromios
commented
8 years ago I believe I followed the instructions for local server, including turning off config.force_ssl = true. I am using the rails_12factor gem, so according to your instructions, the log entries should come on SDOUT, which is what I pasted above. I am not seeing anything in log/production.log.
In the above output, the benchmark works for quite a few iterations, showing increased memory output before quitting, so at least initially the production server seems to be working.
richardvenneman
commented
8 years ago I had the same issue and eventually found that I configured conditional authentication in a production environment.
if ENV['BASIC_AUTH_STATUS'] == 'enabled'
config.middleware.insert_before(::Rack::Runtime, '::Rack::Auth::Basic', 'Restricted') do |u, p|
u == ENV['BASIC_AUTH_USER'] && p == ENV['BASIC_AUTH_PASS']
end
endIn my Figaro configuration I had a faulty value in place and that's why derailed yielded a "Bad Request". You can try running your web server and check if you can visit your app in a web browser:
SECRET_KEY_BASE=foo RAILS_ENV=production bundle exec rails sI am able to visit the app in the web browser, so it sounds like the cause of my issue is different from richardvenneman. Also, the benchmark runs for quite some time, outputting memory measurements before crashing.
schneems
commented
8 years ago Turn off logs to STDOUT, make sure they're going to your logs/production.log. You should see actual requests coming in like GET / and queries and stuff you would normally expect in logs. Once you get that you'll see what is happening that is causing your process to crash.
obromios
commented
8 years ago I took the rails_12factor out of my Gemfile, and restarted the production server. This time I was seeing the normal log information.
If I execute
USE_SERVER=puma bundle exec derailed exec perf:mem_over_time
it runs as described above, but also hits the same problem. I have put below an excerpt of the log immediately prior to the exception.
[2016-06-08T20:41:57.422757 #75960] INFO -- : Completed 302 Found in 9ms (ActiveRecord: 0.8ms)
I, [2016-06-08T20:41:57.423743 #75960] INFO -- : source=rack-timeout id=45780c87a335c82ecb4ec469340f5fb1 timeout=10000ms service=18ms state=completed
I, [2016-06-08T20:41:57.447779 #75960] INFO -- : source=rack-timeout id=a287c182f80a37720dd016b16a5f3d66 timeout=10000ms state=ready
I, [2016-06-08T20:41:57.448886 #75960] INFO -- : Started GET "/" for 127.0.0.1 at 2016-06-08 20:41:57 +1000
I, [2016-06-08T20:41:57.458592 #75960] INFO -- : Processing by PagesController#home as */*
I, [2016-06-08T20:41:57.468474 #75960] INFO -- : Redirected to http://localhost:3878/central/home
I, [2016-06-08T20:41:57.468863 #75960] INFO -- : Completed 302 Found in 10ms (ActiveRecord: 0.9ms)
I, [2016-06-08T20:41:57.470426 #75960] INFO -- : source=rack-timeout id=a287c182f80a37720dd016b16a5f3d66 timeout=10000ms service=23ms state=completed
I, [2016-06-08T20:41:57.507521 #75960] INFO -- : source=rack-timeout id=b52906d00e89d57cf9c6537ee56682c7 timeout=10000ms state=ready
I, [2016-06-08T20:41:57.509146 #75960] INFO -- : Started GET "/" for 127.0.0.1 at 2016-06-08 20:41:57 +1000
I, [2016-06-08T20:41:57.514607 #75960] INFO -- : Processing by PagesController#home as */*
I, [2016-06-08T20:41:57.521750 #75960] INFO -- : Redirected to http://localhost:3878/central/home
I, [2016-06-08T20:41:57.522395 #75960] INFO -- : Completed 302 Found in 7ms (ActiveRecord: 1.0ms)
I, [2016-06-08T20:41:57.524136 #75960] INFO -- : source=rack-timeout id=b52906d00e89d57cf9c6537ee56682c7 timeout=10000ms service=17ms state=completed
I, [2016-06-08T20:41:57.562730 #75960] INFO -- : source=rack-timeout id=c928ce9aeaa98904417770a807f6e4f7 timeout=10000ms state=ready
I, [2016-06-08T20:41:57.563918 #75960] INFO -- : Started GET "/" for 127.0.0.1 at 2016-06-08 20:41:57 +1000
I, [2016-06-08T20:41:57.568956 #75960] INFO -- : source=rack-timeout id=c928ce9aeaa98904417770a807f6e4f7 timeout=10000ms service=6ms state=completed
bundler: failed to load command: derailed (/Users/Chris/.rvm/gems/ruby-2.2.1@golf_mentor221/bin/derailed)
RuntimeError: Bad request to "curl 'http://localhost:3878/' -s --fail 2>&1" Response:
""
/Users/Chris/.rvm/gems/ruby-2.2.1@golf_mentor221/gems/derailed_benchmarks-1.3.1/lib/derailed_benchmarks/tasks.rb:85:in `call_app'
/Users/Chris/.rvm/gems/ruby-2.2.1@golf_mentor221/gems/derailed_benchmarks-1.3.1/lib/derailed_benchmarks/tasks.rb:174:in `block (3 levels) in <top (required)>'
The trace after the error is the same as the above. There is a perceptible pause in the logging, perhaps up to one second, immediately prior to the exception occuring.
From what I can see, there is no indication why bundler failed the command. The last memory measurement prior to the exception was
128.98828125. I have used activity monitor while the tests are running, and the memory pressure is green.
schneems
commented
8 years ago I will mention that derailed cannot handle a 302 response, it looks like going to / will redirect someone to central/home in your app. You should be using PATH_TO_HIT=central/home in your derailed command.
What are the contents of this file /Users/Chris/.rvm/gems/ruby-2.2.1@golf_mentor221/bin/derailed ?
Can you give me your bundle list ? What version of bundler are you using?
obromios
commented
8 years ago I changed the routing so / goes to central/home. The benchmark appears to run longer than before, but still fails with the same exception.
I am using bundler 1.12.3.
The contents of /Users/Chris/.rvm/gems/ruby-2.2.1@golf_mentor221/bin/derailed was
#!/usr/bin/env ruby
#
# This file was generated by RubyGems.
#
# The application 'derailed_benchmarks' is installed as part of a gem, and
# this file is here to facilitate running it.
#
require 'rubygems'
version = ">= 0"
if ARGV.first
str = ARGV.first
str = str.dup.force_encoding("BINARY") if str.respond_to? :force_encoding
if str =~ /\A_(.*)_\z/ and Gem::Version.correct?($1) then
version = $1
ARGV.shift
end
end
gem 'derailed_benchmarks', version
load Gem.bin_path('derailed_benchmarks', 'derailed', version)I assume by the bundle list you mean the list printed out when you run bundle command. I have attached a file with that list.
temp.txt
One curious thing is that if I run the benchmark immediately after it has failed, then it will fail after the first GET '/'. If I wait a couple of minutes and run it again, then it will only fail after many iterations.
subakva
commented
8 years ago Is it possible that rack-attack is throttling requests from the profiler?
schneems
commented
8 years ago IDK, it looks like rack-timeout is in the backtrace. You can try removing that gem and re-trying. Also try taking out rack-attack. Alternatively start with a fresh new rails new app and add gems until it starts to fail like your app is.
obromios
commented
7 years ago Yes it is not only possible, it is true that I have rack-attack is setup to throttle requests. When I commented out the relevant section, I did not get the error message. Thank you.
silasjmatson
commented
6 years ago I ran into this issue as well, but my problem was that the endpoint required authentication and I'd misspelled USE_AUTH as USE_ATH. :man_facepalming:
Just posting here in case it helps anyone else.
I asked this question on stackoverflow and have not received an answer, so I am raising as an issue here.
I am trying to use [derailed_benchmark to track down a memory leak in a rails app.
When I run the test
the test runs until the memory usage starts to level off, then then the test throws an error:
How do I fix this?
The output is as follows: