OSX Travis fails spawn test with InterruptException

[tkelman]

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

[vtjnash]

@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?

[yuyichao]

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.

[JeffBezanson]

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

[tkelman]

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]

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?

[staticfloat]

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

[vtjnash]

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