I have run into an issue similar to that fixed in <a class="issue-link js-issue-link"

A couple of quick debugging thoughts: What happens if you try

_defaultlink : <a href="https://github.com/JuliaIntero

If you just do capture() around a <code class="notran

Yes, that hangs too. I have modified <a href="https://github.com/mus

Hang when captureing output from MathLink about iocapture.jl HOT 7 OPEN

musoke commented on August 25, 2024

Hang when captureing output from MathLink

from iocapture.jl.

Comments (7)

musoke commented on August 25, 2024 1

Does it also hang if you manually do redirect_stdout / redirect_stderr? Basically, it would be good to try to reduce the capture() implementation down, to see which part there might be causing the hang.

I have made some progress with this line of investigation. Here is a script that reduces IOCapture.capture's implementation to approximately the minimum required to reproduce the hang.

using IOCapture
using Logging
using MathLink

function hangs()
    @info "Before capture"
    c = IOCapture.capture() do
        W`Sin`
    end
    @info "After capture" c
end

function hangs_mwe()
    @debug "Before capture"
    c = iocapture_mwe() do
        W`Sin`
    end
    @debug "After capture" c
end

function iocapture_mwe(f)
    @debug "Entered"
    default_stdout = stdout
    # default_stderr = stderr

    pipe = Pipe()
    Base.link_pipe!(pipe; reader_supports_async = true, writer_supports_async = true)

    pe_stdout = pipe.in
    # pe_stderr = pipe.in

    redirect_stdout(pe_stdout)
    # redirect_stderr(pe_stderr)

    output = IOBuffer()
    buffer_redirect_task = @async write(output, pipe)

    yield()
    @show value = f()

    output = String(take!(output)),
    @info "captured output" output


    redirect_stdout(default_stdout)
    # redirect_stderr(default_stderr)

    close(pe_stdout)
    # close(pe_stderr)

    wait(buffer_redirect_task)  # No hang if this line is commented

    (value, output)
end

ENV["JULIA_DEBUG"] = Main

hangs_mwe()

The problem seems to be connected to wait(buffer_redirect_task) - the hang goes away if that line is commented.

What happens if you try to capture() a _defaultlink() call? As you say, it seems to try to establish a connection first, so maybe this helps to reduce this.

What is _defaultlink()?

Are there any Julia version differences? Does it also hang on nightly or 1.6?

I tried a few different juliaup channels and see the same behaviour each of 1.6, 1.7, 1.8, 1.9, and alpha (currently 1.10.0-alpha+x0.64.linux.gnu).

from iocapture.jl.

mortenpi commented on August 25, 2024

A couple of quick debugging thoughts:

What happens if you try to capture() a _defaultlink() call? As you say, it seems to try to establish a connection first, so maybe this helps to reduce this.
Does it also hang if you manually do redirect_stdout / redirect_stderr? Basically, it would be good to try to reduce the capture() implementation down, to see which part there might be causing the hang.
Are there any Julia version differences? Does it also hang on nightly or 1.6?

from iocapture.jl.

mortenpi commented on August 25, 2024

_defaultlink: https://github.com/JuliaInterop/MathLink.jl/blob/305115610de2d6ea1f4a64e0df458b9282c03b08/src/link.jl#L88-L103

It seems like this gets sometimes called to establish the default connection as you said?

https://github.com/JuliaInterop/MathLink.jl/blob/305115610de2d6ea1f4a64e0df458b9282c03b08/src/eval.jl#L52-L59

Although I didn't immediately see how it relates to the W... macros right now.

from iocapture.jl.

musoke commented on August 25, 2024

I think you're right.

The W... string literals are defined by W_str and W_cmd. The latter contains a call to weval, which in turn has the _defaultlink call you pointed out.
https://github.com/JuliaInterop/MathLink.jl/blob/305115610de2d6ea1f4a64e0df458b9282c03b08/src/eval.jl#L87

from iocapture.jl.

mortenpi commented on August 25, 2024

If you just do capture() around a _defaultlink call, does that hang too though?

from iocapture.jl.

musoke commented on August 25, 2024

Yes, that hangs too.

I have modified capture and _defaultlink to capture only stdout and added some debug statements. Here's a repo with those versions pinned and the following script: https://github.com/musoke/mathlink-iocpture-hang

using IOCapture
using Logging
using MathLink

