[BUG] Sometimes errors with Memento

[oxinabox]

description

If I call weave some script analysis.jl which at some point calls a function that uses Memento.jl to log something, if Memento is loaded inside the call to weave (e.g. from a using line inside analysis.jl), then i get an IOError.

If I load Memento first before loading calling weave then all is well.

versions

julia> using InteractiveUtils; versioninfo()
Julia Version 1.6.3-pre.1
Commit 7c45ff0e94 (2021-07-16 20:20 UTC)
Platform Info:
  OS: Linux (x86_64-linux-gnu)
  CPU: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-11.0.1 (ORCJIT, tigerlake)

julia> using Pkg; Pkg.status()
      Status `~/temp/Project.toml`
  [f28f55f0] Memento v1.2.0
  [44d3d7a6] Weave v0.10.10
  [91a5bcdd] Plots v1.22.3

minimum reproducible steps

I don't have a minimum reproducer, yet.
I am working on it.

Here is the stacktrace
It is hard to report what because of #431 but I hacked up Weave.jl and I have a stacktrace:

/tmp/jl_vWopSH❱ ✔ ❱ julia-1.6 --project=. -e "using Weave; weave(\"analysis.jl\"; doctype=\"md2html\", out_path=pwd()); "     20:14:23
┌ Info: Weaving chunk 1 from line 2
└   progress = 0.0
  Activating environment at `/tmp/jl_vWopSH/Project.toml`
┌ Info: Weaving chunk 2 from line 7
└   progress = 0.25
[ Info: For saving to png with the Plotly backend PlotlyBase has to be installed.
┌ Info: Weaving chunk 3 from line 25
└   progress = 0.5
┌ Info: Weaving chunk 3 from line 28
└   progress = 0.75
┌ Info: Weaved all chunks
└   progress = 1
ERROR: LoadError: IOError: stream is closed or unusable
Stacktrace:
  [1] check_open
    @ ./stream.jl:386 [inlined]
  [2] uv_write_async(s::Base.PipeEndpoint, p::Ptr{UInt8}, n::UInt64)
    @ Base ./stream.jl:1018
  [3] uv_write(s::Base.PipeEndpoint, p::Ptr{UInt8}, n::UInt64)
    @ Base ./stream.jl:981
  [4] unsafe_write(s::Base.PipeEndpoint, p::Ptr{UInt8}, n::UInt64)
    @ Base ./stream.jl:1064
  [5] write
    @ ./strings/io.jl:185 [inlined]
  [6] print
    @ ./strings/io.jl:187 [inlined]
  [7] with_output_color(::Function, ::Symbol, ::Base.PipeEndpoint, ::String, ::Vararg{String, N} where N; bold::Bool)
    @ Base ./util.jl:77
  [8] printstyled(::Base.PipeEndpoint, ::String, ::Vararg{String, N} where N; bold::Bool, color::Symbol)
    @ Base ./util.jl:105
  [9] emit(handler::Memento.DefaultHandler{Memento.DefaultFormatter, Base.PipeEndpoint}, rec::Memento.DefaultRecord)
    @ Memento ~/.julia/packages/Memento/IanT6/src/handlers.jl:211
 [10] log(handler::Memento.DefaultHandler{Memento.DefaultFormatter, Base.PipeEndpoint}, rec::Memento.DefaultRecord)
    @ Memento ~/.julia/packages/Memento/IanT6/src/handlers.jl:44
 [11] log(logger::Memento.Logger, rec::Memento.DefaultRecord)
    @ Memento ~/.julia/packages/Memento/IanT6/src/loggers.jl:366
 [12] _log(logger::Memento.Logger, level::String, msg::String)
    @ Memento ~/.julia/packages/Memento/IanT6/src/loggers.jl:411
 [13] log
    @ ~/.julia/packages/Memento/IanT6/src/loggers.jl:390 [inlined]
 [14] info
    @ ~/.julia/packages/Memento/IanT6/src/loggers.jl:426 [inlined]
 <<A WHOLE BUNCH OF CALLS TO A PACKAGE THAT USES MEMENTO>>
 [31] top-level scope
    @ /tmp/jl_vWopSH/analysis.jl:2
 [32] eval
    @ ./boot.jl:360 [inlined]
 [33] include_string(mapexpr::typeof(identity), mod::Module, code::String, filename::String)
    @ Base ./loading.jl:1116
 [34] include_string
    @ ./loading.jl:1126 [inlined]
 [35] (::Weave.var"#32#34"{String, Module, String, Task, Base.PipeEndpoint, Base.PipeEndpoint, Base.TTY})()
    @ Weave /tmp/jl_vWopSH/dev/Weave/src/run.jl:218
 [36] task_local_storage(body::Weave.var"#32#34"{String, Module, String, Task, Base.PipeEndpoint, Base.PipeEndpoint, Base.TTY}, key::Symbol, val::String)
    @ Base ./task.jl:281
 [37] capture_output(code::String, mod::Module, path::String, error::Bool, report::Weave.Report)
    @ Weave /tmp/jl_vWopSH/dev/Weave/src/run.jl:216
 [38] #29
    @ /tmp/jl_vWopSH/dev/Weave/src/run.jl:191 [inlined]
 [39] _broadcast_getindex_evalf
    @ ./broadcast.jl:648 [inlined]
 [40] _broadcast_getindex
    @ ./broadcast.jl:621 [inlined]
 [41] getindex
    @ ./broadcast.jl:575 [inlined]
 [42] macro expansion
    @ ./broadcast.jl:984 [inlined]
 [43] macro expansion
    @ ./simdloop.jl:77 [inlined]
 [44] copyto!
    @ ./broadcast.jl:983 [inlined]
 [45] copyto!
    @ ./broadcast.jl:936 [inlined]
 [46] copy
    @ ./broadcast.jl:908 [inlined]
 [47] materialize(bc::Base.Broadcast.Broadcasted{Base.Broadcast.DefaultArrayStyle{1}, Nothing, Weave.var"#29#30"{Weave.Report, Module, Bool, String}, Tuple{Vector{String}}})
    @ Base.Broadcast ./broadcast.jl:883
 [48] run_code(doc::Weave.WeaveDoc, chunk::Weave.CodeChunk, report::Weave.Report, mod::Module)
    @ Weave /tmp/jl_vWopSH/dev/Weave/src/run.jl:192
 [49] eval_chunk(doc::Weave.WeaveDoc, chunk::Weave.CodeChunk, report::Weave.Report, mod::Module)
    @ Weave /tmp/jl_vWopSH/dev/Weave/src/run.jl:263
 [50] run_chunk
    @ /tmp/jl_vWopSH/dev/Weave/src/run.jl:133 [inlined]
 [51] run_doc(doc::Weave.WeaveDoc; doctype::String, out_path::String, args::Dict{Any, Any}, mod::Nothing, fig_path::Nothing, fig_ext::Nothing, cache_path::String, cache::Symbol)
    @ Weave /tmp/jl_vWopSH/dev/Weave/src/run.jl:74
 [52] weave(source::String; doctype::String, informat::Nothing, out_path::String, args::Dict{Any, Any}, mod::Nothing, fig_path::Nothing, fig_ext::Nothing, cache_path::String, cache::Symbol, template::Nothing, css::Nothing, highlight_theme::Nothing, pandoc_options::Vector{String}, latex_cmd::Vector{String}, keep_unicode::Bool)
    @ Weave /tmp/jl_vWopSH/dev/Weave/src/Weave.jl:176
in expression starting at /tmp/jl_vWopSH/analysis.jl:2

In contrast if I load memento outside the weave beforehand:

/tmp/jl_vWopSH❱ ✘ ❱ julia-1.6 --project=. -e "using Weave, Memento; weave(\"analysis.jl\"; doctype=\"md2html\", out_path=pwd()); "
┌ Info: Weaving chunk 1 from line 2
└   progress = 0.0
  Activating environment at `/tmp/jl_vWopSH/Project.toml`
┌ Info: Weaving chunk 2 from line 7
└   progress = 0.25
[ Info: For saving to png with the Plotly backend PlotlyBase has to be installed.
┌ Info: Weaving chunk 3 from line 25
└   progress = 0.5
┌ Info: Weaving chunk 3 from line 28
└   progress = 0.75
[info | FOOBAR]: SOME  NICE MEMENTO LOGS
[info | FOOBAR]: SOME MORE NICE MEMENTO LOGS
┌ Info: Weaved all chunks
└   progress = 1
[ Info: Weaved to /tmp/jl_vWopSH/analysis.html