extension to instrument SQL statements - execute_insert is seemingly not called?

[davetron5000]

Trying to add some basic instrumentation in my app and I could not find solid docs on what an extension is/can do, so I'm referencing https://github.com/signalfx/ruby-sequel-instrumentation/. Here is a simplified version:

module Sequel
  module Extensions
    module MyInstrumentation
      def execute(sql, opts = Sequel::OPTS, &block)
        puts "execute"
        super
      end
      def execute_dui(sql, opts = Sequel::OPTS, &block)
        puts "execute_dui"
        super
      end
      def execute_insert(sql, opts = Sequel::OPTS, &block)
        puts "execute_insert"
        super
      end
    end
  end
  Sequel::Dataset.register_extension(:my_instrumentation, Sequel::Extensions::BrutInstrumentation)
end

It is registered like so:

Sequel::Database.extension :my_instrumentation

a SELECT causes "execute" to be printed and UPDATE causes "execute_dui" to be printed. INSERT, however does not trigger anything. The insert does happen, however the methods in my extension aren't called.

This leads me to believe I'm doing something wrong and any expected behavior is incidental.

Anyone know what I'm missing or what I need to do differently?

Sequel 5.86.0
Postgres server 16.1 (Debian 16.1-1.pgdg120+1))
Ruby 3.3.5

[jeremyevans]

PostgreSQL uses INSERT RETURNING, so you want to override returning_fetch_rows in addition to the methods you are overriding.

[davetron5000]

I see the method in the source code, but when I override it, it's not called (the INSERT still happens though). Looking through actions.rb I'm wondering if there is something I'm doing that's weird.

Here is more context around how I'm setting it up (still somewhat simplified and shown as inline, but this is the basic order of operations):

Sequel::Database.extension :pg_array
Sequel::Database.extension :my_instrumentation

sequel_db = Sequel.connect(ENV["DATABASE_URL"])
sequel_db.logger = SemanticLogger["Sequel::Database"]
Sequel::Model.db = sequel_db

model = SomeModel.new
model.update(some_attributes) # this triggers the INSERT

[jeremyevans]

When using models, which want all column values and not just the primary key values after INSERT, Dataset#insert_select is used if available. So that's what you want to override. This is an adapter-specific method, and not all adapters support it.

[davetron5000]

OK, that worked, thanks! Is there a good way to know what are all the methods I might want to override? Or is there a different level at which I should be doing this?

[janko]

Have you considered hooking onto log_connection_yield? This is what I've done in sequel-activerecord_connection, and it seems to be reliable.

[davetron5000]

I can't tell what the method does - is it just wrapping every call for the purposes of logging? Can it be disabled inadvertently?

[janko]

Yes, it wraps every SQL statement with added logging. It's the only Sequel method I know that's consistently called for every SQL statement, so it might be more reliable than overriding execute_* methods.

Can it be disabled inadvertently?

Not sure I understand the question.

[davetron5000]

Can it be disabled inadvertently?

Not sure I understand the question.

Is there some Sequel setting that "turns off" this logging feature such that the method would no longer be called?

[janko]

No, the method is a no-op if logger is unset, but it will still be called.

[adam12]

Another hook could be log_duration. It's the one I use for roda-enhanced_logger.

[davetron5000]

Cool log_connection_yield worked, but I had to register_extension on Sequel::Database (which I guess makes sense since that's where it's defined :)