Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Eye kills itself #62

Closed
tetherit opened this issue May 30, 2014 · 20 comments
Closed

Eye kills itself #62

tetherit opened this issue May 30, 2014 · 20 comments
Labels
Milestone

Comments

@tetherit
Copy link

I have this check:

require 'rtsp/client'
class Rtsp < Eye::Checker::CustomDefer
  param :addr, String, true

  def initialize(*args)
    super
    @addr = addr
    @rtsp_client = RTSP::Client.new(@addr)
  end

  def get_value
    begin
      if @rtsp_client.describe.code == 200
        check_with_ffmpeg
      else
        false
      end
    rescue
      false
    end
  end

  def good?(value)
    value
  end

  def human_value(value)
    value == true ? 'Ok' : 'Err'
  end

  private
  def check_with_ffmpeg
    system("ffmpeg -loglevel warning -y -stimeout 5000000 " \
      "-i #{@addr} -c:v copy -an -vframes 1 -f rawvideo /dev/null")
  end
end

It works most of the time, however sometimes, I get this in eye.log and it stops monitoring all processes:

[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68987a616e64da431e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]

The formatted output looks like this:

[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68e17a616e64de651e00:proxy] check:rtsp task was terminated
celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'
celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'
celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'
celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'
celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'
celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'
celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'
celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'
celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'
celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'

Any ideas why it happened and how to prevent this from happening?

@kostya
Copy link
Owner

kostya commented May 30, 2014

seems, it happen when you process restart or stop and celluloid kill your long running(sleeping) check. So there is no problem, as it seems.
What you mean with " and it stops monitoring all processes:"?
Show log before and after error.

@tetherit
Copy link
Author

There is no more log after this line - that is the last log in the file, here is the log before this line and after restarting eye the next day (look at the date stamp):

[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:proxy] daemonizing: `live555ProxyServer -p 10113 -V rtsp://192.168.88.202/2` with start_grace: 2.5s, env: '', <3510> (in /data/deployer/xanagent/releases/20140520102144/tmp/recorder)
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:proxy] sleeping for :start_grace 2.5
[2014-05-29 21:55:57 +0100] [recorder:537f2a907a616e33bd59a700:proxy] check:cpu(<85%) [0%, 0%] => OK
[2014-05-29 21:55:57 +0100] [recorder:537f2a907a616e33bd59a700:proxy] check:memory(<300Mb) [1Mb, 1Mb] => OK
[2014-05-29 21:55:57 +0100] [recorder:537b68c87a616e64da541e00:proxy] check:cpu(<85%) [0%, 0%] => OK
[2014-05-29 21:55:57 +0100] [recorder:537b68c87a616e64da541e00:proxy] check:memory(<300Mb) [1Mb, 1Mb] => OK
[2014-05-29 21:55:57 +0100] [recorder:537f2ab57a616e33b903a900:proxy] check:cpu(<85%) [0%, 0%] => OK
[2014-05-29 21:55:57 +0100] [recorder:537f2ab57a616e33b903a900:proxy] check:memory(<300Mb) [1Mb, 1Mb] => OK
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] check:ctime [*21:52, *21:52] => Fail
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] NOTIFY: Bounded ctime: [*21:52, *21:52] send to [:restart]
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] schedule :restart (reason: bounded ctime)
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] => restart  (reason: bounded ctime)
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] switch :restarting [:up => :restarting] (reason: bounded ctime)
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] switch :stopping [:restarting => :stopping] (reason: bounded ctime)
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] send_signal TERM to 28836
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] sleeping for :stop_grace 0.5
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] check:cpu(<85%) [1%, 2%] => OK
[2014-05-29 21:55:57 +0100] [recorder:537b68eb7a616e64e20d1e00:detector] check:memory(<300Mb) [84Mb, 84Mb] => OK
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:call, meta={:method_name=>:process}, status=:callwait
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:call, meta={:method_name=>:process}, status=:callwait
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:call, meta={:method_name=>:send}, status=:sleeping
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:call, meta={:method_name=>:send}, status=:sleeping
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537f2a907a616e33bd59a700:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537f2a9c7a616e33c111a800:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537f2a867a616e33c10aa800:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68be7a616e64de4c1e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68c87a616e64da541e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68c87a616e64da541e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68d77a616e64de611e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537b68e17a616e64de651e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [celluloid] Terminating task: type=:timer, meta=nil, status=:receiving
[2014-05-29 21:55:57 +0100] [recorder:537f2ab57a616e33b903a900:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-29 21:55:57 +0100] [recorder:537b68987a616e64da431e00:proxy] check:rtsp task was terminated ["/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:32:in `terminate'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `block in cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `each'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:404:in `cleanup'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:375:in `shutdown'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:185:in `run'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:157:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `block in initialize'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'", "/home/deployer/xanagent/shared/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `block in create'"]
[2014-05-30 11:12:28 +0100] [recorder:537b68987a616e64da431e00] send_command: monitor
[2014-05-30 11:12:28 +0100] [recorder:537b68987a616e64da431e00] schedule :monitor (reason: monitor by user)

