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

Race condition when closeing the Pipe() used for redirect_* #48

Open
NHDaly opened this issue Dec 6, 2022 · 1 comment · Fixed by #49
Open

Race condition when closeing the Pipe() used for redirect_* #48

NHDaly opened this issue Dec 6, 2022 · 1 comment · Fixed by #49

Comments

@NHDaly
Copy link
Contributor

NHDaly commented Dec 6, 2022

There is a race condition in the implementation of the capture_* and suppress_* macros, described in this julia issue: JuliaLang/julia#47759 (comment), racing against another Task in another Thread doing logging.

It comes from the fact that we do not lock around the critical section in between "redirect" and "close":

try
$(esc(block))
finally
if ccall(:jl_generating_output, Cint, ()) == 0
redirect_stdout(original_stdout)
close(out_wr)
end
end

If another task starts a log message and grabs a local reference to stderr before the redirect, it will grab a local reference to the Pipe. And then if it finishes logging after the Pipe has been closed, the log message will throw an error.

You can see this easily with this program:

Threads.nthreads()  # 4

using Suppressor

t = Threads.@spawn begin
    for _ in 1:100
        @info "hello, friends"
        sleep(0.001)
    end
end

for _ in 1:1000
    @suppress_err sleep(0.001)
end

display(t)

Which for me gives:

Task (failed) @0x000000011353af50
IOError: stream is closed or unusable

We think the easiest fix would be to not manually close the Pipe, but rather to let GC close it, once all references have disappeared. This ensures that if someone has accidentally grabbed a reference to stderr in another thread, that they will not break because the Pipe is closed.

I'm not sure whether GC will already close a pipe when it's GC'd, or if we would need to add a finalizer for it? But either way, I think that's probably the best solution.

CC: @vilterp, @dewilson.

quinnj pushed a commit that referenced this issue Jun 13, 2023
* #47759 - Flush writer pipe; don't close it.

Fixes #47759: Flush writer pipe; don't close it.

Since closing the pipe can cause race conditions with someone writing to the pipe, it's better to flush it, and then leave closing the pipe endpoint to GC.

* Fix the approach: Use a closable IO to safely abort the writing task

This way we achieve all the goals:
- We close the writing task from our side, in a way that doesn't impact
  any other task that has captured the logger. The other task's output
  will just be silently dropped.
- We still allow the Pipe()s to be gracefully closed by GC, once they're
  no longer referenced.
NHDaly added a commit to NHDaly/Suppressor.jl that referenced this issue Jun 14, 2023
quinnj pushed a commit that referenced this issue Jun 14, 2023
@NHDaly
Copy link
Contributor Author

NHDaly commented Jun 29, 2023

@quinnj can we reopen this, since we had to revert #49?

@quinnj quinnj reopened this Jun 30, 2023
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 a pull request may close this issue.

2 participants