noahd1 / oink

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

STDOUT for heroku #21

Closed gabecoyne closed 11 years ago

gabecoyne commented 11 years ago

Can you make this work on heroku? Heroku needs a puts instead of logger.info

config.middleware.use( Oink::Middleware, :logger => Rails.logger, stdout: true )

That would make it so I could see the data in the log, then you would still need a way to parse it since it's not local and it's not in Hodel3000Logger format, but I could at least see the individual "Memory usage: #{memory} | PID: #{$$}" lines.

If all Oink logs started with Oink, this might work:

heroku logs -n 5000 | grep Oink > log/oink_prod.log oink --threshold=5 log/oink_prod.log

Thanks for the Gem!

radanskoric commented 11 years ago

Hi, you can use oink with heroku but you have to set it up a bit.

You can use the regular production log on heroku but you have to temporarily lower your log level to INFO. It's now probably set to WARN either in environments/production.rb or in heroku config variables under the LOG_LEVEL variable.

If you lower it to INFO you will see the "Memory usage: #{memory} | PID: #{$$}" lines.

To have the logs in hodel 3000 format you have to replace the regular rails logger with Hodel3000CompliantLogger (a dependancy of oink) by placing this inside either application.rb or environments/production.rb:

config.logger = Hodel3000CompliantLogger.new(STDOUT)

Also, when enabling the oink middleware you have to explicitly tell it to use the hodel 3000 logger:

config.middleware.use( Oink::Middleware, :logger => Hodel3000CompliantLogger.new(STDOUT))

You need to get the log files locally. If you've got some heroku log drains set up (like papertrail or something custom) you can use that. To quickly get some log data to try it out just do something like:

heroku logs --tail --source app --app app-name > production.log

and leave it running for a while to collect some data.

Finally, once you get the heroku logs locally, before you can analyze it with oink it you need to remove the bits at the start of all log lines that heroku adds and that look like:

2013-01-03T16:30:35+00:00 app[web.2]:

you can do that easily on mac/linux system by measuring the length of that part (if you have less than 10 dynos they'll always be of the same length) and using the cut command:

cat production.log | cut -c 39- > production-clear.log

Now you can run oink analysis normally on production-clear.log.

noahd1 commented 11 years ago

Thanks @radanskoric for providing this information. I know a lot of people like to use Oink on Heroku. If you have suggestions on how to make Oink work more smoothly on Heroku, feel free to add suggestions or a pull request.

Thanks again.

gabecoyne commented 11 years ago

Thanks @radanskoric! I really appreciate the feedback.

Do you have this working on a heroku app?

I'm on the Cedar stack on ruby 1.9.2 and Rails 3.2.1.

If I update my config to this:

config.logger = Hodel3000CompliantLogger.new(STDOUT) config.middleware.use( Oink::Middleware, :logger => Hodel3000CompliantLogger.new(STDOUT))

My app crashes with this:

2013-01-03T17:59:20+00:00 app[web.1]: Exiting 2013-01-03T17:59:20+00:00 app[web.1]: /app/vendor/bundle/ruby/1.9.1/gems/railties-3.2.1/lib/rails/rack/log_tailer.rb:8:in size': No such file or directory - log/staging.log (Errno::ENOENT) 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/railties-3.2.1/lib/rails/rack/log_tailer.rb:8:ininitialize' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/server.rb:295:in new' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/server.rb:295:inblock in build_app' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/server.rb:291:in reverse_each' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/server.rb:291:inbuild_app' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/server.rb:301:in wrapped_app' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/server.rb:252:instart' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/railties-3.2.1/lib/rails/commands/server.rb:70:in start' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/railties-3.2.1/lib/rails/commands.rb:55:inblock in <top (required)>' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/railties-3.2.1/lib/rails/commands.rb:50:in tap' 2013-01-03T17:59:20+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/railties-3.2.1/lib/rails/commands.rb:50:in<top (required)>' 2013-01-03T17:59:20+00:00 app[web.1]: from script/rails:6:in require' 2013-01-03T17:59:20+00:00 app[web.1]: from script/rails:6:in

'

Also, I had to update LOG_LEVEL to get info level logs. Updating config.log_level = :info in production.rb didn't do it.

Thanks again. Really hoping to get this working ;)

gabecoyne commented 11 years ago

Looks like the final solution was this:

heroku config:add LOG_LEVEL=info

production.rb

config.middleware.use( Oink::Middleware, :logger => Hodel3000CompliantLogger.new(STDOUT))

this broke things

config.logger = Hodel3000CompliantLogger.new(STDOUT)

And this worked for logging:

heroku logs --tail > log/production.log cat log/production.log | cut -c 39- | grep 'Oink|Memory|Instantiation' > log/production-oink.log oink --threshold=0 log/production-oink.log

gabecoyne commented 11 years ago

Posted here for others: http://stackoverflow.com/questions/8986144/using-oink-gem-with-heroku/14145299#14145299

radanskoric commented 11 years ago

@gabecoyne Yes I have it working on Cedar stack, ruby 1.9.2 and rails 3.2.5. With the "config.logger = ..." line not causing issues. Not sure if rails 3.2.1. -> 3.2.5 is why I am not seeing any issues there. However, as you noticed yourself, non oink lines are not actually necessary to get the metrics so it's not a big issue. Glad you got it working!

@noahd1 I've actually only got it setup today, I've left it to collect some significant amount of data overnight and will analyse it tomorrow so I'll still have to see what's the usage experience for troubleshooting heroku apps.

kakubei commented 10 years ago

How about working on Heroku but with a Padrino app? I've setup the configuration as in the examples above but get an error:

Errno::ENOENT: No such file or directory - log/oink.log

Can't figure out how to get around this error on Heroku since it should not be trying to log to oink.log but the regular Padrino logs.

Any help would be appreciated.

benoittgt commented 9 years ago

@kakubei Old post but you have to setup a STDOUT not a file. See below.