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.

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

Occasional "`close': can't be called from trap context (ThreadError)" error #1357

Open
slhck opened this issue Feb 7, 2023 · 3 comments
Open

Comments

@slhck
Copy link

slhck commented Feb 7, 2023

Describe the bug

I occasionally get the following error running Rspec tests in my Rails app, after upgrading to Ruby 3.1.3 and Rails 7.0.4.2:

/usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:66: warning: Exception in finalizer #<Proc:0x0000ffff7e434918 /usr/local/bundle/gems/elastic-apm-4.6.0/lib/elastic_apm/transport/connection/proxy_pipe.rb:55>
/usr/local/bundle/gems/elastic-apm-4.6.0/lib/elastic_apm/transport/connection/proxy_pipe.rb:55:in `close': can't be called from trap context (ThreadError)
        from /usr/local/bundle/gems/elastic-apm-4.6.0/lib/elastic_apm/transport/connection/proxy_pipe.rb:55:in `block in finalize'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:66:in `method_added'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:66:in `block in generate_method'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:65:in `module_eval'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:65:in `block in generate_method'
        from /usr/local/lib/ruby/3.1.0/mutex_m.rb:79:in `synchronize'
        from /usr/local/lib/ruby/3.1.0/mutex_m.rb:79:in `mu_synchronize'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:61:in `generate_method'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:39:in `generate_relation_method'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/delegation.rb:107:in `method_missing'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/finder_methods.rb:575:in `ordered_relation'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/finder_methods.rb:541:in `find_nth_with_limit'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/associations/collection_proxy.rb:1119:in `find_nth_with_limit'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/finder_methods.rb:534:in `find_nth'
        from /usr/local/bundle/gems/activerecord-7.0.4.2/lib/active_record/relation/finder_methods.rb:146:in `first'
        from /home/surfmeterserver/spec/support/authentication_helper.rb:16:in `export_api_key_params'
        from /home/surfmeterserver/spec/requests/export_api/v1/measurements_spec.rb:71:in `block (4 levels) in <main>'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:263:in `instance_exec'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:263:in `block in run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:511:in `block in with_around_and_singleton_context_hooks'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:468:in `block in with_around_example_hooks'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:486:in `block in run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:626:in `block in run_around_example_hooks_for'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:352:in `call'
        from /usr/local/bundle/gems/rspec-rails-5.1.2/lib/rspec/rails/adapters.rb:75:in `block (2 levels) in <module:MinitestLifecycleAdapter>'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:457:in `instance_exec'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:457:in `instance_exec'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:390:in `execute_with'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:628:in `block (2 levels) in run_around_example_hooks_for'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:352:in `call'
        from /home/surfmeterserver/spec/rails_helper.rb:106:in `block (3 levels) in <main>'
        from /usr/local/bundle/gems/database_cleaner-core-2.0.1/lib/database_cleaner/strategy.rb:30:in `cleaning'
        from /usr/local/lib/ruby/3.1.0/forwardable.rb:238:in `cleaning'
        from /usr/local/bundle/gems/database_cleaner-core-2.0.1/lib/database_cleaner/cleaners.rb:34:in `block (2 levels) in cleaning'
        from /usr/local/bundle/gems/database_cleaner-core-2.0.1/lib/database_cleaner/cleaners.rb:35:in `cleaning'
        from /usr/local/lib/ruby/3.1.0/forwardable.rb:238:in `cleaning'
        from /home/surfmeterserver/spec/rails_helper.rb:105:in `block (2 levels) in <main>'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:457:in `instance_exec'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:457:in `instance_exec'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:390:in `execute_with'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:628:in `block (2 levels) in run_around_example_hooks_for'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:352:in `call'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:629:in `run_around_example_hooks_for'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/hooks.rb:486:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:468:in `with_around_example_hooks'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:511:in `with_around_and_singleton_context_hooks'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example.rb:259:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:646:in `block in run_examples'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:642:in `map'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:642:in `run_examples'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:607:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:608:in `block in run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:608:in `map'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:608:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:608:in `block in run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:608:in `map'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_group.rb:608:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:121:in `block (3 levels) in run_specs'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:121:in `map'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:121:in `block (2 levels) in run_specs'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/configuration.rb:2070:in `with_suite_hooks'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:116:in `block in run_specs'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/reporter.rb:74:in `report'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:115:in `run_specs'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:89:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:71:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:45:in `invoke'
        from /usr/local/bundle/gems/rspec-core-3.12.1/exe/rspec:4:in `<main>'
        from /usr/local/bundle/gems/spring-commands-rspec-1.0.4/lib/spring/commands/rspec.rb:18:in `load'
        from /usr/local/bundle/gems/spring-commands-rspec-1.0.4/lib/spring/commands/rspec.rb:18:in `call'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/command_wrapper.rb:38:in `call'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:217:in `block in serve'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:181:in `fork'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:181:in `serve'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:144:in `block in run'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:138:in `loop'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:138:in `run'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application/boot.rb:19:in `<top (required)>'
        from <internal:/usr/local/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>:85:in `require'
        from <internal:/usr/local/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>:85:in `require'
        from -e:1:in `<main>'

I only have the elastic-apm Gem installed and configured with capture_body: all.

The error does not happen all the time, just occasionally during the rspec runs.

Sometimes the stack trace is a different one:

/usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:189: warning: Exception in finalizer #<Proc:0x0000ffffab7af480 /usr/local/bundle/gems/elastic-apm-4.6.0/lib/elastic_apm/transport/connection/proxy_pipe.rb:55>
/usr/local/bundle/gems/elastic-apm-4.6.0/lib/elastic_apm/transport/connection/proxy_pipe.rb:55:in `close': can't be called from trap context (ThreadError)
        from /usr/local/bundle/gems/elastic-apm-4.6.0/lib/elastic_apm/transport/connection/proxy_pipe.rb:55:in `block in finalize'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:189:in `column_widths'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:178:in `block in formatted_row_from'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:177:in `each'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:177:in `each_with_index'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:177:in `each'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:177:in `map'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:177:in `formatted_row_from'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:168:in `block in formatted_value_rows'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:167:in `map'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:167:in `formatted_value_rows'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:154:in `dump'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:145:in `dump'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:43:in `dump_statuses'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:32:in `block in persist'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:25:in `open'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:25:in `persist'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/example_status_persister.rb:15:in `persist'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:203:in `persist_example_statuses'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:90:in `block in run'
        from <internal:kernel>:90:in `tap'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:89:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:71:in `run'
        from /usr/local/bundle/gems/rspec-core-3.12.1/lib/rspec/core/runner.rb:45:in `invoke'
        from /usr/local/bundle/gems/rspec-core-3.12.1/exe/rspec:4:in `<main>'
        from /usr/local/bundle/gems/spring-commands-rspec-1.0.4/lib/spring/commands/rspec.rb:18:in `load'
        from /usr/local/bundle/gems/spring-commands-rspec-1.0.4/lib/spring/commands/rspec.rb:18:in `call'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/command_wrapper.rb:38:in `call'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:217:in `block in serve'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:181:in `fork'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:181:in `serve'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:144:in `block in run'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:138:in `loop'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application.rb:138:in `run'
        from /usr/local/bundle/gems/spring-3.1.1/lib/spring/application/boot.rb:19:in `<top (required)>'
        from <internal:/usr/local/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>:85:in `require'
        from <internal:/usr/local/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>:85:in `require'
        from -e:1:in `<main>'

Environment

  • OS: Linux (Docker, ruby:3.1-alpine3.17)
  • Ruby version: 3.1.3
  • Framework and version: Rails 7.0.4.2
  • APM Server version: 8.6.1
  • Agent version: 4.6.0

Additional context

This has worked before when I was using Ruby 3.0 and Rails 6.1.

@orkhan
Copy link

orkhan commented Sep 12, 2023

same thing... still...

@demsullivan
Copy link

Same error. We're seeing it in the logs for our Sneakers process.

OS: Linux (Docker, ruby:3.3-slim-bookworm)
Ruby version: 3.3.3
Framework and version: Rails 7.0.8.4
APM Server version: 8.11.1
Agent version: 4.7.3

@RogerW
Copy link

RogerW commented Jul 15, 2024

I think problem in https://github.com/ruby/ruby/blob/master/doc/signals.rdoc

Also You can read https://comandeo.dev/2023/01/01/mutexes-in-finalizers.html

possible solution - monkey patch

module ElasticAPM
  module Transport
    class Connection
      # @api private
      class ProxyPipe
        class Write
          def initialize(io, compress: true)
            @io = io
            @compress = compress
            @bytes_sent = Concurrent::AtomicFixnum.new(0)
            @config = ElasticAPM.agent&.config # this is silly, fix Logging

            return unless compress

            enable_compression!
          end
        end
      end
    end
  end
end

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants