Random ActiveRecord::RecordNotFound errors

[noctivityinc]

The gem is working great most of the time. However, I am catching a bunch of random errors like this:

ERROR TYPE	ActiveRecord::RecordNotFound
ERROR MESSAGE	Couldn't find Passwordless::Session with [WHERE "passwordless_sessions"."identifier" = $1 AND "passwordless_sessions"."authenticatable_type" = $2]

Any idea what would cause this and how I should handle them? Here is the backtrace:

/gems/activerecord-7.2.2/lib/active_record/relation/finder_methods.rb:425 in raise_record_not_found_exception!
/gems/activerecord-7.2.2/lib/active_record/core.rb:319 in find_by!
/gems/passwordless-1.8.0/app/controllers/passwordless/sessions_controller.rb:252 in passwordless_session
/gems/passwordless-1.8.0/app/controllers/passwordless/sessions_controller.rb:54 in show
/gems/actionpack-7.2.2/lib/action_controller/metal/basic_implicit_render.rb:8 in send_action
/gems/actionpack-7.2.2/lib/abstract_controller/base.rb:226 in process_action
/gems/actionpack-7.2.2/lib/action_controller/metal/rendering.rb:193 in process_action
/gems/actionpack-7.2.2/lib/abstract_controller/callbacks.rb:261 in block in process_action
/gems/activesupport-7.2.2/lib/active_support/callbacks.rb:121 in block in run_callbacks
/gems/turbo-rails-2.0.11/lib/turbo-rails.rb:24 in with_request_id
/gems/turbo-rails-2.0.11/app/controllers/concerns/turbo/request_id_tracking.rb:10 in turbo_tracking_request_id
/gems/activesupport-7.2.2/lib/active_support/callbacks.rb:130 in block in run_callbacks
/gems/actiontext-7.2.2/lib/action_text/rendering.rb:25 in with_renderer
/gems/actiontext-7.2.2/lib/action_text/engine.rb:71 in block (4 levels) in <class:Engine>
/gems/activesupport-7.2.2/lib/active_support/callbacks.rb:130 in instance_exec
/gems/activesupport-7.2.2/lib/active_support/callbacks.rb:130 in block in run_callbacks
/gems/activesupport-7.2.2/lib/active_support/callbacks.rb:141 in run_callbacks
/gems/actionpack-7.2.2/lib/abstract_controller/callbacks.rb:260 in process_action
/gems/actionpack-7.2.2/lib/action_controller/metal/rescue.rb:27 in process_action
/gems/actionpack-7.2.2/lib/action_controller/metal/instrumentation.rb:77 in block in process_action
/gems/activesupport-7.2.2/lib/active_support/notifications.rb:210 in block in instrument
/gems/activesupport-7.2.2/lib/active_support/notifications/instrumenter.rb:58 in instrument
/gems/activesupport-7.2.2/lib/active_support/notifications.rb:210 in instrument
/gems/actionpack-7.2.2/lib/action_controller/metal/instrumentation.rb:76 in process_action
/gems/actionpack-7.2.2/lib/action_controller/metal/params_wrapper.rb:259 in process_action
/gems/activerecord-7.2.2/lib/active_record/railties/controller_runtime.rb:39 in process_action
/gems/actionpack-7.2.2/lib/abstract_controller/base.rb:163 in process
/gems/actionview-7.2.2/lib/action_view/rendering.rb:40 in process
/gems/actionpack-7.2.2/lib/action_controller/metal.rb:252 in dispatch
/gems/actionpack-7.2.2/lib/action_controller/metal.rb:335 in dispatch
/gems/actionpack-7.2.2/lib/action_dispatch/routing/route_set.rb:67 in dispatch
/gems/actionpack-7.2.2/lib/action_dispatch/routing/route_set.rb:50 in serve
/gems/actionpack-7.2.2/lib/action_dispatch/journey/router.rb:53 in block in serve
/gems/actionpack-7.2.2/lib/action_dispatch/journey/router.rb:133 in block in find_routes
/gems/actionpack-7.2.2/lib/action_dispatch/journey/router.rb:126 in each
/gems/actionpack-7.2.2/lib/action_dispatch/journey/router.rb:126 in find_routes
/gems/actionpack-7.2.2/lib/action_dispatch/journey/router.rb:34 in serve
/gems/actionpack-7.2.2/lib/action_dispatch/routing/route_set.rb:896 in call
/gems/rack-3.1.8/lib/rack/tempfile_reaper.rb:20 in call
/gems/rack-3.1.8/lib/rack/etag.rb:29 in call
/gems/rack-3.1.8/lib/rack/conditional_get.rb:31 in call
/gems/rack-3.1.8/lib/rack/head.rb:15 in call
/gems/actionpack-7.2.2/lib/action_dispatch/http/permissions_policy.rb:38 in call
/gems/actionpack-7.2.2/lib/action_dispatch/http/content_security_policy.rb:35 in call
/gems/rack-session-2.0.0/lib/rack/session/abstract/id.rb:272 in context
/gems/rack-session-2.0.0/lib/rack/session/abstract/id.rb:266 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/cookies.rb:704 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/callbacks.rb:31 in block in call
/gems/activesupport-7.2.2/lib/active_support/callbacks.rb:101 in run_callbacks
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/callbacks.rb:30 in call
/gems/airbrake-13.0.4/lib/airbrake/rack/middleware.rb:34 in call!
/gems/airbrake-13.0.4/lib/airbrake/rack/middleware.rb:23 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/debug_exceptions.rb:31 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/show_exceptions.rb:32 in call
/gems/railties-7.2.2/lib/rails/rack/logger.rb:41 in call_app
/gems/railties-7.2.2/lib/rails/rack/logger.rb:29 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/remote_ip.rb:96 in call
/gems/request_store-1.7.0/lib/request_store/middleware.rb:19 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/request_id.rb:33 in call
/gems/rack-3.1.8/lib/rack/method_override.rb:28 in call
/gems/rack-3.1.8/lib/rack/runtime.rb:24 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/executor.rb:16 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/static.rb:27 in call
/gems/rack-3.1.8/lib/rack/sendfile.rb:114 in call
/gems/actionpack-7.2.2/lib/action_dispatch/middleware/ssl.rb:82 in call
/gems/railties-7.2.2/lib/rails/engine.rb:535 in call
/gems/puma-6.4.3/lib/puma/configuration.rb:272 in call
/gems/puma-6.4.3/lib/puma/request.rb:100 in block in handle_request
/gems/puma-6.4.3/lib/puma/thread_pool.rb:378 in with_force_shutdown
/gems/puma-6.4.3/lib/puma/request.rb:99 in handle_request
/gems/puma-6.4.3/lib/puma/server.rb:464 in process_client
/gems/puma-6.4.3/lib/puma/server.rb:245 in block in run
/gems/puma-6.4.3/lib/puma/thread_pool.rb:155 in block in spawn_thread

