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

serialize(io, handler) in tests no longer throws an exception #184

Closed
KristofferC opened this issue Feb 19, 2022 · 3 comments · Fixed by #189
Closed

serialize(io, handler) in tests no longer throws an exception #184

KristofferC opened this issue Feb 19, 2022 · 3 comments · Fixed by #189

Comments

@KristofferC
Copy link
Contributor

The following code no longer throws on Julia 1.8 leading to a test failure:

Memento.jl/test/handlers.jl

Lines 117 to 123 in eccf67a

try
serialize(io, handler)
@test false
catch e
@test e isa ErrorException
@test e.msg == "cannot serialize a running Task"
end

I haven't looked into it in detail but it would be good to understand what changed. Maybe the serializer can handle the conditions that it previously failed on?

PkgEval report: https://s3.amazonaws.com/julialang-reports/nanosoldier/pkgeval/by_hash/f51f24c_vs_2ca8b0c/Memento.primary.log

@iamed2
Copy link
Member

iamed2 commented Feb 23, 2022

I tried to reproduce the original error in the comment above and I ended up here:

julia> pmap(1:3) do i
           Memento.info(LOGGER, i)  # ERROR: cannot serialize a running Task
       end
ERROR: On worker 2:
MethodError: no method matching info(::Logger, ::Int64)
Closest candidates are:
  info(::Logger, ::AbstractString) at ~/.julia/packages/Memento/Qk5GZ/src/loggers.jl:425 (method too new to be called from this world context.)
Stacktrace:
 [1] #11
   @ ./REPL[21]:2
 [2] #invokelatest#2
   @ ./essentials.jl:729
 [3] invokelatest
   @ ./essentials.jl:727
 [4] #106
   @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:285
 [5] run_work_thunk
   @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:70
 [6] macro expansion
   @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:285 [inlined]
 [7] #105
   @ ./task.jl:476
