Class: RailsSemanticLogger::ActionController::LogSubscriber

Inherits:
ActiveSupport::LogSubscriber
  • Object
show all
Defined in:
lib/rails_semantic_logger/action_controller/log_subscriber.rb

Constant Summary collapse

INTERNAL_PARAMS = 
%w[controller action format _method only_path].freeze

Class Attribute Summary collapse

Instance Method Summary collapse

Class Attribute Details

.action_message_format ⇒ Object

Returns the value of attribute action_message_format.



18
19
20
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 18

def action_message_format
  @action_message_format
end

.processing_log_level ⇒ Object

Returns the value of attribute processing_log_level.



18
19
20
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 18

def processing_log_level
  @processing_log_level
end

Instance Method Details

#halted_callback(event) ⇒ Object 



94
95
96
97
98
99
100
101
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 94

def halted_callback(event)
  controller_logger(event).info do
    {
      message: "Filter chain halted as #{event.payload[:filter].inspect} rendered or redirected",
      metric:  "rails.controller.halted_callback"
    }
  end
end

#process_action(event) ⇒ Object 



29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 29

def process_action(event)
  controller_logger(event).info do
    # `event.payload` is shared with every other subscriber on this notification, so we work on
    # a copy. A shallow `dup` is sufficient: only mutate `payload` via top-level key reassignment
    # (e.g. `payload[:format] = ...`) or by writing into a freshly-created hash (e.g. the `.except`
    # result below). Never mutate a nested object that still belongs to the original payload
    # (e.g. `payload[:foo][:bar] = ...` on an unduped key), or the change will leak back into the
    # shared payload and corrupt what other subscribers see.
    payload = event.payload.dup

    # Unused, but needed for Devise 401 status code monkey patch to still work.
    ::ActionController::Base.log_process_action(payload)

    params = payload[:params]

    if params.is_a?(Hash) || params.is_a?(::ActionController::Parameters)
      # According to PR https://github.com/reidmorrison/rails_semantic_logger/pull/37/files
      # params is not always a Hash.
      payload[:params] = params.to_unsafe_h unless params.is_a?(Hash)
      payload[:params] = params.except(*INTERNAL_PARAMS)

      if payload[:params].empty?
        payload.delete(:params)
      elsif params["file"]
        # When logging to JSON the entire tempfile is logged, so convert it to a string.
        payload[:params]["file"] = params["file"].inspect
      end
    end

    format           = payload[:format]
    payload[:format] = format.to_s.upcase if format.is_a?(Symbol)

    payload[:path]   = extract_path(payload[:path]) if payload.key?(:path)

    exception = payload.delete(:exception)
    if payload[:status].nil? && exception.present?
      exception_class_name = exception.first
      payload[:status]     = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
    end

    # Rounds off the runtimes. For example, :view_runtime, :mongo_runtime, etc.
    payload.keys.each do |key|
      payload[key] = payload[key].to_f.round(2) if key.to_s =~ /(.*)_runtime/
    end

    payload[:allocations] = event.allocations
    payload[:cpu_time]    = event.cpu_time.round(2)
    payload[:idle_time]   = event.idle_time.round(2)
    payload[:gc_time]     = event.gc_time.round(2) if event.respond_to?(:gc_time)

    payload[:status_message] = ::Rack::Utils::HTTP_STATUS_CODES[payload[:status]] if payload[:status].present?

    payload.delete(:headers)
    payload.delete(:request)
    payload.delete(:response)

    {
      message:  action_message("Completed", event.payload),
      duration: event.duration,
      payload:  payload,
      metric:   "rails.controller.process_action"
    }
  end
end

#redirect_to(event) ⇒ Object 



130
131
132
133
134
135
136
137
138
139
140
141
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 130

def redirect_to(event)
  payload = {location: event.payload[:location]}

  # Rails 8.1+ optionally logs the source location of the redirect when
  # ActionDispatch.verbose_redirect_logs is enabled.
  if ActionDispatch.respond_to?(:verbose_redirect_logs) && ActionDispatch.verbose_redirect_logs
    source           = redirect_source_location
    payload[:source] = source if source
  end

  controller_logger(event).info(message: "Redirected to", payload: payload, metric: "rails.controller.redirect_to")
end

#rescue_from_callback(event) ⇒ Object

Rails 8.1+ emits this event when an exception is handled by a rescue_from callback. On earlier Rails versions the event is never instrumented, so this handler is dormant.



105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 105

def rescue_from_callback(event)
  controller_logger(event).info do
    exception = event.payload[:exception]
    backtrace = exception.backtrace&.first
    backtrace = backtrace&.delete_prefix("#{Rails.root}/") if defined?(Rails.root) && Rails.root

    {
      message: "rescue_from handled #{exception.class}",
      payload: {
        exception:         exception.class.name,
        exception_message: exception.message,
        backtrace:         backtrace
      },
      metric:  "rails.controller.rescue_from_callback"
    }
  end
end

#send_data(event) ⇒ Object 



143
144
145
146
147
148
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 143

def send_data(event)
  controller_logger(event).info(message:  "Sent data",
                                payload:  {file_name: event.payload[:filename]},
                                duration: event.duration,
                                metric:   "rails.controller.send_data")
end

#send_file(event) ⇒ Object 



123
124
125
126
127
128
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 123

def send_file(event)
  controller_logger(event).info(message:  "Sent file",
                                payload:  {path: event.payload[:path]},
                                duration: event.duration,
                                metric:   "rails.controller.send_file")
end

#start_processing(event) ⇒ Object 



25
26
27
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 25

def start_processing(event)
  controller_logger(event).send(self.class.processing_log_level) { action_message("Processing", event.payload) }
end

#unpermitted_parameters(event) ⇒ Object 



150
151
152
153
154
155
156
157
158
159
160
161
162
 
# File 'lib/rails_semantic_logger/action_controller/log_subscriber.rb', line 150

def unpermitted_parameters(event)
  controller_logger(event).debug do
    unpermitted_keys = event.payload[:keys]
    payload          = {keys: unpermitted_keys}
    # Rails includes the controller/action context alongside the rejected keys.
    payload[:context] = event.payload[:context] if event.payload[:context]

    {
      message: "Unpermitted parameter#{'s' if unpermitted_keys.size > 1}: #{unpermitted_keys.join(', ')}",
      payload: payload
    }
  end
end