Julia: OSX Travis fails spawn test with InterruptException

Created on 26 Jul 2016 · 25Comments · Source: JuliaLang/julia

e.g. https://travis-ci.org/JuliaLang/julia/jobs/147328890
or https://travis-ci.org/JuliaLang/julia/jobs/146808733

    From worker 6:       * spawn                       [stdio passthrough ok]
    From worker 6:  Error During Test
    From worker 6:    Test threw an exception of type InterruptException
    From worker 6:    Expression: success(truecmd)
    From worker 6:    InterruptException:
    From worker 6:     in push! at ./array.jl:444 [inlined]
    From worker 6:     in wait(::Condition) at ./event.jl:14
    From worker 6:     in stream_wait(::Base.Process, ::Condition, ::Vararg{Condition,N}) at ./stream.jl:44
    From worker 6:     in wait at ./process.jl:712 [inlined]
    From worker 6:     in success(::Base.Process) at ./process.jl:602
    From worker 6:     in success(::Cmd) at ./process.jl:608
    From worker 6:     in include_string(::String, ::String) at ./loading.jl:380
    From worker 6:     in include_from_node1(::String) at ./loading.jl:429
    From worker 6:     in macro expansion at ./util.jl:180 [inlined]
    From worker 6:     in runtests(::String) at /private/tmp/julia/share/julia/test/testdefs.jl:7
    From worker 6:     in (::Base.Serializer.__deserialized_types__.##277)(::String) at /private/tmp/julia/share/julia/test/runtests.jl:44
    From worker 6:     in (::Base.##499#501{Base.CallMsg{:call_fetch}})() at ./multi.jl:1193
    From worker 6:     in run_work_thunk(::Base.##499#501{Base.CallMsg{:call_fetch}}, ::Bool) at ./multi.jl:844
    From worker 6:     in macro expansion at ./multi.jl:1193 [inlined]
    From worker 6:     in (::Base.##498#500{Base.CallMsg{:call_fetch},Base.MsgHeader,TCPSocket})() at ./event.jl:46

O ci heisenbug mac test

Source

tkelman

Most helpful comment

@vtjnash said the fix may be only for 1.0. Anyways shouldn't hold 0.6.1 on it.

ViralBShah on 7 Oct 2017

👍2

All 25 comments

@yuyichao Could this be a SIGSEGV happening, but getting picked up by the catch_exception_raise, jl_addr_is_safepoint fiter? The backtrace seems to be too consistent, unless that ccall is really just the first safepoint?

vtjnash on 26 Jul 2016

Unless there's actually a SIGINT or further corruption (i.e. the signal pending flag is corrupted), the SEGV at safepoint should throw a interruption. If the signal pending flag is not set, a safepoint that didn't wait for the GC is assumed to be a GC safepoint that is triggered after the GC is finished and shouldn't throw anything.

yuyichao on 26 Jul 2016

This is happening fairly often. Will need to fix this to get reliable CI.

JeffBezanson on 29 Jul 2016

slightly different backtrace on this one, but probably same underlying cause

From worker 6:       * cmdlineargs          Error During Test
    From worker 6:    Test threw an exception of type InterruptException
    From worker 6:    Expression: readchomp(pipeline(ignorestatus(@cmd("\$exename --startup-file=no -p")),stderr=catcmd)) == "ERROR: option `-p/--procs` is missing an argument"
    From worker 6:    InterruptException:
    From worker 6:     in push! at ./array.jl:476 [inlined]
    From worker 6:     in #spawn#417(::Nullable{Base.ProcessChain}, ::Function, ::Cmd, ::Tuple{Base.DevNullStream,Pipe,Ptr{Void}}) at ./process.jl:472
    From worker 6:     in (::Base.#kw##spawn)(::Array{Any,1}, ::Base.#spawn, ::Cmd, ::Tuple{Base.DevNullStream,Pipe,Ptr{Void}}) at ./<missing>:0
    From worker 6:     in #spawn#416(::Nullable{Base.ProcessChain}, ::Function, ::Base.ErrOrCmds, ::Tuple{Base.DevNullStream,Pipe,Base.TTY}) at ./process.jl:385
    From worker 6:     in spawn(::Base.ErrOrCmds, ::Tuple{Base.DevNullStream,Pipe,Base.TTY}) at ./process.jl:378
    From worker 6:     in open(::Base.ErrOrCmds, ::String, ::Base.DevNullStream) at ./process.jl:524
    From worker 6:     in read(::Base.ErrOrCmds, ::Base.DevNullStream) at ./process.jl:559
    From worker 6:     in readstring; at ./process.jl:566 [inlined] (repeats 2 times)
    From worker 6:     in readchomp; at ./io.jl:324 [inlined]
    From worker 6:     in macro expansion; at /private/tmp/julia/share/julia/test/cmdlineargs.jl:250 [inlined]
    From worker 6:     in anonymous at ./<missing>:?
    From worker 6:     in include_string(::String, ::String) at ./loading.jl:380
    From worker 6:     in include_from_node1(::String) at ./loading.jl:429
    From worker 6:     in macro expansion at ./util.jl:226 [inlined]
    From worker 6:     in runtests(::String) at /private/tmp/julia/share/julia/test/testdefs.jl:7
    From worker 6:     in (::Base.Serializer.__deserialized_types__.##16#24)(::String) at /private/tmp/julia/share/julia/test/runtests.jl:44
    From worker 6:     in (::Base.##627#629{Base.CallMsg{:call_fetch}})() at ./multi.jl:1421
    From worker 6:     in run_work_thunk(::Base.##627#629{Base.CallMsg{:call_fetch}}, ::Bool) at ./multi.jl:1001
    From worker 6:     in macro expansion at ./multi.jl:1421 [inlined]
    From worker 6:     in (::Base.##626#628{Base.CallMsg{:call_fetch},Base.MsgHeader,TCPSocket})() at ./event.jl:68
    From worker 7:       * examples              in  23.67 seconds, maxrss  579.75 MB
Exception running test cmdlineargs :
On worker 6:
LoadError: There was an error during testing
 in record at ./test.jl:397
 in do_test at ./test.jl:281
 in macro expansion; at /private/tmp/julia/share/julia/test/cmdlineargs.jl:250 [inlined]
 in anonymous at ./<missing>:?
 in include_string at ./loading.jl:380
 in include_from_node1 at ./loading.jl:429
 in macro expansion at ./util.jl:226 [inlined]
 in runtests at /private/tmp/julia/share/julia/test/testdefs.jl:7
 in #16 at /private/tmp/julia/share/julia/test/runtests.jl:44
 in #627 at ./multi.jl:1421
 in run_work_thunk at ./multi.jl:1001
 in macro expansion at ./multi.jl:1421 [inlined]
 in #626 at ./event.jl:68
while loading /private/tmp/julia/share/julia/test/cmdlineargs.jl, in expression starting on line 11
ERROR: LoadError: Some tests exited with errors.
 in (::##11#19)() at /private/tmp/julia/share/julia/test/runtests.jl:72
 in cd(::##11#19, ::String) at ./file.jl:59
 in include_from_node1(::String) at ./loading.jl:426
 in process_options(::Base.JLOptions) at ./client.jl:262
 in _start() at ./client.jl:318
while loading /private/tmp/julia/share/julia/test/runtests.jl, in expression starting on line 26

tkelman on 10 Aug 2016

not Travis specific: buildbot log https://build.julialang.org/builders/build_osx10.9-x64/builds/1751/steps/shell_2/logs/stdio

Exception running test spawn :
On worker 7:
LoadError: InterruptException:
 in typeinf_edge at ./inference.jl:1627
 in typeinf_ext at ./inference.jl:1650
 in #pipeline at ./<missing>:0
 in jlcall_#pipeline_19864 at /Users/osx/buildbot/slave/build_osx10_9-x64/build/usr/lib/julia/sys.dylib:?
 in include_string at ./loading.jl:478
 in jlcall_include_string_33102 at /Users/osx/buildbot/slave/build_osx10_9-x64/build/usr/lib/julia/sys.dylib:?
 in include_from_node1 at ./loading.jl:544
 in jlcall_include_from_node1_18844 at /Users/osx/buildbot/slave/build_osx10_9-x64/build/usr/lib/julia/sys.dylib:?
 in macro expansion at ./util.jl:232 [inlined]
 in runtests at /Users/osx/buildbot/slave/build_osx10_9-x64/build/test/testdefs.jl:7
 in #619 at ./multi.jl:1425
 in run_work_thunk at ./multi.jl:1005
 in macro expansion at ./multi.jl:1425 [inlined]
 in #618 at ./event.jl:68
while loading /Users/osx/buildbot/slave/build_osx10_9-x64/build/test/spawn.jl, in expression starting on line 207
ERROR: LoadError: Some tests exited with errors.
 in (::##11#18)() at /Users/osx/buildbot/slave/build_osx10_9-x64/build/test/runtests.jl:72

@vtjnash ideas?

tkelman on 14 Sep 2016

Yep, just wanted to pop in and say this is still happening on the buildtest buildbots.

staticfloat on 22 Nov 2016

shucks, on the merge commit too: https://travis-ci.org/JuliaLang/julia/jobs/194054914

vtjnash on 21 Jan 2017

still failing https://travis-ci.org/JuliaLang/julia/jobs/194719508

Error in testset spawn:
Error During Test
  Test threw an exception of type TypeError
  Expression: ex::Base.UVError.code == Base.UV_EMFILE
  TypeError: anonymous: in typeassert, expected Base.UVError, got InterruptException

tkelman on 24 Jan 2017

Seems to be a new / different failure, in that it consistently occurs in a different test.

vtjnash on 24 Jan 2017

still failing... https://travis-ci.org/JuliaLang/julia/jobs/195872484
https://build.julialang.org/builders/build_osx10.9-x64/builds/2468/steps/shell_2/logs/stdio

tkelman on 27 Jan 2017

Here are two more that look possibly related:

https://travis-ci.org/JuliaLang/julia/jobs/200076193
https://travis-ci.org/JuliaLang/julia/jobs/200079892

JeffBezanson on 10 Feb 2017

https://travis-ci.org/JuliaLang/julia/jobs/200079892

I got similar failure on FreeBSD (4GB ram + 4GB swap on it).
https://julia.iblis.cnmc.tw/#/builders/1/builds/178/steps/6/logs/stdio
Seems this is caused by OS's OOM killer.

└─[iblis@ns]% uname -a
FreeBSD ns 12.0-CURRENT FreeBSD 12.0-CURRENT #3 r313500M: Fri Feb 10 22:39:13 CST 2017     root@ns:/usr/obj/usr/src/sys/GENERIC  amd64
┌─[~]
| [-- INSERT --]
└─[iblis@ns]% dmesg | tail
swap_pager: out of swap space
swap_pager_getswapspace(16): failed
pid 48631 (julia), uid 1001, was killed: out of swap space
swap_pager: out of swap space
swap_pager_getswapspace(16): failed
pid 70675 (julia), uid 1001, was killed: out of swap space
pid 70676 (julia), uid 1001, was killed: out of swap space
swap_pager: out of swap space
swap_pager_getswapspace(16): failed
pid 13530 (julia), uid 1001, was killed: out of swap space

iblis17 on 27 Feb 2017

Seems this is caused by OS's OOM killer.

I suspected it was something like this. I guess the solution would be to get Travis to raise some limit.

StefanKarpinski on 28 Feb 2017

Enable this again?
https://github.com/JuliaLang/julia/blob/master/.travis.yml#L134-L135

iblis17 on 28 Feb 2017

It got a different error message on a different test due to a different failure on a different kernel. Why would you suspect them to be related?

vtjnash on 28 Feb 2017

@vtjnash hmm... we are talking about this (https://travis-ci.org/JuliaLang/julia/jobs/200079892) build and this (https://julia.iblis.cnmc.tw/#/builders/1/builds/178/steps/6/logs/stdio) build. I think the error messages are similar.

iblis17 on 28 Feb 2017

https://travis-ci.org/JuliaLang/julia/jobs/200079892#L3590 is pretty different from this issue
The error message of https://travis-ci.org/JuliaLang/julia/jobs/200079892#L3590 is also very different from https://julia.iblis.cnmc.tw/#/builders/1/builds/178/steps/6/logs/stdio at line 110

yuyichao on 28 Feb 2017

I think this should be fixed for 1.0 since it is breaking tests on the buildbot and @vtjnash says he knows what to do.

cc @ararslan

ViralBShah on 6 Oct 2017

Once there's a fix, it should be backported to 0.6. Luckily the failure is only spurious, so in the meantime we can keep running the macOS builds on the buildbot repeatedly until one of them goes through...

ararslan on 7 Oct 2017

@vtjnash said the fix may be only for 1.0. Anyways shouldn't hold 0.6.1 on it.

ViralBShah on 7 Oct 2017

👍2

"things you wanted fixed soon" ≠ "release blocker"; throw the "priority" label on it for that.

StefanKarpinski on 7 Oct 2017

👍1

If Jameson knows how to fix it already, is there anything to triage?

ararslan on 7 Oct 2017

Can I assume that this is no longer relevant?

StefanKarpinski on 12 Feb 2018

It still happens occasionally though less often than it used to.

ararslan on 12 Feb 2018

fixed by #22041

vtjnash on 3 Oct 2018

Was this page helpful?

0 / 5 - 0 ratings

Related issues

Broadcasting a function on an array gives an expression

dpsanders · 3Comments

Should `where` be a keyword?

yurivish · 3Comments

0.5 `@test_skip` causes CI to fail

sbromberger · 3Comments

split() enhancement, keep_splitter

i-apellaniz · 3Comments

add special display for ≈ test failures

StefanKarpinski · 3Comments