function hangs()
    @debug "Before capture"
    c = IOCapture.capture() do
        MathLink._defaultlink()
    end
    @debug "After capture" c
end

ENV["JULIA_DEBUG"] = "IOCapture,MathLink"

# weval("Sin[0]")  # no hang if uncommented
hangs()

The result of running it is

┌ Debug: Redirected outputs, about to call f
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:114
┌ Debug: yielded, about to call f
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:120
┌ Debug: defaultlink uninitialised
│   defaultlink = MathLink.Link(Ptr{Nothing} @0x0000000000000000)
└ @ MathLink ~/.julia/packages/MathLink/oqu5t/src/link.jl:90
┌ Debug: _defaultlink return value
│   defaultlink = MathLink.Link(Ptr{Nothing} @0x0000000001579db0)
└ @ MathLink ~/.julia/packages/MathLink/oqu5t/src/link.jl:107
┌ Debug: result of calling f
│   f = #3 (generic function with 1 method)
│   f_val = MathLink.Link(Ptr{Nothing} @0x0000000001579db0)
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:122
┌ Debug: ended redirects, closed pipes
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:134

At which point it halts indefinitely.

If seems that the call to f (_defaultlink in this case) at

IOCapture.jl/src/IOCapture.jl

Lines 121 to 123 in 3fc23ea

 f_val = f() 

 @debug "result of calling f" f f_val 

 f_val, true, Vector{Ptr{Cvoid}}()

returns.

However, capture gets stuck at

IOCapture.jl/src/IOCapture.jl

Line 136 in 3fc23ea

wait(buffer_redirect_task)

Adding a weval("Sin[0]") before the capture prevents it from hanging and gives this output:

┌ Debug: defaultlink uninitialised
│   defaultlink = MathLink.Link(Ptr{Nothing} @0x0000000000000000)
└ @ MathLink ~/.julia/packages/MathLink/oqu5t/src/link.jl:90
┌ Debug: _defaultlink return value
│   defaultlink = MathLink.Link(Ptr{Nothing} @0x00000000015eee70)
└ @ MathLink ~/.julia/packages/MathLink/oqu5t/src/link.jl:107
┌ Debug: Redirected outputs, about to call f
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:114
┌ Debug: yielded, about to call f
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:120
┌ Debug: defaultlink already initialised
│   defaultlink = MathLink.Link(Ptr{Nothing} @0x00000000015eee70)
└ @ MathLink ~/.julia/packages/MathLink/oqu5t/src/link.jl:104
┌ Debug: _defaultlink return value
│   defaultlink = MathLink.Link(Ptr{Nothing} @0x00000000015eee70)
└ @ MathLink ~/.julia/packages/MathLink/oqu5t/src/link.jl:107
┌ Debug: result of calling f
│   f = #3 (generic function with 1 method)
│   f_val = MathLink.Link(Ptr{Nothing} @0x00000000015eee70)
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:122
┌ Debug: ended redirects, closed pipes
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:134
┌ Debug: waited on buffer, end finally
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:137
┌ Debug: return values
│   value = MathLink.Link(Ptr{Nothing} @0x00000000015eee70)
└ @ IOCapture ~/.julia/packages/IOCapture/dYgMT/src/IOCapture.jl:140

from iocapture.jl.

musoke commented on August 25, 2024

TLDR: MathLink doesn't let pipe.out close after initialising so

IOCapture.jl/src/IOCapture.jl

Line 130 in a23f2a4

wait(buffer_redirect_task)

hangs. I don't know if this is a bug here or MathLink. I can submit a PR here to add close(pipe.out) but am not sure if that is correct.

Here is a script that demonstrates. It passes two functions through a very pared down version of IOCapture.capture: one is a vanilla function and the other uses MathLink.

using MathLink

function boring()
    1 + 2
end

function mathlink()
    weval("Sin[0]")
end

