Unicorn on Heroku is throwing weird bugs that cause H13 server errors. What is killing my unicorns?

I have a Rails 4 application running on Heroku that suddenly started throwing a lot of H13 errors. I followed it through the logs and saw many errors with a unicorn complaining about memoized object is not a string

. The processes are then handled by SIGIOT. Here's the exact error:

unicorn_http.rl:295: write_value: Assertion `rb_type((VALUE)(f)) == RUBY_T_STRING && "memoized object is not a string"' failed.

      

Errors can also look like this:

unicorn_http.rl:296: write_value: Assertion `(!!((!(((VALUE)(f) & RUBY_IMMEDIATE_MASK) || !!(((VALUE)(f) & ~((VALUE)RUBY_Qnil)) == 0)) && (int)(((struct RBasic*)(f))->flags & RUBY_T_MASK) != RUBY_T_NODE)?(((struct RBasic*)(f))->flags&((((VALUE)1)<<11))):((((int)(long)(f))&RUBY_FIXNUM_FLAG)||((((int)(long)(f))&RUBY_FLONUM_MASK) == RUBY_FLONUM_FLAG)))) && "unfrozen object"' failed. 

      

This is happening on different paths and I can't figure out what's going on. I ran the unicorn config with a big headroom:

worker_processes Integer(ENV["WEB_CONCURRENCY"] || 2)
timeout 29
preload_app true

before_fork do |server, worker|
  Signal.trap 'TERM' do
    puts 'Unicorn master intercepting TERM and sending myself QUIT instead'
    Process.kill 'QUIT', Process.pid
  end

  defined?(ActiveRecord::Base) and
    ActiveRecord::Base.connection.disconnect!
end

after_fork do |server, worker|
  Signal.trap 'TERM' do
    puts 'Unicorn worker intercepting TERM and doing nothing. Wait for master to send QUIT'
  end

  defined?(ActiveRecord::Base) and
    ActiveRecord::Base.establish_connection
end

      

And here is a snippet of Heroku logs with error:

Sep 15 15:38:42 #{app} heroku/router:  at=error code=H13 desc="Connection closed without response" method=GET path="#{path}" host=host.org request_id=6af16b9e-02ff-494e-8c8c-11f060f3b8fe fwd="109.63.24.000" dyno=web.1 connect=1ms service=15ms status=503 bytes=1187 
Sep 15 15:38:42 #{app} app/web.1:  unicorn worker[1] -p 4635 -c ./config/unicorn.rb: unicorn_http.rl:295: write_value: Assertion `rb_type((VALUE)(f)) == RUBY_T_STRING && "memoized object is not a string"' failed. 
Sep 15 15:38:42 #{app} app/web.1:  I, [2014-09-15T22:38:41.878914 #675]  INFO -- : worker=1 ready 
Sep 15 15:38:42 #{app} app/web.1:  E, [2014-09-15T22:38:41.835934 #2] ERROR -- : reaped #<Process::Status: pid 672 SIGIOT (signal 6)> worker=1 

...

Sep 15 15:26:52 #{app} app/web.1:  unicorn worker[0] -p 4635 -c ./config/unicorn.rb: unicorn_http.rl:295: write_value: Assertion `rb_type((VALUE)(f)) == RUBY_T_STRING && "memoized object is not a string"' failed. 
Sep 15 15:26:52 #{app} app/web.1:  E, [2014-09-15T22:26:52.483577 #2] ERROR -- : reaped #<Process::Status: pid 487 SIGIOT (signal 6)> worker=0 
Sep 15 15:26:52 #{app} heroku/router:  at=error code=H13 desc="Connection closed without response" method=GET path="#{path}" host=host.org request_id=92fbf67f-56b1-4144-917a-c3d29171f631 fwd="76.234.45.000" dyno=web.1 connect=4ms service=18ms status=503 bytes=1208 

      

A typical request queue is usually <10ms in this app and it seems to have just started recently, but I haven't changed the age unicorn setting. The app is a Heroku app with Rails 4.1.1 with Ruby 2.0.0 in Unicorn 4.8.2. It uses memecache with dalli for minimal caching. Requests don't work with error H13, so I don't find the 29th timeout set in the unicorn.rb config.

+3


source to share





All Articles