noahd1 / oink

Log parser to identify actions which significantly increase VM heap size
MIT License
1.18k stars 71 forks source link

Oink with Rails 3 #5

Closed TeuF closed 13 years ago

TeuF commented 13 years ago

Does Oink work with rails 3 ? And if yes, how does we need to install it ?

Thanks a lot,

noahd1 commented 13 years ago

I don't know anyone who's yet tested or tried it with rails 3, I'm afraid. It's definitely next on my list. The new instrumentation stuff should make some of the hoops we're jumping through a bit simpler too.

cgriego commented 13 years ago

A nice Rails 3 centric feature would be to support ActionController::Metal, by making the Oink modules ActiveSupport::Concern and pulling in anything they depend on (like filters).

jtoy commented 13 years ago

has anyone tried this? would love to know

noahd1 commented 13 years ago

I gave this a shot and it seems to work fine in rails3. The only rails hooks that it's relying on really are around/after filters on controllers which still exist.

It can be installed as a gem and included in your Gemfile for your app. Let me know if you have any issues.

noahd1 commented 13 years ago

Ok, as I've been working towards a 1.0 release, I realized that while my earlier statement is true, it does log fine in rails3, the log format changed slightly in rails3, which breaks the parsing of the logs.

I have this fixed in master, which uses middleware instead of controller filters, and writes to its own separate log.

cgriego commented 13 years ago

Using a custom log file breaks the request-log-analyzer gem in a way that is not easily resolvable (it would have to correlate entries across two log files) which in turn breaks ScoutApp's support of Oink. Can't it go back to using the Rails logger if Rails is loaded? We have been successfully using Scout to monitor Oink in Rails 3 but this change will break that.

https://github.com/wvanbergen/request-log-analyzer/blob/master/lib/request_log_analyzer/file_format/oink.rb

noahd1 commented 13 years ago

Hey Chris -

Thanks for bringing this to my attention and sorry I introduced a change which breaks ScoutApp's support of Oink. First, since I already pushed an "0.9.1" release, make sure to freeze support at "0.1.2" until we are able to resolve this issue.

Oink version 0.1.2 does not work with Rails 3 applications - the reason for this is that Oink's log parser was reading lines written both by Oink and by Rails, and the lines written by Rails changed from version 2.x and 3.x.

I was uncomfortable with this fragility and coupling with Rails version-specific logging lines, and it struck me that if Oink was writing the relevant lines instead of Rails, it would be isolated from Rails logging changes, and furthermore, would allow oink to be framework-agnostic (Sinatra, etc).

Any application that reads the Rails log for this specific information is going to have this same issue.

I am comfortable re-introducing the ability of Oink to write to the Rails log (or its own log), but only when it is resilient to framework logging changes. To do this will probably involve:

  1. logging duplicative information that Rails already logs
  2. prefixing Oink logged lines with "oink"

Apologies for the length of this response, but prior to recently I wasn't aware that others were hinged to Oink's log format, which means changes to Oink's log format are going to require greater collaboration that I had envisioned.

Let me know your thoughts on this.

cgriego commented 13 years ago