function hang(f)
    pipe = Pipe()
    @debug "Pipe created" f = string(f) pipe pipe.in pipe.out

    default_stdout = stdout
    Base.link_pipe!(pipe; reader_supports_async = true, writer_supports_async = true)
    pe_stdout = pipe.in
    redirect_stdout(pe_stdout)

    output = IOBuffer()
    buffer_redirect_task = @async write(output, pipe)

    val = f()
    @debug "Value computed" f = string(f) val
    @debug "Pipe in use" f = string(f) pipe pipe.in pipe.out

    redirect_stdout(default_stdout)
    close(pe_stdout)

    if timedwait(() -> istaskdone(buffer_redirect_task), 30) === :ok
        @info "wait succeeded" f = string(f) pipe pipe.in pipe.out
    else
        @warn "wait timed out after 30 seconds" f = string(f) pipe pipe.in pipe.out
        close(pipe.out)
        wait(buffer_redirect_task)
        @info "wait succeeded after closing pipe.out" f = string(f) pipe pipe.in pipe.out
    end

    @debug "Contents of redirected stdout" String(take!(output))
end

ENV["JULIA_DEBUG"] = Main

hang(boring)
print("\n\n")
hang(mathlink)

One can see in the output below that waiting on buffer_redirect_task succeeds for the vanilla function. It does not for the MathLink function - until pipe.out is closed explicitly.

┌ Debug: Pipe created
│   f = "boring"
│   pipe = Pipe(RawFD(4294967295) init => RawFD(4294967295) init, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(4294967295) init, 0 bytes waiting)
│   pipe.out = Base.PipeEndpoint(RawFD(4294967295) init, 0 bytes waiting)
└ @ Main ~/tmp/IOCapture-hang/buf.jl:13
┌ Debug: Value computed
│   f = "boring"
│   val = 3
└ @ Main ~/tmp/IOCapture-hang/buf.jl:24
┌ Debug: Pipe in use
│   f = "boring"
│   pipe = Pipe(RawFD(21) open => RawFD(20) active, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(21) open, 0 bytes waiting)
│   pipe.out = Base.PipeEndpoint(RawFD(20) active, 0 bytes waiting)
└ @ Main ~/tmp/IOCapture-hang/buf.jl:25
┌ Info: wait succeeded
│   f = "boring"
│   pipe = Pipe(RawFD(4294967295) closed => RawFD(4294967295) closed, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(4294967295) closed, 0 bytes waiting)
└   pipe.out = Base.PipeEndpoint(RawFD(4294967295) closed, 0 bytes waiting)
┌ Debug: Contents of redirected stdout
│   String(take!(output)) = ""
└ @ Main ~/tmp/IOCapture-hang/buf.jl:39


┌ Debug: Pipe created
│   f = "mathlink"
│   pipe = Pipe(RawFD(4294967295) init => RawFD(4294967295) init, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(4294967295) init, 0 bytes waiting)
│   pipe.out = Base.PipeEndpoint(RawFD(4294967295) init, 0 bytes waiting)
└ @ Main ~/tmp/IOCapture-hang/buf.jl:13
┌ Debug: Value computed
│   f = "mathlink"
│   val = "Sin[0]"
└ @ Main ~/tmp/IOCapture-hang/buf.jl:24
┌ Debug: Pipe in use
│   f = "mathlink"
│   pipe = Pipe(RawFD(21) open => RawFD(20) active, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(21) open, 0 bytes waiting)
│   pipe.out = Base.PipeEndpoint(RawFD(20) active, 0 bytes waiting)
└ @ Main ~/tmp/IOCapture-hang/buf.jl:25
┌ Warning: wait timed out after 30 seconds
│   f = "mathlink"
│   pipe = Pipe(RawFD(4294967295) closed => RawFD(20) active, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(4294967295) closed, 0 bytes waiting)
│   pipe.out = Base.PipeEndpoint(RawFD(20) active, 0 bytes waiting)
└ @ Main ~/tmp/IOCapture-hang/buf.jl:33
┌ Info: wait succeeded after closing pipe.out
│   f = "mathlink"
│   pipe = Pipe(RawFD(4294967295) closed => RawFD(4294967295) closed, 0 bytes waiting)
│   pipe.in = Base.PipeEndpoint(RawFD(4294967295) closed, 0 bytes waiting)
└   pipe.out = Base.PipeEndpoint(RawFD(4294967295) closed, 0 bytes waiting)
┌ Debug: Contents of redirected stdout
│   String(take!(output)) = ""
└ @ Main ~/tmp/IOCapture-hang/buf.jl:39

from iocapture.jl.

Hang when captureing output from MathLink about iocapture.jl HOT 7 OPEN

Comments (7)

Related Issues (10)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent

	f_val = f()
	@debug "result of calling f" f f_val
	f_val, true, Vector{Ptr{Cvoid}}()