Mysql2::Error: Incorrect table name '' - when using with Rails, Rolify, & CanCanCan

clveranis commented 1 year ago

I recently found out about the AppMap utility and I'm trying to incorporate it into my Rails app via IntelliJ. However, after installing the gem and configuring it, any request I make results throws the following exception:

ActiveRecord::StatementInvalid in UsersController#index

Mysql2::Error: Incorrect table name ''

It does this for every page, model, request, etc. when using a browser. From my stack trace, it looks like the issue is arising when the roles are being checked in my Ability.rb file (I'm using Devise, CanCanCan, and Rolify for authentication).

If I try to do user.roles in the rails console it produces this:

irb(main):001:0> u = User.find 1
  User Load (0.4ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` = 1 LIMIT 1
=> #<User id: 1, name: "Admin", title: nil, client_id: nil, client_access_token: nil, mobile_phone: nil, business_ph... >

irb(main):002:0> u.roles
  Role Load (0.5ms)  SELECT `roles`.* FROM `roles` INNER JOIN `` ON `roles`.`id` = ``.`role_id` WHERE ``.`user_id` = 1
(Object doesn't support #inspect)

If I remove the AppMap gem then everything in my application works as intended like it has been previously.

irb(main):001:0> u = User.find 1
  User Load (0.4ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` = 1 LIMIT 1
=> #<User id: 1, name: "Admin", title: nil, client_id: nil, client_access_token: nil, mobile_phone: nil, business_ph... >

irb(main):002:0> u.roles
  Role Load (2.6ms)  SELECT `roles`.* FROM `roles` INNER JOIN `users_roles` ON `roles`.`id` = `users_roles`.`role_id` WHERE `users_roles`.`user_id` = 1
=> [#<Role:0x00007fdf1abb6bf0, id: 1, name: "admin", resource_type: nil, resource_id: nil, created_at: Thu, 25 Aug 2022 02:03:11.000000000 UTC +00:00, updated_at: Thu, 25 Aug 2022 02:03:11.000000000 UTC +00:00>]

I'm not really sure where to go from here so any input would be greatly appreciated!

Versions:

IntelliJ IDEA: 2022.1.4 (Ultimate)
AppMap Plugin: 0.21.0
AppMap Gem: 0.94.1
Rails: 6.1.4.7
Ruby: 3.0.1
MySql2: 0.5.4
CanCaCan: 3.2.2
Devise: 4.8.1
Rolify: 6.0.0

brikelly commented 1 year ago

Thank you for the detailed issue, @clveranis! We will take a look and see what we can find out for you.

clveranis commented 1 year ago

Thank you! I'm very excited to use this plugin as I've been looking for something like this for a long time and just found out about it.

Here is the code in the role.rb model (incase that helps):

class Role < ApplicationRecord
  has_and_belongs_to_many :users, :join_table => 'users_roles'

  belongs_to :resource,
             :polymorphic => true,
             :optional => true

  validates :resource_type,
            :inclusion => { :in => Rolify.resource_types },
            :allow_nil => true

  scopify

  def titleize_role_name
    name.titleize
  end
end

This may not have anything to do with the root cause but endpoints that do not check the user roles for authentication do not throw exceptions, so I'm thinking it most likely does have something to do with this. If you need any more info from me then just let me know.

Thank you!

brikelly commented 1 year ago

That might help, thank you! I'll let @dividedmind weigh in next.

dividedmind commented 1 year ago

@clveranis does this problem always happen in the same place, or are there other queries that also cause it? Could you tell me more about the code that's causing the problem? It would help to see what's happening there. Are you doing the join yourself, or is the query built by one of the libraries? Or is it just a vanilla AR association?

clveranis commented 1 year ago

It happens anytime a query is executed involving the users_roles table, which is defined by the association above. The code that is specifically triggering the exception is when it hits a user.has_role? function to check the users role(s).

clveranis commented 1 year ago

@dividedmind is there a way I can send/show you an AppMap of what happens? Like are there features or something that I can enable/run to show you? I'm still very new to AppMap so if the answer is yes then I'll likely need you to guide me.

kgilpin commented 1 year ago

Try adding this line to your appmap.yml:

exclude:
- ActiveRecord::Relation#records

@petecheslock It seems to resolve the problem in mastodon for me. I will look into the root cause of that.

clveranis commented 1 year ago

Unfortunately that didn't solve the issue for me. I also tried adding to exclude my Ability class which is where it's getting stuck.

exclude:
- Ability
- ActiveRecord::Relation#records

Full Stack trace:

ActiveRecord::StatementInvalid in OrdersController#index

Mysql2::Error: Incorrect table name '' 

    user ||= User.new

    if user.has_cached_role? :advisor
      can [:read, :update], User, id: user.id
      can :read, Faq
      can :read, Policy, customer_facing: '1'

[Application Trace](http://localhost:3000/orders#) | [Framework Trace](http://localhost:3000/orders#) | [Full Trace](http://localhost:3000/orders#)
[mysql2 (0.5.4) lib/mysql2/client.rb:148:in `_query'](http://localhost:3000/orders#)
[mysql2 (0.5.4) lib/mysql2/client.rb:148:in `block in query'](http://localhost:3000/orders#)
[mysql2 (0.5.4) lib/mysql2/client.rb:147:in `handle_interrupt'](http://localhost:3000/orders#)
[mysql2 (0.5.4) lib/mysql2/client.rb:147:in `query'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206:in `block (2 levels) in execute'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205:in `block in execute'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/notifications/instrumenter.rb:24:in `instrument'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204:in `execute'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/mysql/database_statements.rb:50:in `execute'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215:in `execute_and_free'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/mysql/database_statements.rb:55:in `exec_query'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:101:in `block in select_all'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:118:in `block in cache_sql'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:109:in `cache_sql'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:101:in `select_all'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/querying.rb:47:in `find_by_sql'](http://localhost:3000/orders#)
[bullet (7.0.4) lib/bullet/active_record61.rb:19:in `find_by_sql'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/statement_cache.rb:150:in `execute'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/associations/association.rb:227:in `find_target'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/associations/has_many_through_association.rb:217:in `find_target'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/associations/collection_association.rb:274:in `load_target'](http://localhost:3000/orders#)
[bullet (7.0.4) lib/bullet/active_record61.rb:176:in `load_target'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/associations/collection_proxy.rb:43:in `load_target'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/associations/collection_proxy.rb:1002:in `records'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/relation/delegation.rb:88:in `each'](http://localhost:3000/orders#)
[rolify (6.0.0) lib/rolify/adapters/active_record/role_adapter.rb:34:in `find_all'](http://localhost:3000/orders#)
[rolify (6.0.0) lib/rolify/adapters/active_record/role_adapter.rb:34:in `find_cached'](http://localhost:3000/orders#)
[rolify (6.0.0) lib/rolify/role.rb:49:in `has_cached_role?'](http://localhost:3000/orders#)
[app/models/ability.rb:39:in `initialize'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_additions.rb:354:in `new'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_additions.rb:354:in `current_ability'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_resource.rb:138:in `current_ability'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_resource.rb:78:in `load_collection?'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_resource_loader.rb:19:in `load_resource'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_resource.rb:33:in `load_and_authorize_resource'](http://localhost:3000/orders#)
[cancancan (3.2.2) lib/cancan/controller_resource.rb:17:in `block in add_before_action'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:427:in `instance_exec'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:427:in `block in make_lambda'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:179:in `block (2 levels) in halting_and_conditional'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/abstract_controller/callbacks.rb:34:in `block (2 levels) in <module:Callbacks>'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:180:in `block in halting_and_conditional'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:512:in `block in invoke_before'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:512:in `each'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:512:in `invoke_before'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `bind_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `do_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:49:in `trace_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:16:in `call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:63:in `block in hook_method_def'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:115:in `block in run_callbacks'](http://localhost:3000/orders#)
[actiontext (6.1.4.7) lib/action_text/rendering.rb:20:in `with_renderer'](http://localhost:3000/orders#)
[actiontext (6.1.4.7) lib/action_text/engine.rb:59:in `block (4 levels) in <class:Engine>'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:126:in `instance_exec'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:126:in `block in run_callbacks'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:137:in `run_callbacks'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/abstract_controller/callbacks.rb:41:in `process_action'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_controller/metal/rescue.rb:22:in `process_action'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/notifications.rb:203:in `block in instrument'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/notifications/instrumenter.rb:24:in `instrument'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/notifications.rb:203:in `instrument'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_controller/metal/instrumentation.rb:33:in `process_action'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `bind_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `do_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:49:in `trace_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:16:in `call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:63:in `block in hook_method_def'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `bind_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `do_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:49:in `trace_call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:16:in `call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:63:in `block in hook_method_def'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_controller/metal/params_wrapper.rb:249:in `process_action'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/railties/controller_runtime.rb:27:in `process_action'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/abstract_controller/base.rb:165:in `process'](http://localhost:3000/orders#)
[actionview (6.1.4.7) lib/action_view/rendering.rb:39:in `process'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_controller/metal.rb:190:in `dispatch'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_controller/metal.rb:254:in `dispatch'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/routing/route_set.rb:50:in `dispatch'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/routing/route_set.rb:33:in `serve'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/journey/router.rb:50:in `block in serve'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/journey/router.rb:32:in `each'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/journey/router.rb:32:in `serve'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/routing/route_set.rb:842:in `call'](http://localhost:3000/orders#)
[bullet (7.0.4) lib/bullet/rack.rb:15:in `call'](http://localhost:3000/orders#)
[warden (1.2.9) lib/warden/manager.rb:36:in `block in call'](http://localhost:3000/orders#)
[warden (1.2.9) lib/warden/manager.rb:34:in `catch'](http://localhost:3000/orders#)
[warden (1.2.9) lib/warden/manager.rb:34:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/tempfile_reaper.rb:15:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/etag.rb:27:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/conditional_get.rb:27:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/head.rb:12:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/http/permissions_policy.rb:22:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/http/content_security_policy.rb:18:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/session/abstract/id.rb:266:in `context'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/session/abstract/id.rb:260:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/cookies.rb:689:in `call'](http://localhost:3000/orders#)
[activerecord (6.1.4.7) lib/active_record/migration.rb:601:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/callbacks.rb:98:in `run_callbacks'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/callbacks.rb:26:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/executor.rb:14:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'](http://localhost:3000/orders#)
[web-console (4.2.0) lib/web_console/middleware.rb:132:in `call_app'](http://localhost:3000/orders#)
[web-console (4.2.0) lib/web_console/middleware.rb:28:in `block in call'](http://localhost:3000/orders#)
[web-console (4.2.0) lib/web_console/middleware.rb:17:in `catch'](http://localhost:3000/orders#)
[web-console (4.2.0) lib/web_console/middleware.rb:17:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'](http://localhost:3000/orders#)
[railties (6.1.4.7) lib/rails/rack/logger.rb:37:in `call_app'](http://localhost:3000/orders#)
[railties (6.1.4.7) lib/rails/rack/logger.rb:26:in `block in call'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/tagged_logging.rb:99:in `block in tagged'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/tagged_logging.rb:37:in `tagged'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/tagged_logging.rb:99:in `tagged'](http://localhost:3000/orders#)
[railties (6.1.4.7) lib/rails/rack/logger.rb:26:in `call'](http://localhost:3000/orders#)
[sprockets-rails (3.4.2) lib/sprockets/rails/quiet_assets.rb:13:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/remote_ip.rb:81:in `call'](http://localhost:3000/orders#)
[request_store (1.5.1) lib/request_store/middleware.rb:19:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/request_id.rb:26:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/method_override.rb:24:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/runtime.rb:22:in `call'](http://localhost:3000/orders#)
[activesupport (6.1.4.7) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/executor.rb:14:in `call'](http://localhost:3000/orders#)
[appmap (0.94.1) lib/appmap/middleware/remote_recording.rb:131:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/static.rb:24:in `call'](http://localhost:3000/orders#)
[rack (2.2.4) lib/rack/sendfile.rb:110:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/host_authorization.rb:119:in `call'](http://localhost:3000/orders#)
[actionpack (6.1.4.7) lib/action_dispatch/middleware/static.rb:24:in `call'](http://localhost:3000/orders#)
[railties (6.1.4.7) lib/rails/engine.rb:539:in `call'](http://localhost:3000/orders#)
[puma (5.6.5) lib/puma/configuration.rb:252:in `call'](http://localhost:3000/orders#)
[puma (5.6.5) lib/puma/request.rb:77:in `block in handle_request'](http://localhost:3000/orders#)
[puma (5.6.5) lib/puma/thread_pool.rb:340:in `with_force_shutdown'](http://localhost:3000/orders#)
[puma (5.6.5) lib/puma/request.rb:76:in `handle_request'](http://localhost:3000/orders#)
[puma (5.6.5) lib/puma/server.rb:443:in `process_client'](http://localhost:3000/orders#)
[puma (5.6.5) lib/puma/thread_pool.rb:147:in `block in spawn_thread'](http://localhost:3000/orders#)

Hopefully this helps.

kgilpin commented 1 year ago

Ok thanks. I do have another theory I’m working on today. Stay tuned!

On Tue, Dec 13, 2022 at 8:00 AM clveranis @.***> wrote:

Unfortunately that didn't solve the issue for me. I also tried adding to exclude my Ability class which is where it's getting stuck.

exclude:

Ability

ActiveRecord::Relation#records

Full Stack trace:

ActiveRecord::StatementInvalid in OrdersController#index

Mysql2::Error: Incorrect table name ''
user ||= User.new

if user.has_cached_role? :advisor
  can [:read, :update], User, id: user.id
  can :read, Faq
  can :read, Policy, customer_facing: '1'
Application Trace | Framework Trace | Full Trace mysql2 (0.5.4) lib/mysql2/client.rb:148:in `_query' mysql2 (0.5.4) lib/mysql2/client.rb:148:in `block in query' mysql2 (0.5.4) lib/mysql2/client.rb:147:in `handle_interrupt' mysql2 (0.5.4) lib/mysql2/client.rb:147:in `query' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206:in `block (2 levels) in execute' activesupport (6.1.4.7) lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads' activesupport (6.1.4.7) lib/active_support/concurrency/share_lock.rb:187:in `yield_shares' activesupport (6.1.4.7) lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205:in `block in execute' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log' activesupport (6.1.4.7) lib/active_support/notifications/instrumenter.rb:24:in `instrument' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204:in `execute' activerecord (6.1.4.7) lib/active_record/connection_adapters/mysql/database_statements.rb:50:in `execute' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215:in `execute_and_free' activerecord (6.1.4.7) lib/active_record/connection_adapters/mysql/database_statements.rb:55:in `exec_query' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:101:in `block in select_all' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:118:in `block in cache_sql' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt' activesupport (6.1.4.7) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:109:in `cache_sql' activerecord (6.1.4.7) lib/active_record/connection_adapters/abstract/query_cache.rb:101:in `select_all' activerecord (6.1.4.7) lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all' activerecord (6.1.4.7) lib/active_record/querying.rb:47:in `find_by_sql' bullet (7.0.4) lib/bullet/active_record61.rb:19:in `find_by_sql' activerecord (6.1.4.7) lib/active_record/statement_cache.rb:150:in `execute' activerecord (6.1.4.7) lib/active_record/associations/association.rb:227:in `find_target' activerecord (6.1.4.7) lib/active_record/associations/has_many_through_association.rb:217:in `find_target' activerecord (6.1.4.7) lib/active_record/associations/collection_association.rb:274:in `load_target' bullet (7.0.4) lib/bullet/active_record61.rb:176:in `load_target' activerecord (6.1.4.7) lib/active_record/associations/collection_proxy.rb:43:in `load_target' activerecord (6.1.4.7) lib/active_record/associations/collection_proxy.rb:1002:in `records' activerecord (6.1.4.7) lib/active_record/relation/delegation.rb:88:in `each' rolify (6.0.0) lib/rolify/adapters/active_record/role_adapter.rb:34:in `find_all' rolify (6.0.0) lib/rolify/adapters/active_record/role_adapter.rb:34:in `find_cached' rolify (6.0.0) lib/rolify/role.rb:49:in `has_cached_role?' app/models/ability.rb:39:in `initialize' cancancan (3.2.2) lib/cancan/controller_additions.rb:354:in `new' cancancan (3.2.2) lib/cancan/controller_additions.rb:354:in `current_ability' cancancan (3.2.2) lib/cancan/controller_resource.rb:138:in `current_ability' cancancan (3.2.2) lib/cancan/controller_resource.rb:78:in `load_collection?' cancancan (3.2.2) lib/cancan/controller_resource_loader.rb:19:in `load_resource' cancancan (3.2.2) lib/cancan/controller_resource.rb:33:in `load_and_authorize_resource' cancancan (3.2.2) lib/cancan/controller_resource.rb:17:in `block in add_before_action' activesupport (6.1.4.7) lib/active_support/callbacks.rb:427:in `instance_exec' activesupport (6.1.4.7) lib/active_support/callbacks.rb:427:in `block in make_lambda' activesupport (6.1.4.7) lib/active_support/callbacks.rb:179:in `block (2 levels) in halting_and_conditional' actionpack (6.1.4.7) lib/abstract_controller/callbacks.rb:34:in `block (2 levels) in ' activesupport (6.1.4.7) lib/active_support/callbacks.rb:180:in `block in halting_and_conditional' activesupport (6.1.4.7) lib/active_support/callbacks.rb:512:in `block in invoke_before' activesupport (6.1.4.7) lib/active_support/callbacks.rb:512:in `each' activesupport (6.1.4.7) lib/active_support/callbacks.rb:512:in `invoke_before' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `bind_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `do_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:49:in `trace_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:16:in `call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:63:in `block in hook_method_def' activesupport (6.1.4.7) lib/active_support/callbacks.rb:115:in `block in run_callbacks' actiontext (6.1.4.7) lib/action_text/rendering.rb:20:in `with_renderer' actiontext (6.1.4.7) lib/action_text/engine.rb:59:in `block (4 levels) in ' activesupport (6.1.4.7) lib/active_support/callbacks.rb:126:in `instance_exec' activesupport (6.1.4.7) lib/active_support/callbacks.rb:126:in `block in run_callbacks' activesupport (6.1.4.7) lib/active_support/callbacks.rb:137:in `run_callbacks' actionpack (6.1.4.7) lib/abstract_controller/callbacks.rb:41:in `process_action' actionpack (6.1.4.7) lib/action_controller/metal/rescue.rb:22:in `process_action' actionpack (6.1.4.7) lib/action_controller/metal/instrumentation.rb:34:in `block in process_action' activesupport (6.1.4.7) lib/active_support/notifications.rb:203:in `block in instrument' activesupport (6.1.4.7) lib/active_support/notifications/instrumenter.rb:24:in `instrument' activesupport (6.1.4.7) lib/active_support/notifications.rb:203:in `instrument' actionpack (6.1.4.7) lib/action_controller/metal/instrumentation.rb:33:in `process_action' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `bind_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `do_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:49:in `trace_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:16:in `call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:63:in `block in hook_method_def' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `bind_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:40:in `do_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:49:in `trace_call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:16:in `call' appmap (0.94.1) lib/appmap/hook/method/ruby3.rb:63:in `block in hook_method_def' actionpack (6.1.4.7) lib/action_controller/metal/params_wrapper.rb:249:in `process_action' activerecord (6.1.4.7) lib/active_record/railties/controller_runtime.rb:27:in `process_action' actionpack (6.1.4.7) lib/abstract_controller/base.rb:165:in `process' actionview (6.1.4.7) lib/action_view/rendering.rb:39:in `process' actionpack (6.1.4.7) lib/action_controller/metal.rb:190:in `dispatch' actionpack (6.1.4.7) lib/action_controller/metal.rb:254:in `dispatch' actionpack (6.1.4.7) lib/action_dispatch/routing/route_set.rb:50:in `dispatch' actionpack (6.1.4.7) lib/action_dispatch/routing/route_set.rb:33:in `serve' actionpack (6.1.4.7) lib/action_dispatch/journey/router.rb:50:in `block in serve' actionpack (6.1.4.7) lib/action_dispatch/journey/router.rb:32:in `each' actionpack (6.1.4.7) lib/action_dispatch/journey/router.rb:32:in `serve' actionpack (6.1.4.7) lib/action_dispatch/routing/route_set.rb:842:in `call' bullet (7.0.4) lib/bullet/rack.rb:15:in `call' warden (1.2.9) lib/warden/manager.rb:36:in `block in call' warden (1.2.9) lib/warden/manager.rb:34:in `catch' warden (1.2.9) lib/warden/manager.rb:34:in `call' rack (2.2.4) lib/rack/tempfile_reaper.rb:15:in `call' rack (2.2.4) lib/rack/etag.rb:27:in `call' rack (2.2.4) lib/rack/conditional_get.rb:27:in `call' rack (2.2.4) lib/rack/head.rb:12:in `call' actionpack (6.1.4.7) lib/action_dispatch/http/permissions_policy.rb:22:in `call' actionpack (6.1.4.7) lib/action_dispatch/http/content_security_policy.rb:18:in `call' rack (2.2.4) lib/rack/session/abstract/id.rb:266:in `context' rack (2.2.4) lib/rack/session/abstract/id.rb:260:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/cookies.rb:689:in `call' activerecord (6.1.4.7) lib/active_record/migration.rb:601:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call' activesupport (6.1.4.7) lib/active_support/callbacks.rb:98:in `run_callbacks' actionpack (6.1.4.7) lib/action_dispatch/middleware/callbacks.rb:26:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/executor.rb:14:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call' web-console (4.2.0) lib/web_console/middleware.rb:132:in `call_app' web-console (4.2.0) lib/web_console/middleware.rb:28:in `block in call' web-console (4.2.0) lib/web_console/middleware.rb:17:in `catch' web-console (4.2.0) lib/web_console/middleware.rb:17:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/show_exceptions.rb:33:in `call' railties (6.1.4.7) lib/rails/rack/logger.rb:37:in `call_app' railties (6.1.4.7) lib/rails/rack/logger.rb:26:in `block in call' activesupport (6.1.4.7) lib/active_support/tagged_logging.rb:99:in `block in tagged' activesupport (6.1.4.7) lib/active_support/tagged_logging.rb:37:in `tagged' activesupport (6.1.4.7) lib/active_support/tagged_logging.rb:99:in `tagged' railties (6.1.4.7) lib/rails/rack/logger.rb:26:in `call' sprockets-rails (3.4.2) lib/sprockets/rails/quiet_assets.rb:13:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/remote_ip.rb:81:in `call' request_store (1.5.1) lib/request_store/middleware.rb:19:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/request_id.rb:26:in `call' rack (2.2.4) lib/rack/method_override.rb:24:in `call' rack (2.2.4) lib/rack/runtime.rb:22:in `call' activesupport (6.1.4.7) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/executor.rb:14:in `call' appmap (0.94.1) lib/appmap/middleware/remote_recording.rb:131:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/static.rb:24:in `call' rack (2.2.4) lib/rack/sendfile.rb:110:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/host_authorization.rb:119:in `call' actionpack (6.1.4.7) lib/action_dispatch/middleware/static.rb:24:in `call' railties (6.1.4.7) lib/rails/engine.rb:539:in `call' puma (5.6.5) lib/puma/configuration.rb:252:in `call' puma (5.6.5) lib/puma/request.rb:77:in `block in handle_request' puma (5.6.5) lib/puma/thread_pool.rb:340:in `with_force_shutdown' puma (5.6.5) lib/puma/request.rb:76:in `handle_request' puma (5.6.5) lib/puma/server.rb:443:in `process_client' puma (5.6.5) lib/puma/thread_pool.rb:147:in `block in spawn_thread'

Hopefully this helps.

— Reply to this email directly, view it on GitHub https://github.com/getappmap/appmap-ruby/issues/302#issuecomment-1348498607, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAVC645R4BUUXP7OGLPK6DWNBXN7ANCNFSM6AAAAAASZKV6VQ . You are receiving this because you commented.Message ID: @.***>

kgilpin commented 1 year ago

@clveranis can you try your code with this branch of appmap-ruby?

https://github.com/getappmap/appmap-ruby/pull/303

Instructions on how to do it are in the PR description ; basically just point the appmap gem to the branch.

clveranis commented 1 year ago

@kgilpin For some reason it cannot find the gem in that branch. I've followed the instructions in the PR and it returns with the message:

gem 'appmap', github: 'getappmap/appmap-ruby', branch: 'feat/enhanced-hook-logging', group: %i[test development] produces:

fatal: Needed a single revision
Could not find gem 'appmap' in https://github.com/getappmap/appmap-ruby.git.

I've also tried using gem appmap-ruby which gives me:

Fetching https://github.com/getappmap/appmap-ruby.git
Could not find gem 'appmap-ruby' in https://github.com/getappmap/appmap-ruby.git (at feat/enhanced-hook-logging@4af5645).

(Same messages if I use applandinc/appmap-ruby as in the PR instructions.)

Do you think it's something with my app or the branch?

kgilpin commented 1 year ago

That is weird. The gem name is definitely appmap:

https://github.com/getappmap/appmap-ruby/blob/master/appmap.gemspec#L10

Does bundle update appmap work?

clveranis commented 1 year ago

Nope, I get the same message when using bundle update appmap

fatal: Needed a single revision
Could not find gem 'appmap' in https://github.com/getappmap/appmap-ruby.git.

As a side note, I set bundle config disable_local_branch_check true default is false, otherwise I get:

clveranis@Charless-iMac link % bundle update appmap
Local override for appmap-ruby at /Users/clveranis/Dev/link is using branch master but Gemfile specifies feat/enhanced-hook-logging

kgilpin commented 1 year ago

Oh, do you have a local checkout of appmap-ruby?

kgilpin commented 1 year ago

Something funny must be going on with the combination of config options you have?

clveranis commented 1 year ago

Okay I figured it out, for some reason I had a "local override" set for that gem (not sure how that happened) but I was able to remove it via bundle config unset local.appmap and successfully install that branch, which works! Appmap seems to be working as expected now and I'm able to navigate through my app. Thank you!

What was the issue if you don't mind me asking?

kgilpin commented 1 year ago

I'm glad it's working! It took a lot of digging to come up with this solution.

Somehow, when AppMap enumerates the methods available on ActiveRecord, it's triggering some code behavior that eventually blanks out the table name on has_and_belongs_to_many relationships. There is a lot of complex code and metaprogramming in ActiveRecord, and to be honest I haven't yet gotten to the specific root cause of the problem. IMO, inspecting the available methods of a class or module should never change the behavior of that class or module...

When I figure it the specific root cause, I will come back here and leave another note :-)

kgilpin commented 1 year ago

Update - https://github.com/getappmap/appmap-ruby/pull/303 is pretty much finalized. Will merge when the build is green.

kgilpin commented 1 year ago

:tada: This issue has been resolved in version 0.95.0 :tada:

The release is available on:

v0.95.0
GitHub release

Your semantic-release bot :package::rocket:

clveranis commented 1 year ago

Awesome! Nice find! Thank you for all of your help to get this resolved promptly! Love the software and keep up the great work!

getappmap / appmap-ruby

Mysql2::Error: Incorrect table name '' - when using with Rails, Rolify, & CanCanCan #302