sentry-raven 0.4.8 not working after bundle update #104

ljromero · 2013-05-29T09:27:49Z

Env:
rails 3.2.11
sentry-raven 0.4.8

sentry server 5.4.5

We are testing a production environment.
Sentry-raven not caching or sending exceptions after server errors.

sentry-raven 0.4.8
Completed 500 Internal Server Error in 1111ms

sentry-raven 0.4.5
Completed 500 Internal Server Error in 1111ms
** [Raven] Sending event 4055553156e548d589acca7ca6c57dd8 to Sentry
** [Raven] Raven HTTP Transport connecting to http://blablabla.local:9000

nateberkopec · 2013-05-29T13:54:53Z

Just tried this on my own production Rails app with edge sentry-raven, and I can't reproduce.

Does running "Raven.capture { 1 / 0 }" in the console send an error to Sentry?

also,

Raven.client.configuration.send_in_current_environment?

should return true. if it doesn't, it means your environment settings are wrong.

romanbsd · 2013-05-30T11:03:13Z

I can positively say that there's a regression in 0.4.8. We we very surprised (in a bad way) to find out that exceptions are no longer delivered. We downgraded to 0.4.6 and now things are back to normal. I'm going to do a diff 0.4.6 and 0.4.8 and see if I notice anything suspicious. We're using passenger+nginx on Engine Yard btw. Couldn't reproduce locally with thin (with RAILS_ENV=production, of course).

ljromero · 2013-05-30T16:01:22Z

Raven.capture is catching but nor sending in the console.

sentry-raven-0.4.8

irb(main):001:0> Raven.capture { 1 / 0 }
ZeroDivisionError: divided by 0
    from org/jruby/RubyFixnum.java:547:in `/'
    from (irb):1:in `evaluate'
    from org/jruby/RubyProc.java:249:in `call'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.8/lib/raven.rb:89:in `capture'
    from (irb):1:in `evaluate'
    from org/jruby/RubyKernel.java:1066:in `eval'
    from org/jruby/RubyKernel.java:1392:in `loop'
    from org/jruby/RubyKernel.java:1174:in `catch'
    from org/jruby/RubyKernel.java:1174:in `catch'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:47:in `start'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:8:in `start'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands.rb:41:in `(root)'
    from org/jruby/RubyKernel.java:1027:in `require'
    from script/rails:6:in `(root)'

raven-sentry-0.4.5

irb(main):007:0> Raven.capture { 1 / 0 }
NameError: undefined local variable or method `logger' for #<Raven::Client:0x409335e1>
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven/client.rb:36:in `send'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:75:in `send'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:108:in `capture_exception'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:92:in `capture'
    from (irb):7:in `evaluate'
    from org/jruby/RubyKernel.java:1066:in `eval'
    from org/jruby/RubyKernel.java:1392:in `loop'
    from org/jruby/RubyKernel.java:1174:in `catch'
    from org/jruby/RubyKernel.java:1174:in `catch'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:47:in `start'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:8:in `start'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands.rb:41:in `(root)'
    from org/jruby/RubyKernel.java:1027:in `require'
    from script/rails:6:in `(root)'