Well I can only respond from the perspective of my use cases. My use cases involve using Oink::MemoryUsageLogger with Rails 2 and 3 and Oink::InstanceTypeCounter with Rails 2 (the Rails 3 app does not use ActiveRecord). I use those combined with the request-log-analyzer gem (via ScoutApp's #1 plugin, the Rails log analyzer) which already handles both the Rails 2 and Rails 3 log formats, but to parse the Oink information it must be within the same log file.

So my use case never intersects with Oink's built-in log parser. Is there anyway to leverage the work that the request-log-analyzer has done? I'm definitely not a fan of adding duplication to the log files since apps with a lot of traffic already generate large enough logs that they're hard to efficiently parse on a nightly basis. An Oink prefix would break the current version of the parser but it would be a simple patch to fix that so I'm not worried about that change.

noahd1 commented 13 years ago

Hi Chris -

I just pushed a 0.9.2 which hopefully addresses your concerns. You can now log to the rails log but configuring the middleware like so in a rails initializer:

YourApplication::Application.middleware.use( Oink::Middleware, :logger => Rails.logger )

It does for now log a bit of duplicate information, because that was the easiest way to support request log analyzer while remaining framework-agnostic. Let me know if this solution works for you.

Over time, I'd like flexibility in changing the oink log format, but it seems this may prove challenging if request log analyzer has its own parser. Might be worth considering how we can consolidate the different log parsers. Perhaps oink should be split into a parser and a logger, and both request log analyzer and oink logger can rely on the oink parser.

inspire22 commented 13 years ago

I'm getting this error on rails3 - its in my gemfile, and in my initializer I have require 'oink' Newap::Application.middleware.use Oink::Middleware( Oink::Middleware, :logger => Rails.logger )

    /Users/inspire/Dropbox/newap/config/initializers/socialdesign_setup.rb:41: undefined method `Middleware' for Oink:Module (NoMethodError)
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:235:in `load'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:235:in `load'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:225:in `load_dependency'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:596:in `new_constants_in'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:225:in `load_dependency'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:235:in `load'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/engine.rb:201
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/engine.rb:200:in `each'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/engine.rb:200
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/initializable.rb:25:in `instance_exec'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/initializable.rb:25:in `run'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/initializable.rb:50:in `run_initializers'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/initializable.rb:49:in `each'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/initializable.rb:49:in `run_initializers'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/application.rb:134:in `initialize!'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/application.rb:77:in `send'
from /Users/inspire/.rvm/gems/ree-1.8.7-2011.03@newap/gems/railties-3.0.7/lib/rails/application.rb:77:in `method_missing'
from /Users/inspire/Dropbox/newap/config/environment.rb:5
noahd1 commented 13 years ago

Looks like you have one too many "Oink::Middlewares" in there. Try this:

Newap::Application.middleware.use( Oink::Middleware, :logger => Rails.logger )
inspire22 commented 13 years ago

Thanks! Strangely OSX memory reports 2.6 GB from 'ps' which is wrong according to activity log. It's just my dev environment though so not a huge deal, and hopefully the deltas will end up right.

inspire 5020 0.3 3.1 2638624 192580 s000 S 11:39AM 0:07.92 /Users/inspire/.rvm/rubies/ree-1.8.7-2011.03/bin/ruby script/rails server

activity manager shows 188MB vsize, 206MB memory size. On linux the processes are about 120MB (which seems normal for a large-sized rails3 app?)

inspire22 commented 13 years ago

Any tips how to set the default rails logger to be a hotel_3000_complaint one? The github project for that hasn't been updated in forever & it's docs are now missing. How does one reopen the Rails.logger, or re-assign it to a subclassed version of itself...

Thanks, Kevin "Desire makes everything blossom; possession makes everything wither and fade." - Proust https://github.com/topfunky/hodel_3000_compliant_logger

On May 1, 2011, at 9:41 AM, noahd1 wrote:

Looks like you have one too many "Oink::Middlewares" in there. Try this:

Newap::Application.middleware.use( Oink::Middleware, :logger => Rails.logger )

Reply to this email directly or view it on GitHub: https://github.com/noahd1/oink/issues/5#comment_1083619

noahd1 commented 13 years ago

For rails3, you'll want the following line in application.rb or in one of your environment files:

config.logger = Hodel3000CompliantLogger.new(config.paths.log.first)

rails2 uses "config.log_path" instead of config.paths.log.first

ghost commented 12 years ago

In Rails 3.1 > config.paths.log.first as been deprecated: http://guides.rubyonrails.org/3_2_release_notes.html

Use

config.logger = Hodel3000CompliantLogger.new(config.paths["log/first"])

instead.

brendon9x commented 11 years ago

For anyone reading the comment from @noahd1, I think that should be

config.logger = Hodel3000CompliantLogger.new(config.paths['log'].first)