Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

Could not log "sql.active_record" event. NoMethodError: undefined method `type' for nil:NilClass #8806

Closed
yahonda opened this Issue · 7 comments

2 participants

@yahonda

Trying to find a testcase rsim/oracle-enhanced#134 and rsim/oracle-enhanced#252, I've found similar issue exists in rails master branch.

  • Tailing the debug.log.
$ cd activerecord
$ tail -f debug.log | grep sql.active_record
  • Execute this test
$ cd activerecord
$ ARCONN=postgresql ruby -Itest test/cases/adapters/postgresql/postgresql_adapter_test.rb -n test_exec_with_binds

Although, this test finishes successfully, debug.log shows this error message.

Could not log "sql.active_record" event. NoMethodError: undefined method `type' for nil:NilClass ["/home/yahonda/git/rails/activerecord/lib/active_record/log_subscriber.rb:24:in `render_bind'", "/home/yahonda/git/rails/activerecord/lib/active_record/log_subscriber.rb:47:in `block in sql'", "/home/yahonda/git/rails/activerecord/lib/active_record/log_subscriber.rb:46:in `map'", "/home/yahonda/git/rails/activerecord/lib/active_record/log_subscriber.rb:46:in `sql'", "/home/yahonda/git/rails/activesupport/lib/active_support/log_subscriber.rb:111:in `finish'", "/home/yahonda/git/rails/activesupport/lib/active_support/notifications/fanout.rb:89:in `finish'", "/home/yahonda/git/rails/activesupport/lib/active_support/notifications/fanout.rb:40:in `block in finish'", "/home/yahonda/git/rails/activesupport/lib/active_support/notifications/fanout.rb:40:in `each'", "/home/yahonda/git/rails/activesupport/lib/active_support/notifications/fanout.rb:40:in `finish'", "/home/yahonda/git/rails/activesupport/lib/active_support/notifications/instrumenter.rb:25:in `ensure in instrument'", "/home/yahonda/git/rails/activesupport/lib/active_support/notifications/instrumenter.rb:25:in `instrument'", "/home/yahonda/git/rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:299:in `log'", "/home/yahonda/git/rails/activerecord/lib/active_record/connection_adapters/postgresql/database_statements.rb:137:in `exec_query'", "test/cases/adapters/postgresql/postgresql_adapter_test.rb:182:in `test_exec_with_binds'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:1294:in `run'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:912:in `block in _run_suite'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:905:in `map'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:905:in `_run_suite'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:892:in `block in _run_suites'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:892:in `map'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:892:in `_run_suites'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:860:in `_run_anything'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:1053:in `run_tests'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:1040:in `block in _run'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:1039:in `each'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:1039:in `_run'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:1028:in `run'", "/home/yahonda/.rvm/gems/ruby-1.9.3-p362@railsmaster/gems/minitest-4.3.3/lib/minitest/unit.rb:782:in `block in autorun'"]

This 'Could not log "sql.active_record" event. NoMethodError: undefined method `type' for nil:NilClass' also appears with following testcases.

$ ARCONN=mysql ruby -Itest test/cases/adapters/mysql/connection_test.rb -n test_exec_with_binds
$ ARCONN=postgresql ruby -Itest test/cases/adapters/postgresql/postgresql_adapter_test.rb -n test_exec_with_binds
$ ARCONN=postgresql ruby -Itest test/cases/adapters/postgresql/schema_authorization_test.rb -n test_auth_with_bind
$ ARCONN=postgresql ruby -Itest test/cases/adapters/postgresql/schema_authorization_test.rb -n test_setting_auth_clears_stmt_cache
$ ARCONN=postgresql ruby -Itest test/cases/adapters/postgresql/schema_test.rb -n test_schema_change_with_prepared_stmt
@carlosantoniodasilva

This happens because those tests are calling exec_query passing binds in the format of [nil, value], where nil should be the column information. I'm taking a look into ignoring the binds column if it's not present, hopefully it'll fix it.

@carlosantoniodasilva carlosantoniodasilva closed this issue from a commit
@carlosantoniodasilva carlosantoniodasilva Ignore binds payload with nil column in AR log subscriber
Some tests were raising the following error:

    Could not log "sql.active_record" event. NoMethodError: undefined method
    `type' for nil:NilClass`

Due to the way binds were being logged, the column info was considered
always present, but that is not true for some of the tests listed in the
issue.

Closes #8806.
77516a7
@carlosantoniodasilva

@yahonda done, please let me know if that works for you or if there's anything else to be fixed. Thanks.

@yahonda

@carlosantoniodasilva Thanks! 77516a7 resolves my issues at the master branch.
Would you consider to backport this fix to 3-2-stable? Because the original issue at oracle enhanced adapter is reported in lower version of Rails. I understand cherry-pick 77516a7 conflicts with 3-2-stable though.

@carlosantoniodasilva

@yahonda I think it's fine to backport the change to 3-2-stable. The conflicts are related to the addition of the column.binary? check to master, and probably to the hash style changes. If you want to go ahead with a pull request cherry-picking and fixing any conflicts, please feel free, otherwise I can try to take a look at this later.

@yahonda

@carlosantoniodasilva Let me try to make a backport. Will open a pull request. Thanks.

@carlosantoniodasilva

Ok, great.

@yahonda yahonda referenced this issue from a commit
Commit has since been removed from the repository and is no longer available.
@yahonda yahonda referenced this issue from a commit in yahonda/rails
@yahonda yahonda Ignore binds payload with nil column in AR log subscriber
Some tests were raising the following error:

    Could not log "sql.active_record" event. NoMethodError: undefined method
    `type' for nil:NilClass`

Due to the way binds were being logged, the column info was considered
always present, but that is not true for some of the tests listed in the
issue.

Closes #8806.

Conflicts:

	activerecord/lib/active_record/log_subscriber.rb
	activerecord/test/cases/log_subscriber_test.rb

Conflict resolution:
- Revert ruby 1.9 style hash to support ruby 1.8
- Do not include 8f59ffc into 3-2-stable
3d1a879
@yahonda

Opened #8838 for 3-2-stable, which still has 2 regressions though.

@parameme parameme referenced this issue in dejan/rails_panel
Closed

SystemStackError (stack level too deep) #34

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.