irb(main):006:0> Rails.logger = Logger.new(STDOUT)
=> #<Logger:0xc36a6d1 @logdev=#<Logger::LogDevice:0x5801e99a @filename=nil, @shift_age=nil, @dev=#<IO:fd 1>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x658faa99 @mon_count=0, @mon_mutex=#<Mutex:0x3b0956e6>, @mon_owner=nil>, @shift_size=nil>, @formatter=#<Logger::SimpleFormatter:0x62283451 @datetime_format=nil>, @progname=nil, @default_formatter=#<Logger::Formatter:0x3d82e42f @datetime_format=nil>, @level=0>
irb(main):007:0> Raven.capture { 1 / 0 }
NameError: undefined local variable or method `logger' for #<Raven::Client:0x409335e1>
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven/client.rb:36:in `send'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:75:in `send'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:108:in `capture_exception'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:92:in `capture'
    from (irb):7:in `evaluate'
    from org/jruby/RubyKernel.java:1066:in `eval'
    from org/jruby/RubyKernel.java:1392:in `loop'
    from org/jruby/RubyKernel.java:1174:in `catch'
    from org/jruby/RubyKernel.java:1174:in `catch'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:47:in `start'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:8:in `start'
    from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands.rb:41:in `(root)'
    from org/jruby/RubyKernel.java:1027:in `require'
    from script/rails:6:in `(root)'

And the environment settings are right in both gemsets:

irb(main):003:0> Raven.client.configuration.send_in_current_environment?
=> true

dcramer · 2013-05-30T16:45:32Z

IIRC correctly I added more logging. This could be an issue with the logger
not getting initialized correctly in all situations

On Thursday, May 30, 2013, ljromero wrote:

Raven.capture is catching but nor sending in the console.

sentry-raven-0.4.8

irb(main):001:0> Raven.capture { 1 / 0 }ZeroDivisionError: divided by 0
from org/jruby/RubyFixnum.java:547:in /' from (irb):1:inevaluate' from org/jruby/RubyProc.java:249:in call' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.8/lib/raven.rb:89:incapture' from (irb):1:in evaluate' from org/jruby/RubyKernel.java:1066:ineval'
from org/jruby/RubyKernel.java:1392:in loop' from org/jruby/RubyKernel.java:1174:incatch' from org/jruby/RubyKernel.java:1174:in catch' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:47:instart' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:8:in start' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands.rb:41:in(root)'
from org/jruby/RubyKernel.java:1027:in require' from script/rails:6:in(root)'

raven-sentry-0.4.5

irb(main):007:0> Raven.capture { 1 / 0 }NameError: undefined local variable or method logger' for #<Raven::Client:0x409335e1> from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven/client.rb:36:insend' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:75:in send' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:108:incapture_exception'
from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:92:in capture' from (irb):7:inevaluate'
from org/jruby/RubyKernel.java:1066:in eval' from org/jruby/RubyKernel.java:1392:inloop' from org/jruby/RubyKernel.java:1174:in catch' from org/jruby/RubyKernel.java:1174:incatch' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:47:in start' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:8:instart'
from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands.rb:41:in (root)' from org/jruby/RubyKernel.java:1027:inrequire' from script/rails:6:in (root)'irb(main):006:0> Rails.logger = Logger.new(STDOUT)=> #<Logger:0xc36a6d1 @logdev=#<Logger::LogDevice:0x5801e99a @filename=nil, @shift_age=nil, @dev=#<IO:fd 1>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x658faa99 @mon_count=0, @mon_mutex=#<Mutex:0x3b0956e6>, @mon_owner=nil>, @shift_size=nil>, @formatter=#<Logger::SimpleFormatter:0x62283451 @datetime_format=nil>, @progname=nil, @default_formatter=#<Logger::Formatter:0x3d82e42f @datetime_format=nil>, @level=0>irb(main):007:0> Raven.capture { 1 / 0 }NameError: undefined local variable or methodlogger' for #Raven::Client:0x409335e1 from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven/client.rb:36:in send' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:75:insend'
from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:108:in capture_exception' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/sentry-raven-0.4.5/lib/raven.rb:92:incapture' from (irb):7:in evaluate' from org/jruby/RubyKernel.java:1066:ineval' from org/jruby/RubyKernel.java:1392:in loop' from org/jruby/RubyKernel.java:1174:incatch'
from org/jruby/RubyKernel.java:1174:in catch' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:47:instart' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands/console.rb:8:in start' from /usr/local/rvm/gems/jruby-1.7.2@warbler/gems/railties-3.2.11/lib/rails/commands.rb:41:in(root)' from org/jruby/RubyKernel.java:1027:in require' from script/rails:6:in(root)'

And the environment settings are right in both gemsets:

irb(main):003:0> Raven.client.configuration.send_in_current_environment?=> true

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/104#issuecomment-18690107
.

David Cramer
http://disqus.com/zeeg
http://twitter.com/zeeg

ragalie · 2013-06-17T19:14:58Z

I'm also experiencing this issue.

dcramer · 2013-06-17T19:41:44Z

7ecb853 is the cuprit, investigating

dcramer · 2013-06-17T19:48:02Z

Actually that's not entirely true.

I'm unable to reproduce still.

Please confirm that Raven.client.configuration.send_in_current_environment? is true, and you've bound a logger that has DEBUG logging enabled:

logger = ::Logger.new(STDOUT)
logger.level = ::Logger::ERROR
logger.formatter = proc do |severity, datetime, progname, msg|
  "-> #{msg}\n"
end

Raven.configuration.logger = logger

dcramer · 2013-06-17T19:55:20Z

Improved logging in 0ae36c2 so it has a sane default

romanbsd · 2013-06-17T19:55:33Z

We've a standard Rails logger (the level is set to INFO).

dcramer · 2013-06-17T19:56:42Z

@romanbsd it will output something if logging is configured. So if it just shows the traceback logging must not be configured correctly.

If it is outputting something, can you paste the cleaned result here?

ragalie · 2013-06-17T20:02:32Z

I have Raven.client.configuration.send_in_current_environment? is true. I'm using the standard Rails logger as well (INFO).

Raven.capture { 1 / 0 } in the console does not log any Raven-related output. It does send the message to Sentry. However, exceptions thrown in the request-response cycle (Rack) are not getting logged or sent.

dcramer · 2013-06-17T20:04:31Z

Are you sure that the production environment is configured to send to Sentry?

dcramer · 2013-06-17T20:05:06Z

There were some changes in 0.4.8 around this that enable it in more situations, so it seems like that wouldn't affect it:

https://github.com/getsentry/raven-ruby#environments

romanbsd · 2013-06-17T20:33:29Z

@dcramer It wasn't outputting anything. We reverted to 0.4.6 and now things are back to normal.

marcomorain · 2013-06-20T08:40:46Z

This was the problem here, it was fixed in this commit:

998a8ca

If the send failed, the rescue block was using logger which was (nil).

romanbsd · 2013-06-20T08:49:48Z

Why did the send fail every time, then? Not even a single exception was reported.

dcramer · 2013-06-20T17:49:56Z

@romanbsd I can't explain that unless the server was throttling you (but you'd see a log message)

Either way, 100% of the time in the current release there are log messages if logging is configured at the appropriate levels

marcomorain · 2013-06-21T13:16:54Z

I think something has gone wrong in Sentry 0.4.8 SSL verification settings. I had to set config.ssl_verification = false manually in the initialiser, and even still I was getting weird issues (I guess only @dcramer can see this) https://app.getsentry.com/team-swrve/swrve-staging/group/6175309/

dcramer · 2013-06-21T17:56:11Z

@marcomorain going to look into our SSL default (it might not be applying), but regarding capture_rack_exception, I believe that was deleted. It probably shouldn't have been, but basically now you can just do Raven.capture_exception, and if you have the Rack middleware installed, it always has the rack context

dcramer · 2013-06-21T18:04:13Z

I think I've fixed the SSL verification issue with 4efeeb5

nateberkopec closed this as completed Sep 12, 2013

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

sentry-raven 0.4.8 not working after bundle update #104

sentry-raven 0.4.8 not working after bundle update #104

ljromero commented May 29, 2013

nateberkopec commented May 29, 2013

romanbsd commented May 30, 2013

ljromero commented May 30, 2013

dcramer commented May 30, 2013

ragalie commented Jun 17, 2013

dcramer commented Jun 17, 2013

dcramer commented Jun 17, 2013

dcramer commented Jun 17, 2013

romanbsd commented Jun 17, 2013

dcramer commented Jun 17, 2013

ragalie commented Jun 17, 2013

dcramer commented Jun 17, 2013

dcramer commented Jun 17, 2013

romanbsd commented Jun 17, 2013

marcomorain commented Jun 20, 2013

romanbsd commented Jun 20, 2013

dcramer commented Jun 20, 2013

marcomorain commented Jun 21, 2013

dcramer commented Jun 21, 2013

dcramer commented Jun 21, 2013

sentry-raven 0.4.8 not working after bundle update #104

sentry-raven 0.4.8 not working after bundle update #104

Comments

ljromero commented May 29, 2013

nateberkopec commented May 29, 2013

romanbsd commented May 30, 2013

ljromero commented May 30, 2013

dcramer commented May 30, 2013

ragalie commented Jun 17, 2013

dcramer commented Jun 17, 2013

dcramer commented Jun 17, 2013

dcramer commented Jun 17, 2013

romanbsd commented Jun 17, 2013

dcramer commented Jun 17, 2013

ragalie commented Jun 17, 2013

dcramer commented Jun 17, 2013

dcramer commented Jun 17, 2013

romanbsd commented Jun 17, 2013

marcomorain commented Jun 20, 2013

romanbsd commented Jun 20, 2013

dcramer commented Jun 20, 2013

marcomorain commented Jun 21, 2013

dcramer commented Jun 21, 2013

dcramer commented Jun 21, 2013