Repository navigation
[SDK-811] Log the internal error's class and message (#1030) - #1223
Conversation
report_internal_error logged only the fixed line "Reporting internal error encountered while sending data to Rollbar." The exception that caused it reached the log only if reporting it also failed, so the log alone gave no clue what broke. Put the internal error's class, message and nearest frame on that line, plus the original exception that was being reported when it happened. The formatting is the one send_failsafe already uses, extracted into exception_info. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
AI Agent Review LGTM (openai, openai-astra)LGTM. No blocking findings were found. LGTM, no findings. I read every changed line against the code in the checkout.
Considered, not flagged
Out-of-scope items from the description |
waltjones
left a comment
There was a problem hiding this comment.
The fallback drops the internal error's details when the original exception is the broken one. lib/rollbar/notifier.rb:565-575
internal_error_details has one rescue around both exception_info calls. If describing the original exception fails, the internal error's description is discarded too, even though it was already built, and only exception.class.name is logged.
This isn't an edge case. A broken #message is far more likely on a user's exception than on Rollbar's own internal error. Item::Backtrace calls current_exception.message (lib/rollbar/item/backtrace.rb:70), so when a user exception's #message raises:
- The resulting RuntimeError becomes the internal error.
- internal_error_details calls the original's #message again, which raises again.
- The log line ends with just RuntimeError.
I confirmed this against the PR's code with ruby -Ilib:
broken original#message => "RuntimeError"
The internal error's message and frame are lost, and the frame would have pointed straight at the broken #message method. The fix is to make the fallback apply to each exception separately:
def internal_error_details(exception, original_error)
details = describe_exception(exception)
original_exception = original_error && original_error[:exception]
if original_exception
details += " (while reporting #{describe_exception(original_exception)})"
end
details
end
def describe_exception(exception)
exception_info(exception)
rescue StandardError
exception.class.name.to_s
endAdd a spec for this case: an original exception whose #message raises, reported through Rollbar.error.
internal_error_details had one rescue around both exception_info calls, so when the original exception's #message raised, the already-built description of the internal error was discarded too and only its class name was logged. That is the common case: Item::Backtrace calls the user exception's #message, so a broken #message there becomes the internal error, and describing the original then raises again. Move the class-name fallback into describe_exception, applied to each exception on its own, and add a spec for an original exception whose #message raises, reported through Rollbar.error. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
Addressed the changes-requested review in f590f8d.
The review had no inline threads, so there was nothing to resolve. The PR description is updated to match. |
There was a problem hiding this comment.
AI Agent Review (openai, openai-astra)
Review of #1223: log the internal error's class and message (#1030)
The log line from report_internal_error now says what the internal error was, and what was being reported when it happened. I checked the changed code paths in the checkout:
- Failsafe messages are unchanged. The new
exception_info(lib/rollbar/notifier.rb:859-870) produces the same string the old inline code built.failsafe_exception_reasonstill rescuesStandardErrorand returns'', as before. - Where the original exception comes from.
internal_error_detailsreads it fromoriginal_error[:exception]. The only caller that passesoriginal_errorisreport_with_rescue(notifier.rb:166-172).process_from_async_handler(notifier.rb:263) passes none, so its log line describes only the internal error. - The specs match the code paths.
Item::Backtrace#trace_datacalls the user exception's#message(lib/rollbar/item/backtrace.rb:70), so the "original#messageraises" spec really does produce aRuntimeError: "broken message"internal error. In the "describing the internal error fails" spec, the exception has no backtrace, sodescribe_exceptionfalls back to"StandardError". - One gap:
describe_exceptionrescues onlyStandardError. The surrounding code expectsSystemStackErrorwhile building the payload:report_with_rescuerescues it explicitly (notifier.rb:165). The new log line calls the original exception's#messageagain, so an exception whose#messageoverflows the stack can now escapeRollbar.errorinto application code. Details are in the inline finding.
Note, not a defect: the original exception's message now goes to the application logger. Payload scrubbing does not apply to log lines. Whether that is acceptable is a product decision.
The description's test, suite and RuboCop results are the author's claims. The diff does not prove them, and I could not run anything here.
report_with_rescue catches SystemStackError while building the payload, e.g. from a user exception whose #message recurses. describe_exception then called that same #message again for the log line, and the SystemStackError it raised escaped report_internal_error (which rescues only StandardError) and Rollbar.error raised into the caller. master returned 'error' here. Rescue SystemStackError in describe_exception too, falling back to the class name, and add a spec reporting such an exception via Rollbar.error. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
AI Agent Review (openai, openai-astra)Review: [SDK-811] Log the internal error's class and messageNo defects found in the changed lines. I read the whole diff against the checkout: What I checked
Minor points (not findings)
Out of scope (stated in the description, not checked further): the original error still isn't reported, and the 429 storm wasn't reproduced. No pinned dependency versions could be resolved for this checkout. None of the conclusions above depend on a library version. |
Description of the change
Fixes #1030: the
[Rollbar] Reporting internal error encountered while sending data to Rollbar.log line didn't say what the internal error was.Notifier#report_internal_errorlogged only that fixed text. The exception that caused it reached the log only if reporting the internal error also failed (therescuebranch logs[Rollbar] Exception: …). Otherwise the details were only in the internal item sent to Rollbar. The reporter couldn't find that item, so the log gave them nothing to go on.The line now includes the internal error's class, message and nearest frame. When the internal error happened while reporting another exception, it also includes that original exception:
failsafe_exception_reason. It's extracted intoexception_infoand shared, so failsafe messages are unchanged.describe_exception, which rescuesStandardErrorandSystemStackErrorand falls back to that exception's class name.SystemStackErroris included becausereport_with_rescuecatches it while building the payload, and calling the same#messageagain here would raise it again. The fallback applies to each exception separately, so a broken#messageon the original exception doesn't drop the internal error's details. That's the common case:Item::Backtracecalls the user exception's#message, so the internal error's frame points straight at the broken method. A broken#messagealso can't pushreport_internal_errorinto its failsafe path.Repro steps (before this change)
Configure Rollbar with a logger, and report an exception whose payload can't be built. For example, its
rollbar_contextraises, standing in for a DB failover during payload building:The log shows only
[Rollbar] Reporting internal error encountered while sending data to Rollbar.and an instance link. NeitherRuntimeError: database unavailablenor the originalconnection losterror appears anywhere in the log.Out of scope (noted during triage)
handle_responseonly logs a warning. So rate limiting alone doesn't explain it.Type of change
Related issues
How this was validated
Ruby 3.4 with
gemfiles/rails81.gemfile, in aruby:3.4container.spec/rollbar_spec.rb(report_internal_error→logging the internal error):Rollbar.error: the log line names the internal and the original exception.#messageraises: the class name is still logged.#messageraises, viaRollbar.error: the internal error's class, message and frame are still logged, followed by(while reporting StandardError).#messageoverflows the stack, viaRollbar.error:Rollbar.errorstill returns'error'instead of raisingSystemStackErrorinto the caller, and logsSystemStackError: "stack level too deep" in … (while reporting StandardError).master, which logs only the fixed text. The#message-on-the-original spec also fails on this PR's first commit, which logged onlyRuntimeError(the case raised in review). The stack-overflow spec fails withSystemStackErroron f590f8d, beforedescribe_exceptionrescued it. That was a regression from this PR, also raised in review:masterreturns'error'there.rollbar-gem, whichproject_gems should handle regex gem patternsexpects).Metrics/ClassLengthonNotifiergrows (640 → 643 lines on this branch, limit 100).Checklists
Development
Code review
🤖 Generated with Claude Code