diff --git a/CHANGELOG.md b/CHANGELOG.md index 0ec15aaaa9..afa6240313 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,7 +1,12 @@ # New Relic Ruby Agent Release Notes ## dev - Version ___ fixes a bug preventing errors from being expected. + Version ___ fixes a bug causing the agent to continue storing data on finished transaction, and a bug preventing errors from being expected. + +- **Bugfix: Finished transactions continue to store data on different threads** + + Previously, when a new thread was spawned the agent would continue using the current transaction to record data on, even if this transaction had finished already in a different thread. Now the agent will only use the current transaction in the new thread if it is not yet finished. Thank you to [@fcheung](https://github.com/fcheung) for reporting this bug and providing us with an extremely helpful reproduction to debug. [PR#1969](https://github.com/newrelic/newrelic-ruby-agent/pull/1969) + - **Bugfix: Expected Errors passed to notice_error are expected again** diff --git a/lib/new_relic/agent/tracer.rb b/lib/new_relic/agent/tracer.rb index 4e1b0383e4..d1c1979519 100644 --- a/lib/new_relic/agent/tracer.rb +++ b/lib/new_relic/agent/tracer.rb @@ -424,7 +424,7 @@ def thread_block_with_current_transaction(*args, segment_name:, parent: nil, &bl current_txn = ::Thread.current[:newrelic_tracer_state]&.current_transaction if ::Thread.current[:newrelic_tracer_state]&.is_execution_traced? proc do begin - if current_txn + if current_txn && !current_txn.finished? NewRelic::Agent::Tracer.state.current_transaction = current_txn current_txn.async = true segment_name += "/Thread#{::Thread.current.object_id}/Fiber#{::Fiber.current.object_id}" if NewRelic::Agent.config[:'thread_ids_enabled'] diff --git a/lib/new_relic/agent/transaction.rb b/lib/new_relic/agent/transaction.rb index ec515c1a32..95b2b43296 100644 --- a/lib/new_relic/agent/transaction.rb +++ b/lib/new_relic/agent/transaction.rb @@ -439,6 +439,10 @@ def initial_segment segments.first end + def finished? + initial_segment.finished? + end + def create_initial_segment(options = {}) segment = create_segment(@default_name, options) segment.record_scoped_metric = false diff --git a/lib/new_relic/agent/transaction/tracing.rb b/lib/new_relic/agent/transaction/tracing.rb index 1ed62d462c..0a81f4f3e3 100644 --- a/lib/new_relic/agent/transaction/tracing.rb +++ b/lib/new_relic/agent/transaction/tracing.rb @@ -29,6 +29,12 @@ def add_segment(segment, parent = nil) else segment.record_on_finish = true ::NewRelic::Agent.logger.debug("Segment limit of #{segment_limit} reached, ceasing collection.") + + if finished? + ::NewRelic::Agent.logger.debug("Transaction #{best_name} has finished but segments still being created, resetting state.") + NewRelic::Agent::Tracer.state.reset + NewRelic::Agent.record_metric('Supportability/Transaction/SegmentLimitReachedAfterFinished/ResetState', 1) + end end segment.transaction_assigned end diff --git a/test/new_relic/agent/tracer_test.rb b/test/new_relic/agent/tracer_test.rb index b8b3321cac..510ef139de 100644 --- a/test/new_relic/agent/tracer_test.rb +++ b/test/new_relic/agent/tracer_test.rb @@ -301,6 +301,22 @@ def test_current_segment_without_transaction assert_nil Tracer.current_segment end + def test_traced_threads_dont_keep_using_finished_transaction + txn = Tracer.start_transaction(name: 'Controller/blogs/index', category: :controller) + threads = [] + threads << Thread.new do + segment = Tracer.start_segment(name: 'Custom/MyClass/myoperation') + sleep(0.01) until txn.finished? + + threads << Thread.new do + assert_nil Tracer.current_transaction + end + end + sleep(0.01) until txn.segments.size >= 2 + txn.finish + threads.each(&:join) + end + def test_current_segment_in_nested_threads_with_traced_thread assert_nil Tracer.current_segment diff --git a/test/new_relic/agent/transaction/tracing_test.rb b/test/new_relic/agent/transaction/tracing_test.rb index 182f3ab58f..0e71ae613c 100644 --- a/test/new_relic/agent/transaction/tracing_test.rb +++ b/test/new_relic/agent/transaction/tracing_test.rb @@ -447,6 +447,32 @@ def test_trace_should_log_segment_limit_reached_once end end + def test_trace_should_reset_state_if_segment_limit_reached_and_transaction_finished + with_config(:'transaction_tracer.limit_segments' => 3) do + txn = Tracer.start_transaction(name: 'Controller/blogs/index', category: :controller) + threads = [] + threads << Thread.new do + segment = Tracer.start_segment(name: 'Custom/MyClass/myoperation') + segment.finish + + assert NewRelic::Agent::Tracer.current_transaction + sleep(0.01) until txn.finished? + segment = Tracer.start_segment(name: 'Custom/MyClass/myoperation2') + segment.finish + segment = Tracer.start_segment(name: 'Custom/MyClass/myoperation3') + segment.finish + segment = Tracer.start_segment(name: 'Custom/MyClass/myoperation4') + segment.finish + + assert_metrics_recorded('Supportability/Transaction/SegmentLimitReachedAfterFinished/ResetState') + assert_nil Tracer.current_transaction + end + sleep(0.01) until txn.segments.size >= 2 + txn.finish + threads.each(&:join) + end + end + def test_threshold_recorded_for_trace with_config(:'transaction_tracer.transaction_threshold' => 2.0) do in_transaction {}