search

kenichi / angelo

Sinatra-like DSL for Reel that supports WebSockets and SSE
Other
303 stars 23 forks source link

Crash on Ctrl+C #56

Closed rjattrill closed 9 years ago

rjattrill commented 9 years ago

Issuing a Ctrl+C to shutdown the server results in a stack dump.

Environment details:

C:\src\exlite\mockEo>jruby -v
jruby 9.0.0.0.rc1 (2.2.2) 2015-06-10 a0bf3b3 Java HotSpot(TM) 64-Bit Server VM 24.79-b02 on     1.7.0_79-b15 +jit [Windows 7-amd64]

C:\src\exlite\mockEo>jruby -S gem

*** LOCAL GEMS ***
angelo (0.4.1)
...
reel (0.5.0)
...

Crash message:

    C:\src\exlite\mockEo>jruby web_server.rb
    I, [2015-06-15T09:21:25.229000 #7940]  INFO -- : Angelo 0.4.1
    I, [2015-06-15T09:21:25.229000 #7940]  INFO -- : listening on localhost:4566
    I, [2015-06-15T09:22:01.676000 #7940]  INFO -- : 127.0.0.1 - - "POST /bid_set HTTP/1.1" 404 -
    ^C
    C:\src\exlite\mockEo>W, [2015-06-15T09:23:32.853000 #7940]  WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, statu
    s=:iowait
            Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces
     here.
    E, [2015-06-15T09:23:32.869000 #7940] ERROR -- : CLEANUP CRASHED!
    Java::JavaLang::NullPointerException:
            org.jruby.util.io.OpenFile.channel(OpenFile.java:2231)
            org.jruby.RubyIO.getChannel(RubyIO.java:403)
            org.nio4r.Nio4r$Selector.deregister(Nio4r.java:188)
            org.nio4r.Nio4r$Selector$INVOKER$i$1$0$deregister.call(Nio4r$Selector$INVOKER$i$1$0$deregister.gen)
            org.jruby.RubyClass.finvoke(RubyClass.java:746)
            org.jruby.runtime.Helpers.invoke(Helpers.java:416)
            org.jruby.RubyBasicObject.callMethod(RubyBasicObject.java:374)
            org.nio4r.Nio4r$Monitor.close(Nio4r.java:422)
            org.nio4r.Nio4r$Monitor.close(Nio4r.java:413)
            org.nio4r.Nio4r$Monitor$INVOKER$i$close.call(Nio4r$Monitor$INVOKER$i$close.gen)
            org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:293)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:131)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:308)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:129)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:115)
            org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:77)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
            org.jruby.ir.instructions.CallBase.interpret(CallBase.java:419)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:324)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:84)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:199)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:185)
            org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:205)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:161)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:292)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:84)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:199)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:185)
            org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:205)
            org.jruby.internal.runtime.methods.WrapperMethod.call(WrapperMethod.java:59)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:161)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:292)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:78)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:164)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:150)
            org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:197)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:129)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:308)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:137)
            org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:116)
            org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
            org.jruby.runtime.Block.yieldSpecific(Block.java:116)
            org.jruby.RubyKernel.loop(RubyKernel.java:1292)
            org.jruby.RubyKernel$INVOKER$s$0$0$loop.call(RubyKernel$INVOKER$s$0$0$loop.gen)
            org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroBlock.call(JavaMethod.java:473)
            org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:273)
            org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:79)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
            org.jruby.ir.instructions.CallBase.interpret(CallBase.java:419)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:324)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:129)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:115)
            org.jruby.RubyClass.finvoke(RubyClass.java:541)
            org.jruby.RubyBasicObject.send19(RubyBasicObject.java:1631)
            org.jruby.RubyBasicObject$INVOKER$i$send19.call(RubyBasicObject$INVOKER$i$send19.gen)
            org.jruby.RubyKernel.public_send(RubyKernel.java:1824)
            org.jruby.RubyKernel$INVOKER$s$0$0$public_send.call(RubyKernel$INVOKER$s$0$0$public_send.gen)
            org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:77)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
            org.jruby.ir.instructions.CallBase.interpret(CallBase.java:419)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:324)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:129)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:115)
            org.jruby.ir.runtime.IRRuntimeHelpers.instanceSuper(IRRuntimeHelpers.java:890)
            org.jruby.ir.instructions.InstanceSuperInstr.interpret(InstanceSuperInstr.java:69)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:324)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:84)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:199)
            org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:185)
            org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:205)
            org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:313)
            org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:163)
            org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:292)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:78)
            org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:137)
            org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:116)
            org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
            org.jruby.runtime.Block.yieldSpecific(Block.java:116)
            org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:456)
            org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
            org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:184)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:108)
            org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:137)
            org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:116)
            org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
            org.jruby.runtime.Block.yieldSpecific(Block.java:116)
            org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:456)
            org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
            org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:184)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:108)
            org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:137)
            org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:116)
            org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
            org.jruby.runtime.Block.yieldSpecific(Block.java:116)
            org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:456)
            org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
            org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:184)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:108)
            org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:137)
            org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:116)
            org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
            org.jruby.runtime.Block.yieldSpecific(Block.java:116)
            org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:456)
            org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
            org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:184)
            org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:108)
            org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:137)
            org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:116)
            org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:146)
            org.jruby.runtime.BlockBody.yield(BlockBody.java:83)
            org.jruby.runtime.Block.yieldArray(Block.java:161)
            org.jruby.ext.fiber.ThreadFiber$1.run(ThreadFiber.java:259)
            java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
            java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
            java.lang.Thread.run(Thread.java:745)
