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.

Sign up for GitHub

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

Jump to bottom

Queries with "binds" cause NoMethodError #17

Open
charlesobrien opened this issue Oct 7, 2023 · 7 comments
Open

Queries with "binds" cause NoMethodError #17

charlesobrien opened this issue Oct 7, 2023 · 7 comments

Comments

@charlesobrien
Copy link

I was playing around with Signalman -- specifically to log and visualize queries in development. Unfortunately, noticed that some queries weren't being logged; in my particular case, I first noticed it with UPDATES.

After some fiddling, it appears that "binds" are not being serialized to JSON when the event is being created.

My interim solution was to update the process method in QueryHandler to:

def process
    create_event event.payload.except(:binds, :connection)
end

Happy to submit a pull request to make this change (and remove binds from the UI) -- but I honestly wasn't sure if this was just the brute force solution to the problem (rather than the right solution).
@excid3
Copy link
Owner

excid3 commented Oct 10, 2023

Were the binds causing it to raise an error which is why they weren't logged?

@charlesobrien
Copy link
Author

@excid3 Affirm. As far as I could tell, any query that included objects in the "binds" array returned in the payload would throw an Internal Server Error/NoMethodError. Surprisingly, there was no detail provided on what method was missing -- from my fiddling my assumption would be whatever method would be serializing the binds objects to JSON.

@excid3
Copy link
Owner

excid3 commented Oct 10, 2023

It's easy to get into infinite loops with this stuff, so we've had to strip out a few things like the :connection but I think binds is pretty important to keep if we can find a way to do it.

Do you have a test case that we can use?

@charlesobrien
Copy link
Author

@excid3 Sure, I can provide a sample application. I'll put a comment here with a link (likely will be tomorrow).

@excid3
Copy link
Owner

excid3 commented Oct 10, 2023

We've got the test/dummy Rails app that you can use. Would just need a query that simulates the issue and it'll be easiest to replicate it into the test suite.

@charlesobrien
Copy link
Author

charlesobrien commented Oct 10, 2023 •
edited
Loading

@excid3 I can reproduce using the existing User model in the dummy app. However, I did discover it only occurs on > Rails 7.1; does not happen on Rails 7.0

The first two tests will fail on Rails 7.1. With :binds excluded, they both pass.

require "test_helper"

class UserTest < ActiveSupport::TestCase
  test 'should create a valid user' do
    user = User.new(name: 'Test User', email: '[email protected]')
    assert user.save
  end

  test 'should retrieve user' do
    assert_nothing_raised do
      User.find_by(email: "[email protected]")
    end
  end

  test 'should retrieve all users' do
    assert_nothing_raised do
      User.all
    end
  end
end

The results:

E

Error:
UserTest#test_should_retrieve_user:
NoMethodError: NoMethodError
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/type/value.rb:145:in `as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:188:in `block in as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:187:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:187:in `as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:63:in `as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:86:in `jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:84:in `block in jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:84:in `map'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:84:in `jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:80:in `block in jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:78:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:78:in `jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:41:in `encode'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:23:in `encode'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/type/json.rb:18:in `serialize'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/type/helpers/mutable.rb:8:in `cast'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute.rb:199:in `type_cast'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute.rb:43:in `value'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute_set.rb:51:in `fetch_value'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:421:in `block in restore_transaction_record_state'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute_set.rb:98:in `transform_values'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute_set.rb:98:in `map'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:420:in `restore_transaction_record_state'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:345:in `rolledback!'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:200:in `block in rollback_records'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:263:in `run_action_on_records'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:199:in `rollback_records'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:527:in `block in rollback_transaction'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `block in synchronize'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:520:in `rollback_transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:539:in `rescue in block in within_new_transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:538:in `block in within_new_transaction'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `block in synchronize'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:532:in `within_new_transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/database_statements.rb:342:in `transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:361:in `with_transaction_returning_status'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:309:in `save'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/suppressor.rb:52:in `save'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/persistence.rb:38:in `create'
    /workspaces/signalman/lib/signalman/base_handler.rb:29:in `create_event'
    /workspaces/signalman/lib/signalman/query_handler.rb:20:in `process'
    /workspaces/signalman/lib/signalman/base_handler.rb:15:in `start'
    /workspaces/signalman/lib/signalman/base_handler.rb:7:in `call'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:177:in `block in finish'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:25:in `block in iterate_guarding_exceptions'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:24:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:24:in `iterate_guarding_exceptions'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:121:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:176:in `finish'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:256:in `block in finish_with_values'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:255:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:255:in `finish_with_values'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/fanout.rb:248:in `finish'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/notifications/instrumenter.rb:64:in `instrument'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract_adapter.rb:1134:in `log'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/sqlite3/database_statements.rb:32:in `internal_exec_query'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/database_statements.rb:628:in `select'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/database_statements.rb:71:in `select_all'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/query_cache.rb:111:in `block in select_all'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/query_cache.rb:151:in `block in cache_sql'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `block in synchronize'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/query_cache.rb:146:in `cache_sql'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/query_cache.rb:111:in `select_all'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/querying.rb:62:in `_query_by_sql'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/querying.rb:51:in `find_by_sql'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/statement_cache.rb:150:in `execute'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/core.rb:409:in `cached_find_by'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/core.rb:284:in `find_by'
    /workspaces/signalman/test/models/user_test.rb:11:in `block (2 levels) in <class:UserTest>'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/testing/assertions.rb:49:in `assert_nothing_raised'
    /workspaces/signalman/test/models/user_test.rb:10:in `block in <class:UserTest>'


bin/rails test test/models/user_test.rb:9

E

Error:
UserTest#test_should_create_a_valid_user:
NoMethodError: NoMethodError
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/type/value.rb:145:in `as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:188:in `block in as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:187:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:187:in `as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/core_ext/object/json.rb:63:in `as_json'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:86:in `jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:84:in `block in jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:84:in `map'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:84:in `jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:80:in `block in jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:78:in `each'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:78:in `jsonify'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:41:in `encode'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/json/encoding.rb:23:in `encode'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/type/json.rb:18:in `serialize'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/type/helpers/mutable.rb:8:in `cast'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute.rb:199:in `type_cast'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute.rb:43:in `value'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute_set.rb:51:in `fetch_value'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:421:in `block in restore_transaction_record_state'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute_set.rb:98:in `transform_values'
    /usr/local/rvm/gems/default/gems/activemodel-7.1.0/lib/active_model/attribute_set.rb:98:in `map'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:420:in `restore_transaction_record_state'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:345:in `rolledback!'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:200:in `block in rollback_records'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:263:in `run_action_on_records'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:199:in `rollback_records'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:527:in `block in rollback_transaction'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `block in synchronize'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:520:in `rollback_transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:539:in `rescue in block in within_new_transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:538:in `block in within_new_transaction'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `block in synchronize'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
    /usr/local/rvm/gems/default/gems/activesupport-7.1.0/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/transaction.rb:532:in `within_new_transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/connection_adapters/abstract/database_statements.rb:342:in `transaction'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:361:in `with_transaction_returning_status'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/transactions.rb:309:in `save'
    /usr/local/rvm/gems/default/gems/activerecord-7.1.0/lib/active_record/suppressor.rb:52:in `save'
    /workspaces/signalman/test/models/user_test.rb:6:in `block in <class:UserTest>'

@excid3
Copy link
Owner

excid3 commented Oct 11, 2023

Great, thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@excid3 @charlesobrien