[mikker]

Anything special about your setup or how you use Passwordless?

[bruno-costanzo]

For the record, I'm caching some of those errors too:

Couldn't find Passwordless::Session with [WHERE "passwordless_sessions"."identifier" = ? AND "passwordless_sessions"."authenticatable_type" = ?]

Here are some details about the error:

Name	Passwordless::SessionsController#show
Method	GET
URL	https://bolsillito.club/users/sign_in/xmlrpc.php?rsd

I don't know if that URL is part of some server executions.

Parameters:

{
  "id": "xmlrpc",
  "rsd": null,
  "action": "show",
  "format": "php",
  "resource": "users",
  "controller": "passwordless/sessions",
  "authenticatable": "user"
}

Backtrace:

Backtrace

/usr/local/bundle/ruby/3.4.0/gems/activerecord-8.0.2/lib/active_record/relation/finder_methods.rb:425:in 'ActiveRecord::FinderMethods#raise_record_not_found_exception!'

/usr/local/bundle/ruby/3.4.0/gems/activerecord-8.0.2/lib/active_record/core.rb:331:in 'ActiveRecord::Core::ClassMethods#find_by!'

/usr/local/bundle/ruby/3.4.0/gems/passwordless-1.8.1/app/controllers/passwordless/sessions_controller.rb:252:in 'Passwordless::SessionsController#passwordless_session'