digitalextremist commented 9 years ago

@kenichi this type of exit handler should probably be put back, but not just used for profiling:

https://github.com/kenichi/angelo/blob/master/lib/angelo.rb#L140

The error shown has to do with somehow disrupting nio4r ... possibly due to not properly shutting down the reactor. But, with jruby, you cannot trap INT or any other kill-like signal directly.

Do something like:

at_exit { #de vs. trap signal {}
  Celluloid.shutdown
  sleep 2
}
kenichi commented 9 years ago

@rjattrill thanks for the report. i see this using plain reel too, both 0.5.0 and 0.6.0-milestone, so i kind of feel that it's not an angelo bug?

@digitalextremist thanks... i tried adding the at_exit to no avail. do you also see this with a plain reel server?

digitalextremist commented 9 years ago

@kenichi I've actually seen this before, now that I think about it. What happens, if it is what I think it is, is definitely on a Reel level also, and I'll look for it. What it is, I think, is that the server loop is sitting in socket.accept which is blocking until a connection. When the socket is taken away ( while being listened to ) it crashes the listener. Lately I've been doing different types of server loops, but often times the best thing you can do is catch the exception, test for shutdown conditions, and mute the output. A lot of times with Celluloid lately, it's so loud upon exit that once I've done all sensitive storage, etc.. I just mute the error output in general, but that's only until Celluloid becomes better about shutdown.

kenichi commented 9 years ago

@digitalextremist do you have some examples of what you're saying? my attempts at "quieting" celluloid usually make it "louder" :)

digitalextremist commented 9 years ago

@kenichi have you tried proper cheating?

def suppressed(&block)
  _ = Celluloid.logger.dup
  Celluloid.logger = ::Logger.new("/dev/null")
  return unless block_given?
  yield
  Celluloid.logger = _
end
kenichi commented 9 years ago

closing in favor of a fix in reel - reopen if determined to be an angelo issue.

rjattrill commented 8 years ago

I also see this in plain Reel. I can't see any open issue so will open one and reference here.

alhafoudh commented 8 years ago

@kenichi which fix are you reffering to? @rjattrill's fix does not fix this :( at least not for me.