Logged Ruby stacktraces lacking newlines? about loggr HOT 9 CLOSED

Have you configured to use slf4j in jruby-rack, I suspect this has not much to do with loggr, because it appears to be logged by some method within tomcat. Unless of course you have a logger.error line in your versions_controller.rb on line 15

from loggr.

I just put a nil.get_stuff there to test stacktraces.

I added a config.webxml.jruby.rack.logging = "slf4j" to config/warble.rb, which puts it in the web.xml to pass to jruby-rack. That's the configuration when the WAR gets deployed to tomcat.
It doesn't seem to have much effect besides adding some rack messages to the log.
I also run under trinidad, and don't know how to set the corresponding option there.

Just using a ConsoleAppender in logback right now, where those stacktraces look the same on the console (under trinidad), or in /var/log/tomcat7/catalina.out (under tomcat). I could try a FileAppender or some better tomcat integration, or something?

from loggr.

My guess is that it a) might be an issue with a formatter (maybe add %ex{full} to your logback pattern or b) the error is logged in java being forced into a string. Which then would look like the output you are getting above.

To be honest I highly suspect the culprit is found in loggr, because loggr only provides the ability to log stuff from ruby and this message is clearly logged by tomcat (or any other middleware). Or it could be whiny_nils in Rails 2.x...

from loggr.

Okay, it's not whiny_nils (https://github.com/rails/rails/blob/2-2-stable/activesupport/lib/active_support/whiny_nil.rb#L55), they just raise a NoMethodError they dont log anything at all. So it's in your Tomcat/Trinidad stack, unless you have custom exception handlers in Rails...

from loggr.

I just threw that nil in there to simulate an exception being thrown by the app.
I believe that exception is caught by Rails and logged. When I replace config.logger =Loggr::SLF4J::Logger.new 'com.foo' with config.logger = FileLogger.new in config/environment.rb, those stacktraces are logged to log/development.log with newlines intact like so:

Wed Feb 15 13:02:29 - FATAL -

NoMethodError (You have a nil object when you didn't expect it!
The error occurred while evaluating nil.get_stuff):
/app/controllers/version_controller.rb:15:in index' /home/leif/.rvm/gems/jruby-1.6.5@jrails/gems/actionpack-2.2.2/lib/action_controller/mime_responds.rb:106:incall'
/home/leif/.rvm/gems/jruby-1.6.5@jrails/gems/actionpack-2.2.2/lib/action_controller/mime_responds.rb:106:in respond_to' /app/controllers/version_controller.rb:14:inindex'

And Rails displays the 500 error page with the stacktrace in either case.

from loggr.

you ar right, guess the exception is logged here https://github.com/rails/rails/blob/2-2-stable/actionpack/lib/action_controller/rescue.rb#L65 and I suppose the gem then interferes (sorry) here https://github.com/at-point/loggr/blob/master/lib/loggr/slf4j/logger.rb#L107

from loggr.

Removing the .gsub(/$\s*^/, '') fixes the stacktrace formatting, thanks! Will there be a version bump for this? I guess we could just depend on the git version, or edit our local copy.

from loggr.

Going to release a new version asap.

Found out why this gsub was there, it appears rack/rails logs "\n\nStarted GET \"/service/foobar\" for 127.0.0.1 at Wed Feb 15 22:28:02 +0100 2012" and having the Started GET on the new line is a bit ugly (and harder to grep for). So now SLF4J::Logger#build_message just strips leading newlines, problem solved, tested and documented :)

Thanks for reporting.

from loggr.

FYI 1.1.2 has been uploaded: https://rubygems.org/gems/loggr

from loggr.