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.

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

AppSignal gem throws errors when running sequel migrations #91

Closed
tombruijn opened this issue Jan 22, 2016 · 4 comments

Comments

Projects
None yet
2 participants
@tombruijn
Copy link
Member

commented Jan 22, 2016

When running migrations with with sequel log level set to debug (in the Rails config: Rails.application.config.log_level = :debug) every migration throws an error.

bundle exec rake db:migrate:reset

This runs normally until migrating and then for every query it throws this error:

Could not log "sql.sequel" event. NoMethodError: undefined method `squeeze' for nil:NilClass
["/Users/tom/.gem/ruby/2.3.0/gems/sequel-rails-0.9.12/lib/sequel_rails/railties/log_subscriber.rb:40:in `sql'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/subscriber.rb:100:in `finish'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/log_subscriber.rb:83:in `finish'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications/fanout.rb:102:in `finish'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications/fanout.rb:46:in `block in finish'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications/fanout.rb:46:in `each'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications/fanout.rb:46:in `finish'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications/instrumenter.rb:36:in `finish'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications/instrumenter.rb:25:in `instrument'",
"/Users/tom/.gem/ruby/2.3.0/gems/activesupport-4.2.4/lib/active_support/notifications.rb:164:in `instrument'",
"/Users/tom/.gem/ruby/2.3.0/gems/appsignal-1.0.1/lib/appsignal/hooks/sequel.rb:12:in `log_yield'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:184:in `execute_query'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:171:in `block in execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:147:in `check_disconnect_errors'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:171:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:524:in `_execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:340:in `block (2 levels) in execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:545:in `check_database_errors'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:340:in `block in execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/database/connecting.rb:249:in `block in synchronize'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/connection_pool/threaded.rb:103:in `hold'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/database/connecting.rb:249:in `synchronize'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:340:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/dataset/actions.rb:950:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/postgres.rb:668:in `fetch_rows'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/dataset/actions.rb:139:in `each'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/adapters/shared/postgres.rb:330:in `foreign_key_list'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/extensions/schema_dumper.rb:255:in `dump_table_generator'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/extensions/schema_dumper.rb:144:in `dump_table_schema'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/extensions/schema_dumper.rb:134:in `block in dump_schema_migration'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/extensions/schema_dumper.rb:134:in `map'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-4.30.0/lib/sequel/extensions/schema_dumper.rb:134:in `dump_schema_migration'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-rails-0.9.12/lib/sequel_rails/railties/database.rake:26:in `block (4 levels) in <top (required)>'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-rails-0.9.12/lib/sequel_rails/railties/database.rake:25:in `open'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-rails-0.9.12/lib/sequel_rails/railties/database.rake:25:in `block (3 levels) in <top (required)>'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:240:in `block in execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:235:in `each'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:235:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/appsignal-1.0.1/lib/appsignal/hooks/rake.rb:15:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:179:in `block in invoke_with_call_chain'",
"/Users/tom/.rubies/ruby-2.3.0/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:172:in `invoke_with_call_chain'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:165:in `invoke'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-rails-0.9.12/lib/sequel_rails/railties/database.rake:75:in `block (2 levels) in <top (required)>'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:240:in `block in execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:235:in `each'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:235:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/appsignal-1.0.1/lib/appsignal/hooks/rake.rb:15:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:179:in `block in invoke_with_call_chain'",
"/Users/tom/.rubies/ruby-2.3.0/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:172:in `invoke_with_call_chain'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:165:in `invoke'",
"/Users/tom/.gem/ruby/2.3.0/gems/sequel-rails-0.9.12/lib/sequel_rails/railties/database.rake:165:in `block (2 levels) in <top (required)>'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:240:in `block in execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:235:in `each'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:235:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/appsignal-1.0.1/lib/appsignal/hooks/rake.rb:15:in `execute'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:179:in `block in invoke_with_call_chain'",
"/Users/tom/.rubies/ruby-2.3.0/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:172:in `invoke_with_call_chain'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/task.rb:165:in `invoke'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:150:in `invoke_task'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:106:in `block (2 levels) in top_level'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:106:in `each'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:106:in `block in top_level'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:115:in `run_with_threads'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:100:in `top_level'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:78:in `block in run'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:176:in `standard_exception_handling'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/lib/rake/application.rb:75:in `run'",
"/Users/tom/.gem/ruby/2.3.0/gems/rake-10.5.0/bin/rake:33:in `<top (required)>'",
"/Users/tom/.gem/ruby/2.3.0/bin/rake:23:in `load'",
"/Users/tom/.gem/ruby/2.3.0/bin/rake:23:in `<main>'"]

slightly formatted for readability

AppSignal gem version that works: 0.11.8
It doesn't work anymore with the latest: 1.0.1

Sequel gem version: 4.30.0
Sequel-rails gem version: 0.9.12

A quick look make me think this is the commit that broke it: f0f00b4#diff-dc2ceb9af0184cfe8b1141877ccc41e3L6

The payload is lost in appsignal as the commit removes it from the instrument call, but sequel-rails still depends on it to show it in the logs.

This is the line in sequel-rails why it only happens in debug: https://github.com/TalentBox/sequel-rails/blob/ad1a51b3ee45f90c99e28413bcc9d45c1eaf2eb8/lib/sequel_rails/railties/log_subscriber.rb#L35

Let me know if you need more information!

@matsimitsu

This comment has been minimized.

Copy link
Member

commented Jan 26, 2016

It seems sequel-rails already has instrumentation. Could you try and disable our sequel instrumentation and see what the result is?

in config.yaml:

instrument_sequel: false

@matsimitsu matsimitsu self-assigned this Jan 26, 2016

@tombruijn

This comment has been minimized.

Copy link
Member Author

commented Jan 26, 2016

When disabling the instrumentation sequel-rails doesn't seem to throw any errors anymore, but since this disables the instrumentation for sequel we can't see queries in appsignal anymore, right?

@matsimitsu

This comment has been minimized.

Copy link
Member

commented Jan 26, 2016

sequel-rails seems to have built-in instrumentation: https://github.com/TalentBox/sequel-rails/blob/89e71cc58ea44ccc85e9c30b7fb55889d36c0287/lib/sequel_rails/sequel/database/active_support_notification.rb

so that should generate the instrumentation (it's pretty much the same code as appsignal's instrumentation)

@tombruijn

This comment has been minimized.

Copy link
Member Author

commented Jan 26, 2016

oooh... That's actually quite nice then. (Although I don't like it being a monkey patch for sequel.)

So if we rely on this we don't need to activate appsignal's instrumentation.
We'll try running it and let you know if we have any other issues concerning this.

@tombruijn tombruijn closed this Jan 26, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.