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

SystemStackError: stack level too deep upgrading v7.2.0 => v8.13.1 #1647

Closed
diclophis opened this issue Nov 21, 2022 · 12 comments
Closed

SystemStackError: stack level too deep upgrading v7.2.0 => v8.13.1 #1647

diclophis opened this issue Nov 21, 2022 · 12 comments
Labels
bug community To tag external issues and PRs submitted by the community P4-Bug Priority 4 Bug

Comments

@diclophis
Copy link

Description

During our test suite run, we are encountering an infinite loop leading to a ruby stack level too deep

Expected Behavior

The newrelic gem to not cause an infinite loop

Troubleshooting or NR Diag results

SystemStackError:
  stack level too deep
Shared Example Group: "a create action" called from ./private-controller_spec.rb:96

     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/guid_generator.rb:16:in `generate_guid'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/transaction/abstract_segment.rb:33:in `initialize'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/transaction/segment.rb:20:in `initialize'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:240:in `new'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:240:in `start_segment'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:27:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'

SystemStackError:
  stack level too deep
Shared Example Group: "a create action" called from ./private-controller_spec.rb:96

     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:242:in `rescue in start_segment'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:235:in `start_segment'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:27:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     #
     # repeats until stack depth error
     #
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:339:in `block (3 levels) in _nr_define_traced_method'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:74:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `block in trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/tracer.rb:355:in `capture_segment_error'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer_helpers.rb:41:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:72:in `trace_execution_scoped'
     # ./bundle/ruby/2.7.0/gems/newrelic_rpm-8.13.1/lib/new_relic/agent/method_tracer.rb:334:in `block (2 levels) in _nr_define_traced_method'
     # ./private-controller.rb:52:in `create'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/abstract_controller/base.rb:194:in `process_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal/rendering.rb:30:in `process_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:109:in `block in run_callbacks'
     # ./private-controller.rb:767:in `sensative_method_four'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
     # ./private-controller.rb:783:in `sensative_method_three'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
     # ./private-controller.rb:357:in `sensative_method_two'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
     # ./private-library.rb:22:in `sensative_method_one'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
     # ./private-controller.rb:830:in `sensative_before_filter'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
     # ./bundle/ruby/2.7.0/gems/hypernova-1.4.0/lib/hypernova/controller_helpers.rb:16:in `hypernova_render_support'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/callbacks.rb:136:in `run_callbacks'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/abstract_controller/callbacks.rb:41:in `process_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal/rescue.rb:22:in `process_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/notifications.rb:168:in `block in instrument'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
     # ./bundle/ruby/2.7.0/gems/activesupport-5.2.8/lib/active_support/notifications.rb:168:in `instrument'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
     # ./bundle/ruby/2.7.0/gems/activerecord-5.2.8/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/abstract_controller/base.rb:134:in `process'
     # ./bundle/ruby/2.7.0/gems/actionview-5.2.8/lib/action_view/rendering.rb:32:in `process'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/metal.rb:191:in `dispatch'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/test_case.rb:517:in `process'
     # ./bundle/ruby/2.7.0/gems/rails-controller-testing-1.0.5/lib/rails/controller/testing/template_assertions.rb:62:in `process'
     # ./bundle/ruby/2.7.0/gems/actionpack-5.2.8/lib/action_controller/test_case.rb:403:in `post'
     # ./bundle/ruby/2.7.0/gems/rails-controller-testing-1.0.5/lib/rails/controller/testing/integration.rb:16:in `block (2 levels) in <module:Integration>'
     # ./private-controller_spec.rb:71:in `do_request'
     # ./private-shared_behaviors.rb:127:in `block (4 levels) in <main>'
     # ./private-controller_spec.rb:84:in `success?'
     # ./private-shared_behaviors.rb:126:in `block (3 levels) in <main>'
     # ./bundle/ruby/2.7.0/gems/rspec-retry-0.6.1/lib/rspec/retry.rb:123:in `block in run'
     # ./bundle/ruby/2.7.0/gems/rspec-retry-0.6.1/lib/rspec/retry.rb:110:in `loop'
     # ./bundle/ruby/2.7.0/gems/rspec-retry-0.6.1/lib/rspec/retry.rb:110:in `run'
     # ./bundle/ruby/2.7.0/gems/rspec-retry-0.6.1/lib/rspec_ext/rspec_ext.rb:12:in `run_with_retry'
     # ./bundle/ruby/2.7.0/gems/rspec-retry-0.6.1/lib/rspec/retry.rb:37:in `block (2 levels) in setup'
     # ./bundle/ruby/2.7.0/gems/webmock-3.14.0/lib/webmock/rspec.rb:37:in `block (2 levels) in <main>'
~

Steps to Reproduce

We are able to reproduce this error consistently by using the upgraded gem in our test builds

Your Environment

ruby2.7 + rails5.2 + linux

Additional context

possibly related to:

#1590
#731

For Maintainers Only or Hero Triaging this bug

Suggested Priority (P1,P2,P3,P4,P5):
Suggested T-Shirt size (S, M, L, XL, Unknown):
@diclophis diclophis added the bug label Nov 21, 2022
@workato-integration
Copy link

https://issues.newrelic.com/browse/NEWRELIC-5476

@github-actions github-actions bot added the community To tag external issues and PRs submitted by the community label Nov 21, 2022
@kaylareopelle
Copy link
Contributor

Hi @diclophis! I'm sorry to hear you're encountering an error while trying to upgrade the agent. Thanks for sharing the stack trace.

