module Semantic module Subscribers # LogSubscriber for event_group :active_record class ActiveRecord < LogSubscriber include AnsiColors IGNORE_PAYLOAD_NAMES = %w[SCHEMA EXPLAIN].freeze TRANSACTION_TAINT = AnsiColors::DARK_TEXT_CYAN def sql(event) name = event.payload[:name] if name.nil? logger.debug ' ', dimensions: Semantic::FancyDimensions.new(rails: '╔═╗', before: 1) logger.debug 'could be a migration running by...', event.payload[:sql] Rails.logger.info ' ', dimensions: Semantic::FancyDimensions.new(rails: '╚═╝') return end return if IGNORE_PAYLOAD_NAMES.include?(name) category, model, *remaining = name.split.reverse return if category == 'TRANSACTION' statement_taint = TEXT_BLUE case category when 'Count' name = "#{category} #{model}" when 'Load' if event.payload[:cached] statement_taint = TEXT_GRAY_300 name = "Cache Read #{model}" no_stats = true elsif model == ::ActiveRecord::SchemaMigration.to_s category_taint = TEXT_MAGENTA name = 'Migration required' logger.debug ' ', dimensions: Semantic::FancyDimensions.new(rails: '╔═╗', before: 1) else row_count = event.payload[:row_count] name = "Read #{row_count} #{model.pluralize(row_count)}" end when 'Update', 'Create', 'Destroy' statement_taint = TEXT__PINK name = "#{category} #{model}" category_taint = TRANSACTION_TAINT increment_transaction_local(event.payload[:transaction].uuid, category.downcase.to_sym, event.duration) else raise "unknown sql category: <#{category}>" end name = "#{name} #{stats_event(event.duration)}" unless no_stats name = "#{name} #{remaining.join(' ')}" if remaining.any? name = colorize(name, category_taint) if category_taint statement = colorize(pretty_binded_statement(event), statement_taint) logger.debug("#{name} #{statement}") end def start_transaction(_event) logger.info(colorize('Begin', TRANSACTION_TAINT)) end def transaction(event) outcome = colorize(event.payload[:outcome].capitalize, TRANSACTION_TAINT) transaction = event.payload[:transaction] summary = transaction_summary(transaction) stats = stats_event(event.duration - transaction_internal_duration(transaction)) logger.info("#{outcome} #{summary} #{stats}") end def instantiation(event); end def strict_loading_violation(event) = any_hook event private def pretty_binded_statement(event) statement = event.payload[:sql].dup bounds = event .payload[:binds] .select { |item| item.is_a?(::ActiveModel::Attribute) } .map(&:value) return statement if bounds.empty? bounds.map { |b| boolean_or_numeric?(b) ? b.to_s : "'#{b}'" } .each_with_index { |sb, index| statement.gsub!("$#{index + 1}", sb) } statement.gsub!(/ LIMIT 1$/, '') # LIMIT 1 is useless! statement rescue StandardError => e logger.debug event.payload[:binds] logger.error 'an error occured during pretty binded statement', e end def boolean_or_numeric?(value) = value.is_a?(Numeric) || value.is_a?(TrueClass) || value.is_a?(FalseClass) def stats_event(duration)= colorize("(#{number_to_ms(duration)})", TEXT_GRAY_400) def number_to_ms(number) = "#{::ActionController::Base.helpers.number_with_precision(number, precision: 1)}ms" def transaction_internal_duration(transaction) = transaction_local(transaction.uuid)[:total_duration] def transaction_summary(transaction) transaction_local(transaction.uuid) .except(:total_duration) .select { |_, value| value.positive? } .map { |k, v| "#{v} #{k.to_s.pluralize(v)}" } .join(',') end def increment_transaction_local(transaction_id, sql_command, duration) transaction_local(transaction_id)[sql_command] += 1 transaction_local(transaction_id)[:total_duration] += duration end def thread_local = Thread.current[self.class.to_s] ||= {} def transaction_local(transaction_id) thread_local[transaction_id] ||= { update: 0, create: 0, destroy: 0, total_duration: 0 } end end end end