reidmorrison/rails_semantic_logger

Could not log "process_action.action_controller" event. NoMethodError: undefined method `to_unsafe_h' for "{}":String

Closed this issue · 0 comments

madejejej commented

Environment

  • Ruby Version: 3.1
  • Rails Version: 7.0.4
  • Semantic Logger Version: 4.12.0
  • Rails Semantic Logger Version: 4.11.0
  • Other Application/framework names and versions: Puma 5.6.5, Grape 1.6.2, Rack 2.2.5
Stack Trace 
/app/vendor/bundle/ruby/3.1.0/gems/rails_semantic_logger-4.11.0/lib/rails_semantic_logger/action_controller/log_subscriber.rb:20:in `block in process_action'
/app/vendor/bundle/ruby/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/base.rb:344:in `log_internal'
/app/vendor/bundle/ruby/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/base.rb:84:in `info'
/app/vendor/bundle/ruby/3.1.0/gems/rails_semantic_logger-4.11.0/lib/rails_semantic_logger/action_controller/log_subscriber.rb:12:in `process_action'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/subscriber.rb:149:in `finish'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/log_subscriber.rb:115:in `finish'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/fanout.rb:211:in `finish'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/fanout.rb:76:in `block in finish'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/fanout.rb:91:in `block in iterate_guarding_exceptions'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/fanout.rb:90:in `each'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/fanout.rb:90:in `iterate_guarding_exceptions'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/fanout.rb:76:in `finish'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/instrumenter.rb:49:in `finish_with_state'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications/instrumenter.rb:30:in `instrument'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/notifications.rb:206:in `instrument'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_controller/metal/instrumentation.rb:66:in `process_action'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_controller/metal/params_wrapper.rb:259:in `process_action'
/app/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/abstract_controller/base.rb:151:in `process'
/app/vendor/bundle/ruby/3.1.0/gems/actionview-7.0.4/lib/action_view/rendering.rb:39:in `process'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_controller/metal.rb:188:in `dispatch'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_controller/metal.rb:251:in `dispatch'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/routing/route_set.rb:32:in `serve'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/journey/router.rb:32:in `each'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/journey/router.rb:32:in `serve'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/routing/route_set.rb:852:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/flipper-0.26.0/lib/flipper/middleware/memoizer.rb:72:in `memoized_call'
/app/vendor/bundle/ruby/3.1.0/gems/flipper-0.26.0/lib/flipper/middleware/memoizer.rb:37:in `call'
/app/lib/middlewares/rack/post.rb:37:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/tempfile_reaper.rb:15:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/etag.rb:27:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/conditional_get.rb:27:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/head.rb:12:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/http/permissions_policy.rb:38:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/http/content_security_policy.rb:36:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/session/abstract/id.rb:266:in `context'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/session/abstract/id.rb:260:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/cookies.rb:696:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/callbacks.rb:99:in `run_callbacks'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rollbar-3.3.2/lib/rollbar/middleware/rails/rollbar.rb:25:in `block in call'
/app/vendor/bundle/ruby/3.1.0/gems/rollbar-3.3.2/lib/rollbar.rb:145:in `scoped'
/app/vendor/bundle/ruby/3.1.0/gems/rollbar-3.3.2/lib/rollbar/middleware/rails/rollbar.rb:22:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/ddtrace-1.7.0/lib/datadog/tracing/contrib/rails/middlewares.rb:19:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/debug_exceptions.rb:28:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rollbar-3.3.2/lib/rollbar/middleware/rails/show_exceptions.rb:22:in `call_with_rollbar'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/show_exceptions.rb:26:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rails_semantic_logger-4.11.0/lib/rails_semantic_logger/rack/logger.rb:43:in `call_app'
/app/vendor/bundle/ruby/3.1.0/gems/rails_semantic_logger-4.11.0/lib/rails_semantic_logger/rack/logger.rb:26:in `block in call'
/app/vendor/bundle/ruby/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/base.rb:190:in `block in tagged'
/app/vendor/bundle/ruby/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/semantic_logger.rb:396:in `named_tagged'
/app/vendor/bundle/ruby/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/base.rb:197:in `tagged'
/app/vendor/bundle/ruby/3.1.0/gems/rails_semantic_logger-4.11.0/lib/rails_semantic_logger/rack/logger.rb:26:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/remote_ip.rb:93:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/request_store-1.5.1/lib/request_store/middleware.rb:19:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/request_id.rb:26:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/method_override.rb:24:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/runtime.rb:22:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/executor.rb:14:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/sendfile.rb:110:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/actionpack-7.0.4/lib/action_dispatch/middleware/host_authorization.rb:131:in `call'
/app/lib/middlewares/rack/pre.rb:17:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-utf8_sanitizer-1.8.0/lib/rack/utf8_sanitizer.rb:28:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/ddtrace-1.7.0/lib/datadog/tracing/contrib/rack/middlewares.rb:88:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/railties-7.0.4/lib/rails/engine.rb:530:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/urlmap.rb:74:in `block in call'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/urlmap.rb:58:in `each'
/app/vendor/bundle/ruby/3.1.0/gems/rack-2.2.5/lib/rack/urlmap.rb:58:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/puma-5.6.5/lib/puma/configuration.rb:252:in `call'
/app/vendor/bundle/ruby/3.1.0/gems/puma-5.6.5/lib/puma/request.rb:77:in `block in handle_request'
/app/vendor/bundle/ruby/3.1.0/gems/puma-5.6.5/lib/puma/thread_pool.rb:340:in `with_force_shutdown'
/app/vendor/bundle/ruby/3.1.0/gems/puma-5.6.5/lib/puma/request.rb:76:in `handle_request'
/app/vendor/bundle/ruby/3.1.0/gems/puma-5.6.5/lib/puma/server.rb:443:in `process_client'
/app/vendor/bundle/ruby/3.1.0/gems/puma-5.6.5/lib/puma/thread_pool.rb:147:in `block in spawn_thread'

Expected Behavior

  • #to_unsafe_h should only be called on instances of ActionController::Parameters
  • ActionController LogSubscriber should skip params that are neither a Hash nor ActionController::Parameters

Actual Behavior

  • #to_unsafe_h is called on anything that is not a Hash
  • payload[:params] might be a String (I don't know why 🤔) and that's not handled well. This case should be skipped.