It looks like the error is related to add_method_tracer calls. The 8.x release featured some breaking changes to this API.

Have you reviewed the 8.x migration guide section on add_method_tracer? Do these changes impact your application's add_method_tracer calls?

@diclophis
Copy link
Author

I have updated the integration with add_method_tracer to account for the guidelines listed in the 8.x migration guide... but the error persists...

@kaylareopelle
Copy link
Contributor

Thanks for trying out the 8.x migration guide!

In your newrelic.yml file, what are your settings for the test: environment? Is monitor_mode set to false?
Are you using any custom instrumentation for PrivateController#create?
If you try to access this controller action on a local development server, does the stack level too deep error also occur in that context?

@kaylareopelle
Copy link
Contributor

@diclophis, it would also be helpful if you could provide a gist or other code-based reproduction of the problem.

@kaylareopelle kaylareopelle added the P4-Bug Priority 4 Bug label Nov 28, 2022
@diclophis
Copy link
Author

@kaylareopelle we do not have any specific setting activated in our config/newrelic.yml related to monitor_mode ... so I reckon it is set to "default".... ?

We make use of NewRelic::Agent.add_custom_attributes in most of our controllers, however there only seems to be a problem with a specific controller in our test suite, we are still investigating to see if there is anything unique in that sense.

@diclophis
Copy link
Author

diclophis commented Nov 29, 2022 •
edited
Loading

We have determined that within the failing controller spec we call through a module implemented essentially as...

class ObfuscatedInstrumentedThing
  def self.obfuscated_method(arg_one, arg_two)
    # ... logic that loops an increments a counter 
    
    NewRelicHelper.log_stat("ObfuscatedInstrumentedThing/counter", counter)

    return result # returns the result
  end
  
  class << self
    include ::NewRelic::Agent::MethodTracer

    add_method_tracer :obfuscated_method, 'Custom/ObfuscatedInstrumentedThing/counter'
  end
end

The term "Obfuscated" is just placeholder for our actual class/method-names ...

@diclophis
Copy link
Author

I think the issue might be an interaction between rr / rspec and the newrelic ... in particular around mock(ObfuscatedInstrumentedThing).obfuscated_method ...

@fallwith
Copy link
Contributor

fallwith commented Dec 9, 2022

Hi @diclophis,

Your given "Expected Behavior" made me smile, and seems completely reasonable. 😄

Thank you for providing us with the obfuscated example code and pointer to the rr and rspec combination.

additional information we'd like to have

  • If possible, could you please also provide us with an example of what your rr based RSpec test looks like? If we had a better idea of what either rspec or rr is doing with the newrelic_rpm gem, we might be able to better narrow down what related code has changed between agent versions 7.2.0 and 8.13.1.
  • In a similar vein, would you please let us know what the NewRelicHelper is doing?
  • Is the tested controller method doing anything manual or custom with New Relic, or is it simply auto-instrumented?

one thing to try - revert individual files back to their v7.2.0 state

When I look at the v7.2.0 versions of tracer.rb, segment.rb, abstract_segment.rb and guid_generator.rb files that are all involved in your provided stack trace, the most significant v8.x agent alterations appear to have been made to guid_generator.rb with d5a8614. There's nothing that immediately jumps out at me that would explain a compatibility issue with rr, but you know rr better than I do and you might see something. You could also try manually reverting just that one guid_generator.rb file and keeping the rest of the newrelic_rpm code at v8.13.1 to see if it helps things. The same could be done for the other files listed in the stack trace.

another thing to try

One additional thing to try temporarily just to help narrow down when the issue was introduced would be to test with other newrelic_rpm versions between v7.2.0 and v8.13.1. Here is a list of the in-between versions. If an earlier v8.x version is known to introduce the problem you are seeing, that would help us narrow down a specific set of changes that have taken place since v7.2.0. I'd recommend testing with v8.0.0 and then going newer until the problem is reproduced. If v8.0.0 itself reproduces the issue, that would be good to know.

  • 8.13.0
  • 8.12.0
  • 8.11.0
  • 8.10.1
  • 8.10.0
  • 8.9.0
  • 8.8.0
  • 8.7.0
  • 8.6.0
  • 8.5.0
  • 8.4.0
  • 8.3.0
  • 8.2.0
  • 8.1.0
  • 8.0.0

Thanks very much for your patience on this one. A tremendous amount of work has gone into the agent between v7.2.0 and v8.13.1 in the hopes of delivering a better, richer experience for our users and we're sorry you're running into this issue.

@diclophis
Copy link
Author

@fallwith please give me a smidge more time, I should be able to make a repo dedicated to reproducing this error.

@fallwith
Copy link
Contributor

Hi @diclophis, just checking in. If you've determined any more information about this one or have anything additional you would like for us to try or look into, please let me know!

@fallwith
Copy link
Contributor

fallwith commented Feb 6, 2023

Hi @diclophis. We're going to close this one for now. As soon as you're ready for additional repro steps or debugging, we'll be happy to help!

@fallwith fallwith closed this as completed Feb 6, 2023
@kford-newrelic kford-newrelic moved this to Code Complete/Done in Ruby Engineering Board Jul 12, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug community To tag external issues and PRs submitted by the community P4-Bug Priority 4 Bug
Projects
Ruby Engineering Board
Archived in project
Milestone
No milestone
Development

No branches or pull requests
3 participants
@diclophis @fallwith @kaylareopelle