@kostya
Copy link
Owner

kostya commented May 30, 2014

Something strange, looks like celluloid bug.
How long can executing check_with_ffmpeg, is it possible that it timeouted for big time?
or @rtsp_client.describe

@tetherit
Copy link
Author

with ffmpeg there's -stimeout 5000000 - so it should timeout within 5 seconds. With @rtsp_client.describe - I'm not 100%, but if I try to access an IP that doesn't respond, it times out within a couple of seconds.

The entire log file is 3GB, heh - I will email you the config and a fair chunk before the freeze.

@kostya
Copy link
Owner

kostya commented May 30, 2014

send last day of log, or something

@tetherit
Copy link
Author

Sent, looks like the system rebooted but still not sure why eye didn't start correctly and stopped responding shortly after starting.

@kostya
Copy link
Owner

kostya commented May 31, 2014

After this error happen, process eye is running or not?
ps aux | grep eye

In log, looks like someone just kills eye. (send term signal or something)

Can you find eye self-pid in log? Which starts with "starting Eye ...
", in your logs i not find this. Then if you find eye pid, try to find
this pid in eye log (may be eye kills itself somehow).

What ruby are you using?

2014-05-30 17:02 GMT+04:00 xanview notifications@github.com:

Sent, looks like the system rebooted but still not sure why eye didn't
start correctly and stopped responding shortly after starting.


Reply to this email directly or view it on GitHub
#62 (comment).

@tetherit
Copy link
Author

I'm using ruby 2.1.1p76 (2014-02-24 revision 45161)

It seems weird anything would try to kill eye since nobody was connected to the server when it happened. I will try to reproduce by rebooting the server until it happens again and report back.

@kostya
Copy link
Owner

kostya commented May 31, 2014

i add to master log signals, maybe this is helps c5e97bf

@kostya
Copy link
Owner

kostya commented May 31, 2014

Also enable Eye.config{ logger_level Logger::DEBUG }

@tetherit
Copy link
Author

tetherit commented Jul 8, 2014

I had this happen again recently and ps aux | grep eye doesn't show eye running at all and nothing in the logs to help identify what happened. This time on a server with an uptime of 80 days and it happened 15 days ago so limited log availability (didn't notice this because the processes were still running) :(

I will update eye on all the servers to the latest version today and report if/as soon as it re-occurs!

@kostya
Copy link
Owner

kostya commented Jul 8, 2014

i think this is related to #67, when eye load pid from pid_file of one of eye-self threads (lwp), and then kill itself, in 0.6.2 i try to fix it.

@kostya
Copy link
Owner

kostya commented Jul 8, 2014

try 0.6.2.pre i think this should be fixed.

@tetherit
Copy link
Author

Pushing to all servers, will re-open if this happens again!

@kostya
Copy link
Owner

kostya commented Jul 29, 2014

i reproduce it, this is a crazy case, when process die, and in 5s there is up new process with the same pid (eye lwp), so eye even not seen that process die, and monitor that wrong new process (self lwp), and then kill itself. Need to check pid + identity(name or start_time) for that pid. I think i fix it in 0.7.
This is all happens, because ruby threads produces system threads, so eye with 100 processes can produce ~300 system threads, and if someone or eye itself, send kill to any thread, eye would die.

@kostya kostya changed the title check:rtsp task was terminated Eye kills itself Jul 29, 2014
@kostya kostya reopened this Jul 29, 2014
@kostya kostya added this to the 0.7 milestone Jul 29, 2014
@tetherit
Copy link
Author

Fantastic :) - I like the idea of checking both the PID and the start time - and possibly the name too, I mean why not, will make sure there is no chance that the wrong PID is being monitored/controller. Looking forward to 0.7, great work!

@kostya kostya added the bug label Jan 18, 2015
@tetherit
Copy link
Author

Hey :) - I had that happen again :( - in fact it happens from time to time (with the latest version), but this time a client complained :(

[2015-01-30 14:07:49 +0000] [recorder:52121f8ac5399f1bc100dc10:recorder] process_really_running?: <9615> {:result=>1}
[2015-01-30 14:07:49 +0000] [recorder:52121f8ac5399f1bc100dc10:recorder] process <9615> did not die after TERM, sending KILL

Boom, no more eye :( - happened after an unclean reboot, so I'm guessing eye assumed it is still running and was looking for processes based on PID only :(

Any update on this?

@kostya
Copy link
Owner

kostya commented Jan 31, 2015

there is commit for this ea964b6, but it makes eye 2 more times using cpu, need to decrease it.

@tetherit
Copy link
Author

Thank you for working on this :)

@kostya kostya modified the milestones: 0.8, 0.7 Sep 16, 2015
@kostya kostya closed this as completed in 9900fe9 Oct 1, 2015
@kostya
Copy link
Owner

kostya commented Nov 22, 2015

this should be fully fixed in 0.8

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant