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.

Sign up for GitHub

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

Jump to bottom

New Relic agent keep spawning processes #344

Open
hanxue opened this issue Apr 7, 2015 · 2 comments
Open

New Relic agent keep spawning processes #344

hanxue opened this issue Apr 7, 2015 · 2 comments

Comments

@hanxue
Copy link

hanxue commented Apr 7, 2015

I am running Helpful on a local vagrant box, following instructions from README.md. I notice the vagrant box taking up 100% CPU, and on further investigation, a ruby process uses up most of the CPU. The process ID also keep changing.

This is from the newrelic_agent.log

[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Starting the New Relic agent in "development" environment.
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : To prevent agent startup add a NEWRELIC_AGENT_ENABLED=false environment variable or modify the "development" section of your newrelic.yml.
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Reading configuration from config/newrelic.yml (/vagrant)
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : New Relic Agent Developer Mode enabled.
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Environment: development
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Dispatcher: sidekiq
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Application: hanxue-helpful
[04/06/15 12:43:37 +0200 heroku (7883)] WARN : Agent configured not to send data in this environment.
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Curb instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing deferred Rack instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Rack::Builder middleware instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Rails 3+ middleware instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing ActiveRecord 4 instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing ActiveJob instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Net instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Sidekiq instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Rails 4 Error instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Rails 4 Controller instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Installing Rails 4 view instrumentation
[04/06/15 12:43:37 +0200 heroku (7883)] INFO : Finished instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Starting the New Relic agent in "development" environment.
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : To prevent agent startup add a NEWRELIC_AGENT_ENABLED=false environment variable or modify the "development" section of your newrelic.yml.
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Reading configuration from config/newrelic.yml (/vagrant)
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : New Relic Agent Developer Mode enabled.
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Environment: development
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Dispatcher: sidekiq
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Application: hanxue-helpful
[04/06/15 12:43:42 +0200 heroku (7894)] WARN : Agent configured not to send data in this environment.
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Curb instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing deferred Rack instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Rack::Builder middleware instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Rails 3+ middleware instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing ActiveRecord 4 instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing ActiveJob instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Net instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Sidekiq instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Rails 4 Error instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Rails 4 Controller instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Installing Rails 4 view instrumentation
[04/06/15 12:43:42 +0200 heroku (7894)] INFO : Finished instrumentation

Notice when the same set of messages repeat, there's a different pid for heroku. I have temporarily disabled the new relic agent. Is there any way to prevent the ruby/heroku processes from getting created all the time?
hanxue added a commit to hanxue/helpful-web that referenced this issue Apr 9, 2015
@hanxue
Bugfix: Update doorkeeper to use before_action
07d6e6d 
Details of bug at asm-helpful#344

The existing code uses    `doorkeeper_for :all, except: [ :create ]`

This will cause the following error

```
 [1563] - Worker 0 (pid: 1571) booted, phase: 0
12:53:24 worker.1 | `doorkeeper_for` no longer available
12:53:24 worker.1 |
12:53:24 worker.1 | Starting in version 2.0.0 of doorkeeper gem, `doorkeeper_for` is no longer
12:53:24 worker.1 | available. Please change `doorkeeper_for` calls in your application with:
12:53:24 worker.1 |
12:53:24 worker.1 |   before_action :doorkeeper_authorize!
12:53:24 worker.1 |
12:53:24 worker.1 | For more information check the README:
12:53:24 worker.1 | https://github.com/doorkeeper-gem/doorkeeper#protecting-resources-with-oauth-aka-your-api-endpoint
12:53:24 worker.1 |
12:53:24 worker.1 | exited with code 1
```

Further details here
https://github.com/doorkeeper-gem/doorkeeper#protecting-resources-with-oauth-aka-your-api-endpoint
This was referenced Apr 9, 2015
Open
Open
@hanxue
Copy link
Author

hanxue commented Apr 10, 2015

I will keep this issue open. Convenient to post log output, as well as linked to pull requests and commits that will eventually solve the problem.

Once I have gotten over the hurdle of doorkeeper in #344 , I see these errors in the worker log

$ tail -f /var/log/helpful.log/worker-1.log 
TID-otrbh4zsk ERROR: Error fetching message: Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/sidekiq-3.3.3/lib/sidekiq.rb:74:in `redis'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/sidekiq-3.3.3/lib/sidekiq/fetch.rb:102:in `retrieve_work'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/sidekiq-3.3.3/lib/sidekiq/fetch.rb:37:in `block in fetch'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/sidekiq-3.3.3/lib/sidekiq/util.rb:16:in `watchdog'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/sidekiq-3.3.3/lib/sidekiq/fetch.rb:33:in `fetch'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/sidekiq-3.3.3/lib/sidekiq/fetch.rb:44:in `block (2 levels) in fetch'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
TID-otrbh4zsk ERROR: /opt/ruby/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
TID-otrcakmug INFO: Terminating 5 quiet workers

Redis is up and running in the Vagrant box though

@hanxue
Copy link
Author

hanxue commented Apr 10, 2015

Found out the cause: doorkeeper authorization code does not work for version 2.0 and above. This pull request should resolve it:

hanxue@07d6e6d

Once I applied the changes, and re-provision the Vagrant box, Helpful is running properly again.

A more readable version of this issue is documented at http://flummox-engineering.blogspot.com/2015/04/doorkeeper-causing-high-cpu-in-rails-app.html

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@hanxue