/usr/local/bundle/ruby/3.4.0/gems/passwordless-1.8.1/app/controllers/passwordless/sessions_controller.rb:54:in 'Passwordless::SessionsController#show'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal/basic_implicit_render.rb:8:in 'ActionController::BasicImplicitRender#send_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/abstract_controller/base.rb:226:in 'AbstractController::Base#process_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal/rendering.rb:193:in 'ActionController::Rendering#process_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/abstract_controller/callbacks.rb:261:in 'block in AbstractController::Callbacks#process_action'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:120:in 'block in ActiveSupport::Callbacks#run_callbacks'

/usr/local/bundle/ruby/3.4.0/gems/turbo-rails-2.0.13/lib/turbo-rails.rb:24:in 'Turbo.with_request_id'

/usr/local/bundle/ruby/3.4.0/gems/turbo-rails-2.0.13/app/controllers/concerns/turbo/request_id_tracking.rb:10:in 'Turbo::RequestIdTracking#turbo_tracking_request_id'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:129:in 'block in ActiveSupport::Callbacks#run_callbacks'

/usr/local/bundle/ruby/3.4.0/gems/actiontext-8.0.2/lib/action_text/rendering.rb:25:in 'ActionText::Rendering::ClassMethods#with_renderer'

/usr/local/bundle/ruby/3.4.0/gems/actiontext-8.0.2/lib/action_text/engine.rb:71:in 'block (4 levels) in <class:Engine>'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:129:in 'BasicObject#instance_exec'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:129:in 'block in ActiveSupport::Callbacks#run_callbacks'

/usr/local/bundle/ruby/3.4.0/gems/rorvswild-1.9.1/lib/rorvswild/plugin/action_controller.rb:29:in 'RorVsWild::Plugin::ActionController.around_action'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:129:in 'BasicObject#instance_exec'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:129:in 'block in ActiveSupport::Callbacks#run_callbacks'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:140:in 'ActiveSupport::Callbacks#run_callbacks'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/abstract_controller/callbacks.rb:260:in 'AbstractController::Callbacks#process_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal/rescue.rb:27:in 'ActionController::Rescue#process_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal/instrumentation.rb:76:in 'block in ActionController::Instrumentation#process_action'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/notifications.rb:210:in 'block in ActiveSupport::Notifications.instrument'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/notifications/instrumenter.rb:58:in 'ActiveSupport::Notifications::Instrumenter#instrument'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/notifications.rb:210:in 'ActiveSupport::Notifications.instrument'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal/instrumentation.rb:75:in 'ActionController::Instrumentation#process_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal/params_wrapper.rb:259:in 'ActionController::ParamsWrapper#process_action'

/usr/local/bundle/ruby/3.4.0/gems/activerecord-8.0.2/lib/active_record/railties/controller_runtime.rb:39:in 'ActiveRecord::Railties::ControllerRuntime#process_action'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/abstract_controller/base.rb:163:in 'AbstractController::Base#process'

/usr/local/bundle/ruby/3.4.0/gems/actionview-8.0.2/lib/action_view/rendering.rb:40:in 'ActionView::Rendering#process'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal.rb:252:in 'ActionController::Metal#dispatch'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_controller/metal.rb:335:in 'ActionController::Metal.dispatch'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/routing/route_set.rb:67:in 'ActionDispatch::Routing::RouteSet::Dispatcher#dispatch'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/routing/route_set.rb:50:in 'ActionDispatch::Routing::RouteSet::Dispatcher#serve'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/journey/router.rb:53:in 'block in ActionDispatch::Journey::Router#serve'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/journey/router.rb:133:in 'block in ActionDispatch::Journey::Router#find_routes'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/journey/router.rb:126:in 'Array#each'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/journey/router.rb:126:in 'ActionDispatch::Journey::Router#find_routes'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/journey/router.rb:34:in 'ActionDispatch::Journey::Router#serve'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/routing/route_set.rb:908:in 'ActionDispatch::Routing::RouteSet#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/tempfile_reaper.rb:20:in 'Rack::TempfileReaper#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/etag.rb:29:in 'Rack::ETag#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/conditional_get.rb:31:in 'Rack::ConditionalGet#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/head.rb:15:in 'Rack::Head#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/http/permissions_policy.rb:38:in 'ActionDispatch::PermissionsPolicy::Middleware#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/http/content_security_policy.rb:38:in 'ActionDispatch::ContentSecurityPolicy::Middleware#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-session-2.1.0/lib/rack/session/abstract/id.rb:274:in 'Rack::Session::Abstract::Persisted#context'

/usr/local/bundle/ruby/3.4.0/gems/rack-session-2.1.0/lib/rack/session/abstract/id.rb:268:in 'Rack::Session::Abstract::Persisted#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/cookies.rb:706:in 'ActionDispatch::Cookies#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/callbacks.rb:31:in 'block in ActionDispatch::Callbacks#call'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/callbacks.rb:100:in 'ActiveSupport::Callbacks#run_callbacks'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/callbacks.rb:30:in 'ActionDispatch::Callbacks#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/debug_exceptions.rb:31:in 'ActionDispatch::DebugExceptions#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/show_exceptions.rb:32:in 'ActionDispatch::ShowExceptions#call'

/usr/local/bundle/ruby/3.4.0/gems/railties-8.0.2/lib/rails/rack/logger.rb:41:in 'Rails::Rack::Logger#call_app'

/usr/local/bundle/ruby/3.4.0/gems/railties-8.0.2/lib/rails/rack/logger.rb:29:in 'Rails::Rack::Logger#call'

/usr/local/bundle/ruby/3.4.0/gems/railties-8.0.2/lib/rails/rack/silence_request.rb:28:in 'Rails::Rack::SilenceRequest#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/remote_ip.rb:96:in 'ActionDispatch::RemoteIp#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/request_id.rb:34:in 'ActionDispatch::RequestId#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/method_override.rb:28:in 'Rack::MethodOverride#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/runtime.rb:24:in 'Rack::Runtime#call'

/usr/local/bundle/ruby/3.4.0/gems/activesupport-8.0.2/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in 'ActiveSupport::Cache::Strategy::LocalCache::Middleware#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/executor.rb:16:in 'ActionDispatch::Executor#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/static.rb:27:in 'ActionDispatch::Static#call'

/usr/local/bundle/ruby/3.4.0/gems/rack-3.1.12/lib/rack/sendfile.rb:114:in 'Rack::Sendfile#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/ssl.rb:92:in 'ActionDispatch::SSL#call'

/usr/local/bundle/ruby/3.4.0/gems/actionpack-8.0.2/lib/action_dispatch/middleware/assume_ssl.rb:24:in 'ActionDispatch::AssumeSSL#call'

/usr/local/bundle/ruby/3.4.0/gems/rorvswild-1.9.1/lib/rorvswild/plugin/middleware.rb:67:in 'RorVsWild::Plugin::Middleware#call'

/usr/local/bundle/ruby/3.4.0/gems/railties-8.0.2/lib/rails/engine.rb:535:in 'Rails::Engine#call'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/configuration.rb:279:in 'Puma::Configuration::ConfigMiddleware#call'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/request.rb:99:in 'block in Puma::Request#handle_request'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/thread_pool.rb:390:in 'Puma::ThreadPool#with_force_shutdown'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/request.rb:98:in 'Puma::Request#handle_request'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/server.rb:472:in 'Puma::Server#process_client'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/server.rb:254:in 'block in Puma::Server#run'

/usr/local/bundle/ruby/3.4.0/gems/puma-6.6.0/lib/puma/thread_pool.rb:167:in 'block in Puma::ThreadPool#spawn_thread'

[jamesjefferies]

I've just hit this too, generally because of scripts attempting to exploit WordPress vulnerabilities, i.e. https://domain.com/people/sign_in/wp-includes/wlwmanifest.xml

This then hits

      @passwordless_session ||= Session.find_by!(
        identifier: params[:id],
        authenticatable_type: authenticatable_type
      )

In the sessions_controller.rb and params[:id] is, of course garbage.

I might see if I can create a PR with some validation of the params[:id] to avoid this issue.

[jamesjefferies]

Ah, that won't work as the id can be a UUID or what have you - maybe just a silently catching the RecordNotFound if in paranoid mode?