Strange Thread related errors

Strange Thread related errors

[Michael Guterl]

Our Rails app has started raising exceptions (caught by hoptoad
thankfully) and I can only imagine they're related to unicorn.  I only
*think* the errors are occurring on the request after we deploy, which
upgrades the Unicorn process.  I say this because the errors are
coming from many different actions, but I haven't been able to
reproduce.

After the most recent batch of errors, I upgraded from 0.95.1 to
0.95.3, but we have not deployed again.

ThreadError: stopping only thread note: use sleep to stop forever

/usr/local/lib/ruby/1.8/monitor.rb:285:in `stop'

/usr/local/lib/ruby/1.8/monitor.rb:285:in `mon_acquire'

/usr/local/lib/ruby/1.8/monitor.rb:214:in `mon_enter'

/usr/local/lib/ruby/1.8/monitor.rb:240:in `synchronize'

/usr/local/lib/ruby/1.8/logger.rb:496:in `write'

/usr/local/lib/ruby/1.8/logger.rb:326:in `add'

/usr/local/lib/ruby/1.8/logger.rb:374:in `info'

/home/deploy/public_html/rm/releases/20100107153636/vendor/plugins/newrelic_rpm/lib/new_relic/agent/agent.rb:46:in
`ensure_worker_thread_started'

/home/deploy/public_html/rm/releases/20100107153636/vendor/plugins/newrelic_rpm/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:248:in
`perform_action'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/base.rb:532:in
`send'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/base.rb:532:in
`process_without_filters'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/filters.rb:606:in
`process'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/base.rb:391:in
`process'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/base.rb:386:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/routing/route_set.rb:437:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:87:in
`dispatch'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:121:in
`_call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:130:in
`build_middleware_stack'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activerecord/lib/active_record/query_cache.rb:29:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activerecord/lib/active_record/query_cache.rb:29:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb:34:in
`cache'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activerecord/lib/active_record/query_cache.rb:9:in
`cache'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activerecord/lib/active_record/query_cache.rb:28:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:361:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/string_coercion.rb:25:in
`call'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/head.rb:9:in `call'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/methodoverride.rb:24:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/params_parser.rb:15:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/session/cookie_store.rb:93:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/activesupport/lib/active_support/cache/strategy/local_cache.rb:24:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/failsafe.rb:26:in
`call'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/lock.rb:11:in `call'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/lock.rb:11:in
`synchronize'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/lock.rb:11:in `call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:106:in
`call'

/home/deploy/public_html/rm/releases/20100107153636/vendor/rails/railties/lib/rails/rack/static.rb:31:in
`call'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/urlmap.rb:46:in `call'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/urlmap.rb:40:in `each'

/usr/local/lib/ruby/gems/1.8/gems/rack-1.0.1/lib/rack/urlmap.rb:40:in `call'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:571:in
`process_client'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:643:in
`worker_loop'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:641:in `each'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:641:in
`worker_loop'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:534:in
`spawn_missing_workers'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:534:in `fork'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:534:in
`spawn_missing_workers'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:530:in `each'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:530:in
`spawn_missing_workers'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:540:in
`maintain_worker_count'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:215:in `start'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/lib/unicorn.rb:28:in `run'

/usr/local/lib/ruby/gems/1.8/gems/unicorn-0.95.1/bin/unicorn_rails:207

/usr/local/bin/unicorn_rails:19:in `load'

/usr/local/bin/unicorn_rails:19
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Iñaki Baz Castillo]

El Jueves, 7 de Enero de 2010, Michael Guterl escribió:
> Our Rails app has started raising exceptions (caught by hoptoad
> thankfully) and I can only imagine they're related to unicorn.  I only
> think the errors are occurring on the request after we deploy, which
> upgrades the Unicorn process.  I say this because the errors are
> coming from many different actions, but I haven't been able to
> reproduce.

Let me explain a problem I had with Sequel and Unicorn (already solved), 
perhaps it's related:


I load Sequel database toolkit in the master process so it generates its own 
threads pool.
Then Unicorn forks into workers but each worker uses the same instance of 
Sequel database, this is, the same threads pool.

This causes errors since some thread could be used by different processes at 
the same time.

The solution is simple:

Don't set the Sequel instance in the master process, instead do it in each 
worker ("after_fork" block in unicorn config file).

In this way each process has its own Sequel instance with its own threads 
pool.

Also, using Sequel thread pool makes no sense when using Unicorn as each 
worker is single thread, so I gain some performance by setting 
"single_threaded = true" in Sequel database configuration (no thread pool 
stuff).

Probably you are getting a similar issue due to ActiveRecord or any other 
multithread library you load in the master process so the instance is shared 
between all the workers.
 


-- 
Iñaki Baz Castillo <ibc@aliax.net>
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Jeremy Evans]

On Thu, Jan 7, 2010 at 8:31 AM, Iñaki Baz Castillo <ibc@aliax.net> wrote:
> Don't set the Sequel instance in the master process, instead do it in each
> worker ("after_fork" block in unicorn config file).

Alternatively, you can set up the Sequel Database in the master
process, and just call Database#disconnect before forking.

> In this way each process has its own Sequel instance with its own threads
> pool.
>
> Also, using Sequel thread pool makes no sense when using Unicorn as each
> worker is single thread, so I gain some performance by setting
> "single_threaded = true" in Sequel database configuration (no thread pool
> stuff).

This is good advice.

Jeremy
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Iñaki Baz Castillo]

El Jueves, 7 de Enero de 2010, Jeremy Evans escribió:
> > Don't set the Sequel instance in the master process, instead do it in
> > each worker ("after_fork" block in unicorn config file).
> 
> Alternatively, you can set up the Sequel Database in the master
> process, and just call Database#disconnect before forking.

Yes, in fact I do that to check the database connection when starting Unicorn 
and raise if some database fails.
Then I disconnect the databases and reconnect in each worker. 


-- 
Iñaki Baz Castillo <ibc@aliax.net>
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Michael Guterl]

On Thu, Jan 7, 2010 at 11:31 AM, Iñaki Baz Castillo <ibc@aliax.net> wrote:
> El Jueves, 7 de Enero de 2010, Michael Guterl escribió:
>> Our Rails app has started raising exceptions (caught by hoptoad
>> thankfully) and I can only imagine they're related to unicorn.  I only
>> think the errors are occurring on the request after we deploy, which
>> upgrades the Unicorn process.  I say this because the errors are
>> coming from many different actions, but I haven't been able to
>> reproduce.
>
> Let me explain a problem I had with Sequel and Unicorn (already solved),
> perhaps it's related:
>
>
> I load Sequel database toolkit in the master process so it generates its own
> threads pool.
> Then Unicorn forks into workers but each worker uses the same instance of
> Sequel database, this is, the same threads pool.
>
> This causes errors since some thread could be used by different processes at
> the same time.
>
> The solution is simple:
>
> Don't set the Sequel instance in the master process, instead do it in each
> worker ("after_fork" block in unicorn config file).
>
> In this way each process has its own Sequel instance with its own threads
> pool.
>
> Also, using Sequel thread pool makes no sense when using Unicorn as each
> worker is single thread, so I gain some performance by setting
> "single_threaded = true" in Sequel database configuration (no thread pool
> stuff).
>
> Probably you are getting a similar issue due to ActiveRecord or any other
> multithread library you load in the master process so the instance is shared
> between all the workers.
>

We currently disconnect from both databases in before_fork and
re-establish the connection in after_fork.

Here's our unicorn config: http://gist.github.com/271449

Maybe I should disable connection pooling?

Best regards,
Michael Guterl
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Iñaki Baz Castillo]

El Jueves, 7 de Enero de 2010, Michael Guterl escribió:
> We currently disconnect from both databases in before_fork and
> re-establish the connection in after_fork.
> 
> Here's our unicorn config: http://gist.github.com/271449

Unfortunately I don't know very well ho ActiveRecords works but you could get 
into the same probem even if you disconnect the db in the case you are sharing 
the same ActiveRecord instance in all the workers.
This issue also ocurred to me using Sequel: I generated the DB instances in 
master process and stored them in an Array that later used in each worker so 
the fact is that I was sharing the same DB object in all the workers, so when 
they reconcet they are in fact using a single connection (or a single 
connection pool) for all the workers.

But I think that ActiveRecords works in a different way as you don't create a 
DB instance but instead use directly a class ("class MyModel < 
ActiveRecords").

 
> Maybe I should disable connection pooling?
 
This should not be the real cause of your problem (if the above is not 
happening to you). Unicorn workers are single thread which means you can use 
threads into them safely (except if those threads are, accidentally, shared by 
other processes).

I suggest the following: Tun the server and ensure you do enough requests so 
all the worker perform at least a DB query. And them check the current DB 
connection in your DB. If you dissable coonectino pooling you should see just 
N connections /being N the number of Unicorn workers).

