crystal-lang / crystal

The Crystal Programming Language
https://crystal-lang.org
Apache License 2.0
19.42k stars 1.62k forks source link

exception in finalize halts program? #3996

Open rdp opened 7 years ago

rdp commented 7 years ago
class Foo
  def finalize
    # Invoked when Foo is garbage-collected
    puts "Bye bye from #{self}!"
    raise "boom"
  end
end

loop do
  Foo.new
end

Output:

$ crystal bad.cr
Bye bye from #<Foo:0x10e4fb600>!
Bye bye from #<Foo:0x10d4a56a0>!
boom (Exception)
Bye bye from #<Foo:0x10e4fb610>!
Failed to raise an exception: END_OF_STACK
[4516129659] *CallStack::print_backtrace:Int32 +107
[4516089934] __crystal_raise +78
[4516090489] *raise<Exception>:NoReturn +137
[4516090337] *raise<String>:NoReturn +17
[4516272930] *Foo#finalize:NoReturn +98
[4516104049] ~procProc(Pointer(Void), Pointer(Void), NoReturn)@/usr/local/Cellar/crystal-lang/0.20.5/src/gc/boehm.cr:108 +17
[4516960480] GC_invoke_finalizers +172
[4516960815] GC_notify_or_invoke_finalizers +174
[4516965813] GC_generic_malloc +37
[4516966426] GC_malloc_kind_global +234
[4516091835] __crystal_malloc_atomic +11
[4516150585] *GC::malloc_atomic<UInt32>:Pointer(Void) +9
[4516149150] *String#byte_slice<Int32, Int32>:String +286
[4516147828] *String#[]<Int32, Int32>:String +84
[4516194373] *File::basename<String>:String +213
[4516108698] *CallStack::dwarf_line_numbers:(Debug::DWARF::LineNumbers | Nil) +474
[4516107582] *CallStack::decode_line_number<Pointer(Void)>:Tuple(String | Nil, Int32, Int32) +30
[4516106830] *CallStack#decode_backtrace:Array(String) +142
[4516106657] *CallStack#printable_backtrace:Array(String) +49
[4516193688] *Exception+@Exception#backtrace?:(Array(String) | Nil) +72
[4516192990] *Exception+@Exception#inspect_with_backtrace<IO::FileDescriptor>:IO::FileDescriptor +110
[4516103854] main +142

and program hard exits.

I might be expect it to output the exception to the screen, but not to hard exit.

Also with that snippet without the raise line, on OS X 1/3 times I get this hard failure immediately:

Invalid memory access (signal 11) at address 0x0
[4454657387] *CallStack::print_backtrace:Int32 +107
[4454631735] __crystal_sigfault_handler +55
[4454804579] sigfault_handler +35
[140735613365178] _sigtramp +26
[4454699622] *Pointer(Fiber)@Pointer(T)#[]=<Int32, Fiber>:Fiber +22
[4454697338] *Deque(Fiber)@Deque(T)#push<Fiber>:Deque(Fiber) +106
[4454697225] *Deque(Fiber)@Deque(T)#<<<Fiber>:Deque(Fiber) +9
[4454703792] *IO::FileDescriptor#wait_writable<(Float64 | Nil)>:Nil +160
[4454703613] *IO::FileDescriptor#wait_writable:Nil +45
[4454702955] *IO::FileDescriptor#unbuffered_write<Slice(UInt8)>:Int32 +555
[4454703957] *IO::FileDescriptor@IO::Buffered#flush:IO::FileDescriptor +69
[4454704340] *IO::FileDescriptor@IO::Buffered#write_byte<UInt8>:(IO::FileDescriptor | Int32 | Nil) +180
[4454692018] *Char#to_s<IO::FileDescriptor>:(IO::FileDescriptor | Int32 | Nil) +210
[4454704135] *IO::FileDescriptor@IO#<<<Char>:IO::FileDescriptor +23
[4454704093] *IO::FileDescriptor@IO#print<Char>:Nil +13
[4454704078] *IO::FileDescriptor@IO#puts:Nil +14
[4454701352] *IO::FileDescriptor@IO#puts<String>:Nil +56
[4454631833] *puts<String>:Nil +41
[4454803475] *Foo#finalize:Nil +83
[4454631777] ~proc5Proc(Pointer(Void), Pointer(Void), Nil)@/Users/packrd/dev/ruby/downloads/crystal/src/gc/boehm.cr:108 +17
[4455479520] GC_invoke_finalizers +172
[4455479855] GC_notify_or_invoke_finalizers +174
[4455484853] GC_generic_malloc +37
[4455485466] GC_malloc_kind_global +234
[4454617019] __crystal_malloc +11
[4454699273] *Pointer(Fiber)@Pointer(T)::malloc<Int32>:Pointer(Fiber) +73
[4454697430] *Deque(Fiber)@Deque(T)#increase_capacity:(Int32 | Nil) +54
[4454697269] *Deque(Fiber)@Deque(T)#push<Fiber>:Deque(Fiber) +37
[4454697225] *Deque(Fiber)@Deque(T)#<<<Fiber>:Deque(Fiber) +9
[4454703792] *IO::FileDescriptor#wait_writable<(Float64 | Nil)>:Nil +160
[4454703613] *IO::FileDescriptor#wait_writable:Nil +45
[4454702955] *IO::FileDescriptor#unbuffered_write<Slice(UInt8)>:Int32 +555
[4454703957] *IO::FileDescriptor@IO::Buffered#flush:IO::FileDescriptor +69
[4454704340] *IO::FileDescriptor@IO::Buffered#write_byte<UInt8>:(IO::FileDescriptor | Int32 | Nil) +180
[4454692018] *Char#to_s<IO::FileDescriptor>:(IO::FileDescriptor | Int32 | Nil) +210
[4454704135] *IO::FileDescriptor@IO#<<<Char>:IO::FileDescriptor +23
[4454704093] *IO::FileDescriptor@IO#print<Char>:Nil +13
[4454704078] *IO::FileDescriptor@IO#puts:Nil +14
[4454701352] *IO::FileDescriptor@IO#puts<String>:Nil +56
[4454631833] *puts<String>:Nil +41
[4454803475] *Foo#finalize:Nil +83
[4454631777] ~proc5Proc(Pointer(Void), Pointer(Void), Nil)@/Users/packrd/dev/ruby/downloads/crystal/src/gc/boehm.cr:108 +17
[4455479520] GC_invoke_finalizers +172
[4455479855] GC_notify_or_invoke_finalizers +174
[4455484853] GC_generic_malloc +37
[4455485466] GC_malloc_kind_global +234
[4454619563] __crystal_malloc_atomic +11
[4454678425] *GC::malloc_atomic<UInt32>:Pointer(Void) +9
[4454668467] *String::Builder#initialize:Bool +51
[4454668385] *String::Builder::new:String::Builder +129
[4454803409] *Foo#finalize:Nil +17
[4454631777] ~proc5Proc(Pointer(Void), Pointer(Void), Nil)@/Users/packrd/dev/ruby/downloads/crystal/src/gc/boehm.cr:108 +17
[4455479520] GC_invoke_finalizers +172
[4455479855] GC_notify_or_invoke_finalizers +174
[4455487382] GC_generic_malloc_many +67
[4455517170] GC_malloc_kind +163
[4454617019] __crystal_malloc +11
[4454803337] *Foo@Reference::new:Foo +25
[4454616984] __crystal_main +1128
[4454631480] main +40

can't seem to repro it in inux, possibly a timing thing.

refi64 commented 7 years ago

FWIW, in C++, raising an exception in a destructor is undefined (a.k.a. your program will probably crash).

rdp commented 7 years ago

Yeah if there's some explicit contract that exceptions are disallowed it could be called out int the docs...but...my guess is hard exiting would not be preferred?

ysbaddaden commented 7 years ago

Finalizers are called from the GC context, which is foreign to Crystal land, and we can't unwind the stack, because no unwind table were generated. hence the failed to raise exception error message. This is the expected behavior; a segfault is just as expected (finalizer == free memory, close resources).

refi64 commented 7 years ago

Maybe Crystal could, when raise is called, detect if the user is in a finalizer and, if so, abort the program with an error?

rdp commented 7 years ago

perhaps instead of calling a crystal #finalize directly it calls a "proxy" method that wraps the real finalize in a begin rescue block?

ysbaddaden commented 7 years ago

@kirbyfan64 this is exactly what's happening, just not limited to finalizers (other C libraries will have that problem). It seems to be failing hard on macOS for some reason.

rdp commented 7 years ago

That snippet on linux gives me what I presume is a similar occurrence (and hard exit):


Failed to raise an exception: END_OF_STACK
[134726682] *CallStack::print_backtrace:Int32 +154
[134684035] __crystal_raise +131
[134685361] ???
[134685166] ???
[134916291] ???
[134701358] ???
[134925572] GC_invoke_finalizers +84
[134926202] GC_notify_or_invoke_finalizers +202
[134927537] GC_generic_malloc +33
[134928265] GC_malloc_kind_global +185
[134928398] GC_malloc +14
[134683022] __crystal_malloc +30
[134814415] *File::new<String, String, Int32, Nil, Nil>:File +63
[134712058] *CallStack::dwarf_line_numbers:(Debug::DWARF::LineNumbers | Nil) +378
[134710758] *CallStack::decode_line_number<Pointer(Void)>:Tuple(String | Nil, Int32, Int32) +54
[134709659] *CallStack#decode_backtrace:Array(String) +187
[134709449] *CallStack#printable_backtrace:Array(String) +73
[134814257] *Exception+ +97
[134813357] *Exception+ +173
[134701075] main +227
[-1219119314] __libc_start_main +222
[134680967] ???

FWIW...

silverweed commented 7 years ago

Couldn't this be detected at compile time? Maybe the parser could give error as soon as it finds a raise call in a finalize..?

asterite commented 7 years ago

@silverweed It's not that simple, that raise could be behind another method. The compiler knows when a method raises, but it doesn't track if all exceptions are rescued.

This issue is very low priority at this moment. Just like I said here, a finalizer is for freeing OS resources, like freeing a file descriptor, etc. One shouldn't allocate memory there or do anything complex.

rdp commented 7 years ago

Moving discussion of the dequeue trace to #4013 FWIW.

asterite commented 6 years ago

Actually Crystal knows when a method could potentially raise, and so we can detect this at compile-time and give an error... except that it becomes incredibly tedious to write those finalize them (in some cases the code could raise, but in practice it never happens, so you have to duplicate code and handle such cases with, say, LibC.printf and LibC.exit).

RX14 commented 6 years ago

We should just document it segfaults and make it GC.add_finalizer.

rdp commented 2 years ago

I guess the oddness here is that bdw gc runs the finalizers "later" after GC, at "the next malloc" after a GC, so these exceptions get raised in seemingly unrelated, arbitrary code that happens to trigger a collection...hmm...