Can the origin of "SystemStackError: stack level too deep" be identified without a full stack trace?

Question

I am running Spree 0-60-stable on Rails 3.0.9 on Heroku Bamboo MRI (Ruby) 1.9.2

Some time on or about Sat, 03 Dec 2011, I began receiving "SystemStackError (stack level too deep)" messages in controllers that did not throw that error before. I had not recompiled the slug since the 28th November. I first tried restarting my web processes, to no avail. I have since made a nominal change (a line of whitespace in my Gemfile) so I could get a slug recompile and pushed that up. No change. I'm still getting the error. I went to look at available stacks I might migrate to, but none others besides the one I'm on bamboo-mri-1.9.2 explicitly support the version of ruby my app is using.

The error (according to Heroku support) is:

ActionView::Template::Error (stack level too deep)

They went on to say, "This implies that you have something within your template which is making a likely-recursive call. While a lack of a code change might indicate some weird behavior on our end, it's also possible that something changed in your database or something was time-based that caused a change in behavior. In either case, a full stack trace would be helpful. Are you using Airbrake or Exceptional to be able to capture this error and determine the source?"

I have since added both Airbrake (Hoptoad) and Exceptional to check what they might show in terms of stack trace. Both provide the same file/line reference, but no further information:

.bundle/gems/ruby/1.9.1/gems/actionpack-3.0.9/lib/action_controller/metal/rescue.rb:19

This doesn't seem very helpful because it's the rescue itself rather than whatever line of code actually triggered it, about which I have only the outermost context. I'm seeing the same error in several places:

• admin/shipments#edit
  • http://www.example.com/admin/orders/R123456789/shipments/H12345678909/edit
  • .bundle/gems/ruby/1.9.1/gems/actionpack-3.0.9/lib/action_controller/metal/rescue.rb:19
• checkout#edit
  • http://www.example.com/checkout/delivery
  • .bundle/gems/ruby/1.9.1/gems/arel-2.0.10/lib/arel/table.rb:44
• checkout#edit
  • http://www.example.com/checkout/delivery
  • .bundle/gems/ruby/1.9.1/gems/arel-2.0.10/lib/arel/visitors/to_sql.rb:305
• checkout#update
  • http://www.example.com/checkout/update/address
  • .bundle/gems/ruby/1.9.1/gems/actionpack-3.0.9/lib/action_controller/metal/rescue.rb:19

So here's my issue in summary:

1. I didn't change my code and the problem appeared 'out of nowhere'.
2. If it was a data change, for example a setting in the admin, which was it?
3. Troubleshooting is rendered difficult by the lack of a full stack trace.

And finally, my question:

Can the origin of "SystemStackError: stack level too deep" be identified without a full stack trace?

Many thanks in advance for any assistance.

Pisciform

Answer 1

In this situation, I;d use "printf debugging". Add log.info "got to here 1" (2, 3 ,4 etc) in various points in your controller and template code.

Then reproduce the error. Then check the logs and see which statements did/didn't get logged - and therefore which part of the code you didn't get to and if any parts repeated endlessly...

and you've at least narrowed down to which part of the code is the problem.

Nolin

Thanks Taryn. I'm going to try this. – Pisciform

I added the line: logger.debug "---------------------------- in CheckoutController" And other similar lines to the checkout controller. But, I'm not seeing any of it it the logs. heroku config Gives me: LOG_LEVEL => DEBUG – Pisciform

If that's the very first line in your controller code (ie there's no authorisation stuff getting called first) then then the problem may be in gem/plugin loading... and that's more black magic than I can help you with from here. – Nolin

It turned out it was a circular definition in one of the models. Spree allows a zone to be defined by other zones and one of the admins had defined a zone using itself, which should be disallowed but isn't. Still...I never did see any of my debug output. Very odd. – Pisciform

Answer 2

SystemStackError is normally caused by some recursive method calling itself directly or indirectly. This is either caused by an error which creates infinite recursion or some operation which takes place recursively and therefore only works for a limited size of data.

Example

class Array
  def size
    return 0 if self.empty?
    1+self[1..-1].size
  end
end

This is theoreticly a correct implementation of size, but its stack size grows linear to the arrays size. On my system this implemantation fails with SystemStackError for Arrays bigger than 8714.

Write puts into your code

If you have a suspision which methods could cause this put a puts into the method to generate some debug output. If you see a lot of output from a certain method you can assume the error is somewhere near thas method.

Trace all methods

Use rubys buildin hooks to trace all method creations. Then automaticly modify each newly created method to generate some debug output. Your code will run realy slow with all this debug informations, but you might see in your trace the cause of your recursion.

Zellner

Thanks Johannes. I'm not sure puts would work since this is a production app on Heroku. The same error is not occurring in my local development environment. Your suggestion is a +1 for 'debug, debug, debug'. So that's the direction I'll head with this, using the built-in logger facility. Again, many thanks. – Pisciform