Stacktrace:
  [1] (::Base.var"#932#934")(x::Task)
    @ Base ./asyncmap.jl:177
  [2] foreach(f::Base.var"#932#934", itr::Vector{Any})
    @ Base ./abstractarray.jl:2769
  [3] maptwice(wrapped_f::Function, chnl::Channel{Any}, worker_tasks::Vector{Any}, c::UnitRange{Int64})
    @ Base ./asyncmap.jl:177
  [4] wrap_n_exec_twice
    @ ./asyncmap.jl:153 [inlined]
  [5] #async_usemap#917
    @ ./asyncmap.jl:103 [inlined]
  [6] #asyncmap#916
    @ ./asyncmap.jl:81 [inlined]
  [7] pmap(f::Function, p::WorkerPool, c::UnitRange{Int64}; distributed::Bool, batch_size::Int64, on_error::Nothing, retry_delays::Vector{Any}, retry_check::Nothing)
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:126
  [8] pmap(f::Function, p::WorkerPool, c::UnitRange{Int64})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:101
  [9] pmap(f::Function, c::UnitRange{Int64}; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:156
 [10] pmap(f::Function, c::UnitRange{Int64})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:156
 [11] top-level scope
    @ REPL[21]:1

julia> pmap(1:3) do i
           Memento.info(LOGGER, string(i))  # ERROR: cannot serialize a running Task
       end
      From worker 2:
      From worker 2:	signal (11): Segmentation fault: 11
      From worker 2:	in expression starting at none:0
      From worker 2:	uv__check_before_write at /workspace/srcdir/libuv/src/unix/stream.c:1406
      From worker 2:	uv_write2 at /workspace/srcdir/libuv/src/unix/stream.c:1449
      From worker 2:	uv_write at /workspace/srcdir/libuv/src/unix/stream.c:1517
      From worker 2:	jl_uv_write at /Users/ericdavies/repos/julia1p8/src/jl_uv.c:478
      From worker 2:	uv_write_async at ./stream.jl:1075
      From worker 2:	uv_write at ./stream.jl:1032
      From worker 2:	unsafe_write at ./stream.jl:1115
      From worker 2:	write at ./strings/io.jl:244 [inlined]
      From worker 2:	print at ./strings/io.jl:246 [inlined]
      From worker 2:	#with_output_color#909 at ./util.jl:107
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	do_apply at /Users/ericdavies/repos/julia1p8/src/builtins.c:725
      From worker 2:	with_output_color##kw at ./util.jl:74
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	do_apply at /Users/ericdavies/repos/julia1p8/src/builtins.c:725
      From worker 2:	#printstyled#910 at ./util.jl:130
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	do_apply at /Users/ericdavies/repos/julia1p8/src/builtins.c:725
      From worker 2:	printstyled##kw at ./util.jl:130
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	emit at /Users/ericdavies/.julia/packages/Memento/Qk5GZ/src/handlers.jl:211
      From worker 2:	log at /Users/ericdavies/.julia/packages/Memento/Qk5GZ/src/handlers.jl:44
      From worker 2:	unknown function (ip: 0x10543ec4d)
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	log at /Users/ericdavies/.julia/packages/Memento/Qk5GZ/src/loggers.jl:366
      From worker 2:	unknown function (ip: 0x105428c1d)
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	_log at /Users/ericdavies/.julia/packages/Memento/Qk5GZ/src/loggers.jl:411
      From worker 2:	log at /Users/ericdavies/.julia/packages/Memento/Qk5GZ/src/loggers.jl:390 [inlined]
      From worker 2:	info at /Users/ericdavies/.julia/packages/Memento/Qk5GZ/src/loggers.jl:426 [inlined]
      From worker 2:	#13 at ./REPL[22]:2
      From worker 2:	unknown function (ip: 0x10543cc05)
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	jl_f__call_latest at /Users/ericdavies/repos/julia1p8/src/builtins.c:769
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	do_apply at /Users/ericdavies/repos/julia1p8/src/builtins.c:725
      From worker 2:	#invokelatest#2 at ./essentials.jl:729
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	do_apply at /Users/ericdavies/repos/julia1p8/src/builtins.c:725
      From worker 2:	invokelatest at ./essentials.jl:727
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	do_apply at /Users/ericdavies/repos/julia1p8/src/builtins.c:725
      From worker 2:	#106 at /Users/ericdavies/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:285
      From worker 2:	run_work_thunk at /Users/ericdavies/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:70
      From worker 2:	macro expansion at /Users/ericdavies/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:285 [inlined]
      From worker 2:	#105 at ./task.jl:476
      From worker 2:	unknown function (ip: 0x1053f291f)
      From worker 2:	_jl_invoke at /Users/ericdavies/repos/julia1p8/src/gf.c:0 [inlined]
      From worker 2:	ijl_apply_generic at /Users/ericdavies/repos/julia1p8/src/gf.c:2522
      From worker 2:	jl_apply at /Users/ericdavies/repos/julia1p8/src/./julia.h:1825 [inlined]
      From worker 2:	start_task at /Users/ericdavies/repos/julia1p8/src/task.c:931
      From worker 2:	Allocations: 15555769 (Pool: 15548895; Big: 6874); GC: 19
Worker 2 terminated.ERROR:
ProcessExitedException(Unhandled Task ERROR: EOFError: read end of file
Stacktrace:
 [1] (::Base.var"#wait_locked#674")(s::Sockets.TCPSocket, buf::IOBuffer, nb::Int64)
   @ Base ./stream.jl:941
 [2] unsafe_read(s::Sockets.TCPSocket, p::Ptr{UInt8}, nb::UInt64)
   @ Base ./stream.jl:950
 [3] unsafe_read
   @ ./io.jl:759 [inlined]
 [4] unsafe_read(s::Sockets.TCPSocket, p::Base.RefValue{NTuple{4, Int64}}, n::Int64)
   @ Base ./io.jl:758
 [5] read!
   @ ./io.jl:760 [inlined]
 [6] deserialize_hdr_raw
   @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/messages.jl:167 [inlined]
 [7] message_handler_loop(r_stream::Sockets.TCPSocket, w_stream::Sockets.TCPSocket, incoming::Bool)
   @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:172
 [8] process_tcp_streams(r_stream::Sockets.TCPSocket, w_stream::Sockets.TCPSocket, incoming::Bool)
   @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/process_messages.jl:133
 [9] (::Distributed.var"#99#100"{Sockets.TCPSocket, Sockets.TCPSocket, Bool})()
   @ Distributed ./task.jl:476
2)
Stacktrace:
  [1] try_yieldto(undo::typeof(Base.ensure_rescheduled))
    @ Base ./task.jl:834
  [2] wait()
    @ Base ./task.jl:894
  [3] wait(c::Base.GenericCondition{ReentrantLock})
    @ Base ./condition.jl:124
  [4] take_buffered(c::Channel{Any})
    @ Base ./channels.jl:416
  [5] take!(c::Channel{Any})
    @ Base ./channels.jl:410
  [6] take!(::Distributed.RemoteValue)
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/remotecall.jl:726
  [7] remotecall_fetch(f::Function, w::Distributed.Worker, args::Int64; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/remotecall.jl:461
  [8] remotecall_fetch(f::Function, w::Distributed.Worker, args::Int64)
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/remotecall.jl:457
  [9] remotecall_fetch(f::Function, id::Int64, args::Int64; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/remotecall.jl:492
 [10] remotecall_fetch(f::Function, id::Int64, args::Int64)
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/remotecall.jl:492
 [11] remotecall_pool(rc_f::Function, f::Function, pool::WorkerPool, args::Int64; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/workerpool.jl:123
 [12] remotecall_pool
    @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/workerpool.jl:121 [inlined]
 [13] #remotecall_fetch#194
    @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/workerpool.jl:229 [inlined]
 [14] remotecall_fetch
    @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/workerpool.jl:229 [inlined]
 [15] #202#203
    @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/workerpool.jl:274 [inlined]
 [16] #202
    @ ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/workerpool.jl:274 [inlined]
 [17] (::Base.var"#922#927"{Distributed.var"#202#204"{Distributed.var"#202#203#205"{WorkerPool, var"#13#14"}}})(r::Base.RefValue{Any}, args::Tuple{Int64})
    @ Base ./asyncmap.jl:100
 [18] macro expansion
    @ ./asyncmap.jl:234 [inlined]
 [19] (::Base.var"#938#939"{Base.var"#922#927"{Distributed.var"#202#204"{Distributed.var"#202#203#205"{WorkerPool, var"#13#14"}}}, Channel{Any}, Nothing})()
    @ Base ./task.jl:476
Stacktrace:
  [1] (::Base.var"#932#934")(x::Task)
    @ Base ./asyncmap.jl:177
  [2] foreach(f::Base.var"#932#934", itr::Vector{Any})
    @ Base ./abstractarray.jl:2769
  [3] maptwice(wrapped_f::Function, chnl::Channel{Any}, worker_tasks::Vector{Any}, c::UnitRange{Int64})
    @ Base ./asyncmap.jl:177
  [4] wrap_n_exec_twice
    @ ./asyncmap.jl:153 [inlined]
  [5] #async_usemap#917
    @ ./asyncmap.jl:103 [inlined]
  [6] #asyncmap#916
    @ ./asyncmap.jl:81 [inlined]
  [7] pmap(f::Function, p::WorkerPool, c::UnitRange{Int64}; distributed::Bool, batch_size::Int64, on_error::Nothing, retry_delays::Vector{Any}, retry_check::Nothing)
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:126
  [8] pmap(f::Function, p::WorkerPool, c::UnitRange{Int64})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:101
  [9] pmap(f::Function, c::UnitRange{Int64}; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:156
 [10] pmap(f::Function, c::UnitRange{Int64})
    @ Distributed ~/repos/julia1p8/usr/share/julia/stdlib/v1.8/Distributed/src/pmap.jl:156
 [11] top-level scope
    @ REPL[22]:1

A few more experiments had processes segfault like that as well. Given that, I don't have time to look further. Maybe someone else will pick it up.

@bicepjai
Copy link

bicepjai commented May 5, 2022

I have the same issue

julia> versioninfo()
Julia Version 1.6.6
Commit b8708f954a (2022-03-28 07:17 UTC)
Platform Info:
  OS: Linux (x86_64-pc-linux-gnu)
  CPU: Intel(R) Xeon(R) CPU E5-1650 v3 @ 3.50GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-11.0.1 (ORCJIT, haswell)
Environment:
  JULIA_NUM_THREADS = 8
  JULIA_EDITOR = code

(@v1.6) pkg> status Memento
      Status `~/.julia/environments/v1.6/Project.toml`
  [f28f55f0] Memento v1.3.1

@iamed2
Copy link
Member

iamed2 commented Oct 4, 2022

@KristofferC we tracked it down to JuliaLang/julia#43325! Looks like this is an issue that was fixed.

The pmap has a segfault issue on both 1.6 and 1.8 (I don't know what it is but it's probably something that should be fixed somewhere), but it looks like the task serialization error goes away. I think we're good to make the failure test conditional on older versions.

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.

3 participants