Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add try/catch around handle_message() to catch errors during logging. #57004

Open
wants to merge 3 commits into
base: master
Choose a base branch
from

Conversation

NHDaly
Copy link
Member

@NHDaly NHDaly commented Jan 9, 2025

Fixes #56889.

Before this PR, an exception thrown while constructing the objects to log (the msg) would be caught and logged. However, an exception thrown while printing the msg to an IO would not be caught, and can abort the program. This breaks the promise that enabling verbose debug logging shouldn't introduce new crashes.

After this PR, an exception thrown during handle_message is caught and logged, just like an exception during msg construction:

julia> struct Foo end

julia> Base.show(::IO, ::Foo) = error("oh no")

julia> begin
           # Unexpectedly, the execption thrown while printing `Foo()` escapes
           @info Foo()
           # So we never reach this line! :'(
           println("~~~~~ ALL DONE ~~~~~~~~")
       end
┌ Error: Exception while generating log record in module Main at REPL[10]:3
│   exception =
│    oh no
│    Stacktrace:
│      [1] error(s::String)
│        @ Base ./error.jl:44
│      [2] show(::IOBuffer, ::Foo)
│        @ Main ./REPL[9]:1
...
│     [30] repl_main
│        @ ./client.jl:593 [inlined]
│     [31] _start()
│        @ Base ./client.jl:568
└ @ Main REPL[10]:3
~~~~~ ALL DONE ~~~~~~~~

This PR respects the change made in #36600 to keep the codegen as small as possible, by putting the new try/catch into a no-inlined function, so that we don't have to introduce a new try/catch in the macro-generated code body.

NHDaly added 2 commits January 9, 2025 10:19
Fixes #56889.

Before this PR, an exception thrown while constructing the objects to
log (the `msg`) would be caught and logged. However, an exception thrown
while _printing_ the msg to an IO would _not_ be caught, and can abort
the program. This breaks the promise that enabling verbose debug logging
shouldn't introduce new crashes.

After this PR, an exception thrown during handle_message is caught and
logged, just like an exception during `msg` construction:

```julia
julia> struct Foo end

julia> Base.show(::IO, ::Foo) = error("oh no")

julia> begin
           # Unexpectedly, the execption thrown while printing `Foo()` escapes
           @info Foo()
           # So we never reach this line! :'(
           println("~~~~~ ALL DONE ~~~~~~~~")
       end
┌ Error: Exception while generating log record in module Main at REPL[10]:3
│   exception =
│    oh no
│    Stacktrace:
│      [1] error(s::String)
│        @ Base ./error.jl:44
│      [2] show(::IOBuffer, ::Foo)
│        @ Main ./REPL[9]:1
...
│     [30] repl_main
│        @ ./client.jl:593 [inlined]
│     [31] _start()
│        @ Base ./client.jl:568
└ @ Main REPL[10]:3
~~~~~ ALL DONE ~~~~~~~~
```
@IanButterworth
Copy link
Member

IanButterworth commented Jan 9, 2025

I think this wold mean try-catch in every log macro usage? That would make #52533 a lot worse (but at least it'd be consistent!)

cc. @gbaraldi

@gbaraldi
Copy link
Member

gbaraldi commented Jan 9, 2025

Logging already introduces try catches in places so I'm not sure how much worse it can get 😄. Notably for GPU stuff I believe we are going in the way of doing more RAII like things to not rely on the GC as much

@NHDaly
Copy link
Member Author

NHDaly commented Jan 9, 2025

Yeah, exactly. I think that since it's already adding try/catches in so many places, we may as well be consistent in applying them to all parts of the logging process.

@IanButterworth
Copy link
Member

IanButterworth commented Jan 9, 2025

It just elevates the need to fix that issue. 👍

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Exception thrown inside Base.show(::IO, x) can cause an exception to leak a log message.
3 participants