Foreman starts using 100% of the CPU in an eternal loop consuming nil data from the process output #260

Closed
mauricio opened this Issue Sep 10, 2012 · 12 comments

9 participants

@mauricio

I'm running foreman at the following environment:

  • Mac OS lion
  • terminal + oh-my-zsh
  • ruby 1.9.3

When running a bunch of processes (in this case, MySQL, ElasticSearch and a Rails app) foreman goes up to consume 100% of the CPU in an eternal loop trying to grab the output of the running processes. After a bit of profiling I have found out the source of the issue, the watch_for_output loop at the Foreman::Engine class. In my machine, it was eternally consuming nil's from the process and kept on running on it forever.

I ended up changing it to sleep a bit if none of the processes produced any kind of output, but I'm not sure if this is the correct solution.

Maybe having a separate thread for each process would be better or trying to find a way to grab this output in an async way instead of being synchronous.

Here's my change (it isn't a pull request because i'm not sure if this is the correct solution, but it works on my machine now and foreman isn't at 100% of CPU anymore):

  def watch_for_output
    Thread.new do
      begin
        loop do
          wrote_data = false
          (IO.select(@readers.values).first || []).each do |reader|
            data = reader.gets
            wrote_data = !data.nil?
            output_with_mutex name_for(@readers.invert[reader]), data
          end
          sleep(1) unless wrote_data
        end
      rescue Exception => ex
        puts ex.message
        puts ex.backtrace
      end
    end
  end
@leehambley

+1, same problem here, Procfile is:

web: puma -p $PORT
mongo: mongod run --config config/mongod.conf
elasticsearch: elasticsearch -f -Des.config=config/elasticsearch.ym
@mauricio

Any comments @ddollar ? Is this the right solution? Should I create a pull request for this?

@pex
pex commented Oct 8, 2012

+1 - any news?

@silviorelli

+1
My procfile:

redis:  bundle exec redis-server config/redis.conf
resque: bundle exec rake resque:work QUEUE=*
web:    bundle exec rails s
solr:   bundle exec rake sunspot:solr:run
mongo:  bundle exec mongod run --config /usr/local/etc/mongod.conf
@silviorelli

Pull request with patch by @mauricio #272
Seems to work for me

@silviorelli

Timeout set instead of sleep, as @ddollar suggested

@ddollar ddollar closed this in 9da4e38 Oct 8, 2012
@silviorelli silviorelli added a commit to silviorelli/foreman that referenced this issue Oct 8, 2012
@silviorelli silviorelli Fix for nil value on io select loop, fixes #260 f7b7029
@silviorelli

I was getting errors for calling first on nil when timeout occurred:

undefined method `first' for nil:NilClass
/Users/silvio/temp1/foreman/lib/foreman/engine.rb:276:in `block (2 levels) in watch_for_output'
@silviorelli

Good, thanks.
Ciao!

@phoet

i still have issues with foreman going to 100% with version 0.60.2

changelog states, this should be fixed with https://github.com/ddollar/foreman/blob/master/Changelog.md#0601-2012-10-08

i did a stackdump and it looks like an immense amount of GC, but maybe that's normal for ruby... no idea...
https://gist.github.com/4169775

@erotte

…same here with ruby 1.9.3-p286

@nicolai86

same issue on ruby 1.9.3-p327, with latest version of foreman (0.60.2)

@fxposter fxposter added a commit to fxposter/foreman that referenced this issue Jan 7, 2013
@fxposter fxposter Fix #299 and #260
Some processes close their output channels and IO.select keeps
returning them as "readable", while IO#gets returns nil on them, thus
spending a lot of CPU looping through the same reader continuously
aceea14
@fxposter

Please, check out #303.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment