Appending custom formatted sql logs and using async

[firstpromoter]

We don't need the SELECT logs so we're excluding them and also format active_record sql logs as JSON like this:

class QueryLogger
  def call(_name, _started, _finished, _unique_id, payload)
    query = payload[:sql]
    rd = payload[:binds]
    data = []
    if rd.is_a?(Array)
      rd.each do |x|
        data << [x.name, x.value.to_s]
      end
    end

    qs = query.strip
    qs = qs.start_with?('SELECT', 'BEGIN', 'COMMIT', 'SHOW')
    unless qs
      Thread.current[:sql_q] ||= []
      Thread.current[:sql_q] << { squ: query, squ_data: data } if data.present?
    end
  end
end

ActiveSupport::Notifications.subscribe('sql.active_record', QueryLogger.new)

than we add it to the logger like this:

  Rails.application.configure do
    formatter = proc do |log, logger|
...
      sql = Thread.current[:sql_q].dup
      Thread.current[:sql_q] = nil
...
 end
...
    SemanticLogger.sync!
    SemanticLogger.add_appender(
      appender: :http,
      url: ..
      header:...
      formatter: formatter)
end

The main problem is that we are forced to use "sync!" mode which slows down the application using this approach. Since threads are different when using the default async mode, AR sql logs that we formatted and stored inside Thread.current is empty when log is processed.

Do you have any idea on how to pass those AR sql logs to the logger, but keeping async mode activated?

[reidmorrison]

There appear to be 2 requirements here:

1. Convert the binds array up into name value pairs.
2. Stop sending select SQL queries from the logs.

For #1, this sounds like it could be a feature that everyone one could use, since the purpose of Semantic Logging is to convert text output into Semantic, or Hash form.
Consider submitting a pull request to break down the binds in the following code:
https://github.com/reidmorrison/rails_semantic_logger/blob/master/lib/rails_semantic_logger/active_record/log_subscriber.rb#L33

Note though that just about every version of rails returns the bind values differently, so custom handling is implemented for every supported version of Rails.

For #2 there are 2 options, we could add a configurable option to allow anyone to disable logging of select queries, in this module:
https://github.com/reidmorrison/rails_semantic_logger/blob/master/lib/rails_semantic_logger/active_record/log_subscriber.rb

Alternatively, to keep it as a custom implementation, add a filter to the logger that is used here:
https://github.com/reidmorrison/rails_semantic_logger/blob/master/lib/rails_semantic_logger/active_record/log_subscriber.rb#L7

The filter proc will receive the entire log structure, can modify it as needed, or in this case just return false to not log anything.
https://logger.rocketjob.io/filtering.html

Without running the actual code, it would be something like:

RailsSemanticLogger::ActiveRecord::LogSubscriber.logger.filter = -> log { ! log.payload[:sql].start_with?('SELECT', 'BEGIN', 'COMMIT', 'SHOW') }

To build out the proc, display the log struct contents to help build out what the code should look like. Also add handling for the case where the payload[:sql] is nil.

It is also possible to modify the log struct inside the filter to break apart the binds, although this would be a useful feature for all users of Rails Semantic Logger.