thuehlinger / daemons

Ruby daemons gem official repository
MIT License
648 stars 71 forks source link

Problematic behavior when handling TERM Signal #84

Open scooler opened 3 years ago

scooler commented 3 years ago

Problem

It toke me quite a while to figure out why I was seeing errors like this in my logs:

I, [2021-11-02T20:58:33.944764 #131302]  INFO -- : *** below you find the most recent exception thrown, this will be likely (but not certainly) the exception that made the application exit abnormally ***                                   
E, [2021-11-02T20:58:33.944878 #131302] ERROR -- : Value will be available once the pipeline executes. (Redis::FutureNotReady)                                                                                                                

I, [2021-11-02T20:58:33.944946 #131302]  INFO -- : *** below you find all exception objects found in memory, some of them may have been thrown in your application, others may just be in memory because they are standard exceptions ***     
E, [2021-11-02T20:58:33.945208 #131302] ERROR -- : stream closed in another thread (IOError)                                                                                                                                                  

E, [2021-11-02T20:58:33.945298 #131302] ERROR -- : failed to allocate memory (NoMemoryError)                                                                                                                                                  

E, [2021-11-02T20:58:33.945372 #131302] ERROR -- : stack level too deep (SystemStackError)                                                                                                                                                    

E, [2021-11-02T20:58:33.945582 #131302] ERROR -- : machine stack overflow in critical region (fatal)                                                                                                                                          

E, [2021-11-02T20:58:33.945641 #131302] ERROR -- : exception reentered (fatal)                                                                                                                                                                

E, [2021-11-02T20:58:33.951859 #131302] ERROR -- : Value will be available once the pipeline executes. (Redis::FutureNotReady)

After some testing I managed to get it to show up when I would use daemon-rails' gem rake daemons:<name>:restart

I managed to figure out the reason, and IMO it's a pitfall that I wouldn't be the only one to fall into.

daemons catches the TERM Signal internally to wrapup the work (:+1: ). But Signal.trap (or Kernel.trap for that matter) work in such a way, that when you define a handler, you overwrite the handler that was previously defined (the method returns the previous handler, but you have to know & remember about it). So to ovewrite daemons' intermal TERM handling it's a matter of simple:

Signal.trap('TERM') do
  $running = false
end

I've seen this done or suggested. (and I was doing this myself).

Then daemons creates these logs as in if options[:backtrace] && !options[:ontop] && !$daemons_sigterm - it depends on $daemons_sigterm to be set. Meaning if daemons didn't receive a TERM signal, and it's stopping, it thinks it's a termination due to failure, and tries to figure out what went wrong.

BUT doing a daemons-rails :restart or even, daemons' Application.stop calls/sends TERM - and so causes these ERRORs in the logs if you happen to trap the TERM signal.

Solution

For me the "passing" the Signal with this approach helped.

daemons handles it internally - providing an option, but I only learned about this when digging through the code.

So long story short - what do you think about mentioning this issue with Signal in Readme or documentation ? :thinking: Or even mention the options[:stop_proc] in readme or documentation :thinking: (I couldn't find mention of it :( ) I mean I could write something, but I'm interested in another opinion :)