-- 
Iñaki Baz Castillo <ibc@aliax.net>
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Jeremy Evans]

On Thu, Jan 7, 2010 at 10:49 AM, Michael Guterl <mguterl@gmail.com> wrote:
> We currently disconnect from both databases in before_fork and
> re-establish the connection in after_fork.
>
> Here's our unicorn config: http://gist.github.com/271449
>
> Maybe I should disable connection pooling?

Try:

  ActiveRecord::Base.clear_active_connections!

instead of:

  ActiveRecord::Base.connection.disconnect!

Jeremy
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Eric Wong]

Michael Guterl <mguterl@gmail.com> wrote:
> Our Rails app has started raising exceptions (caught by hoptoad
> thankfully) and I can only imagine they're related to unicorn.  I only
> *think* the errors are occurring on the request after we deploy, which
> upgrades the Unicorn process.  I say this because the errors are
> coming from many different actions, but I haven't been able to
> reproduce.
> 
> After the most recent batch of errors, I upgraded from 0.95.1 to
> 0.95.3, but we have not deployed again.
> 
> ThreadError: stopping only thread note: use sleep to stop forever
> 
> /usr/local/lib/ruby/1.8/monitor.rb:285:in `stop'
> 
> /usr/local/lib/ruby/1.8/monitor.rb:285:in `mon_acquire'
> 
> /usr/local/lib/ruby/1.8/monitor.rb:214:in `mon_enter'
> 
> /usr/local/lib/ruby/1.8/monitor.rb:240:in `synchronize'
> 
> /usr/local/lib/ruby/1.8/logger.rb:496:in `write'
> 
> /usr/local/lib/ruby/1.8/logger.rb:326:in `add'
> 
> /usr/local/lib/ruby/1.8/logger.rb:374:in `info'
> 
> /home/deploy/public_html/rm/releases/20100107153636/vendor/plugins/newrelic_rpm/lib/new_relic/agent/agent.rb:46:in
> `ensure_worker_thread_started'

Hi Michael,

It looks like there's a background thread with the NewRelic plugin...

With "preload_app true", then any threads spawned in the master will die
in workers.  This is true for Ruby 1.8 green threads by design.  With
1.9, it's not even to share native POSIX threads between processes.

So in your after_fork hook, you need to restart threads inside
each worker.

-- 
Eric Wong
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying

Re: Strange Thread related errors

[Michael Guterl]

On Thu, Jan 7, 2010 at 3:13 PM, Eric Wong <normalperson@yhbt.net> wrote:
> Michael Guterl <mguterl@gmail.com> wrote:
>> Our Rails app has started raising exceptions (caught by hoptoad
>> thankfully) and I can only imagine they're related to unicorn.  I only
>> *think* the errors are occurring on the request after we deploy, which
>> upgrades the Unicorn process.  I say this because the errors are
>> coming from many different actions, but I haven't been able to
>> reproduce.
>>
>> After the most recent batch of errors, I upgraded from 0.95.1 to
>> 0.95.3, but we have not deployed again.
>>
>> ThreadError: stopping only thread note: use sleep to stop forever
>>
>> /usr/local/lib/ruby/1.8/monitor.rb:285:in `stop'
>>
>> /usr/local/lib/ruby/1.8/monitor.rb:285:in `mon_acquire'
>>
>> /usr/local/lib/ruby/1.8/monitor.rb:214:in `mon_enter'
>>
>> /usr/local/lib/ruby/1.8/monitor.rb:240:in `synchronize'
>>
>> /usr/local/lib/ruby/1.8/logger.rb:496:in `write'
>>
>> /usr/local/lib/ruby/1.8/logger.rb:326:in `add'
>>
>> /usr/local/lib/ruby/1.8/logger.rb:374:in `info'
>>
>> /home/deploy/public_html/rm/releases/20100107153636/vendor/plugins/newrelic_rpm/lib/new_relic/agent/agent.rb:46:in
>> `ensure_worker_thread_started'
>
> Hi Michael,
>
> It looks like there's a background thread with the NewRelic plugin...
>
> With "preload_app true", then any threads spawned in the master will die
> in workers.  This is true for Ruby 1.8 green threads by design.  With
> 1.9, it's not even to share native POSIX threads between processes.
>
> So in your after_fork hook, you need to restart threads inside
> each worker.

Thanks for this Eric, much appreciated.  It turns out that New Relic
doesn't officially support Unicorn yet, but I upgraded their plugin
and I have deployed a few times and haven't seen anything since.

Michael Guterl
_______________________________________________
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying