Class: Metrician::Middleware::RequestTiming

Inherits:
Object
  • Object
show all
Defined in:
lib/metrician/middleware/request_timing.rb

Overview

RequestTiming and ApplicationTiming work in concert to time the middleware separate from the request processing. RequestTiming should be the first or near first middleware loaded since it will be timing from the moment the the app server is hit and setting up the env for tracking the middleware execution time. RequestTiming should be the last or near last middleware loaded as it times the application execution (separate from middleware).

Constant Summary collapse

WEB_METRIC = 
"web".freeze

Class Method Summary collapse

Instance Method Summary collapse

Constructor Details

#initialize(app) ⇒ RequestTiming

Returns a new instance of RequestTiming.



14
15
16
 
# File 'lib/metrician/middleware/request_timing.rb', line 14

def initialize(app)
  @app = app
end

Class Method Details

.define_queue_start_marker(env) ⇒ Object 



129
130
131
132
133
134
 
# File 'lib/metrician/middleware/request_timing.rb', line 129

def self.define_queue_start_marker(env)
  @queue_start_marker = ENV_QUEUE_START_KEYS.detect do |key|
    env.keys.include?(key)
  end
  @no_queue_start_marker = @queue_start_marker.nil?
end

.extract_request_start_time(env) ⇒ Object 



111
112
113
114
115
116
117
118
119
 
# File 'lib/metrician/middleware/request_timing.rb', line 111

def self.extract_request_start_time(env)
  return if no_queue_start_marker?
  unless queue_start_marker
    define_queue_start_marker(env)
  end
  return if no_queue_start_marker?
  result = env[queue_start_marker].to_f
  result > 1_000_000_000 ? result : nil
end

.extract_route(controller:, path:) ⇒ Object 



136
137
138
139
140
141
142
143
144
145
 
# File 'lib/metrician/middleware/request_timing.rb', line 136

def self.extract_route(controller:, path:)
  unless controller
    return ASSET_CONTROLLER_ROUTE if path =~ ASSET_PATH_MATCHER
    return UNKNOWN_CONTROLLER_ROUTE
  end
  controller_name = Metrician.dotify(controller.class)
  action_name     = controller.action_name.blank? ? UNKNOWN_ACTION : controller.action_name
  method_name     = controller.request.request_method.to_s
  "#{controller_name}.#{action_name}.#{method_name}".downcase
end

.get_response_size(headers:, body:) ⇒ Object 



147
148
149
150
 
# File 'lib/metrician/middleware/request_timing.rb', line 147

def self.get_response_size(headers:, body:)
  return headers[HEADER_CONTENT_LENGTH] if headers && headers[HEADER_CONTENT_LENGTH]
  body.first.length.to_s if body.respond_to?(:length) && body.length == 1
end

.no_queue_start_marker? ⇒ Boolean

Returns:

  • (Boolean) 


121
122
123
 
# File 'lib/metrician/middleware/request_timing.rb', line 121

def self.no_queue_start_marker?
  @no_queue_start_marker
end

.queue_start_marker ⇒ Object 



125
126
127
 
# File 'lib/metrician/middleware/request_timing.rb', line 125

def self.queue_start_marker
  @queue_start_marker
end

Instance Method Details

#apdex(request_time) ⇒ Object 



97
98
99
100
101
102
103
104
105
106
107
108
109
 
# File 'lib/metrician/middleware/request_timing.rb', line 97

def apdex(request_time)
  satisfied_threshold = Middleware.configuration[:apdex][:satisfied_threshold]
  tolerated_threshold = satisfied_threshold * 4

  case
  when request_time <= satisfied_threshold
    Metrician.gauge(APDEX_SATISFIED_METRIC, request_time)
  when request_time <= tolerated_threshold
    Metrician.gauge(APDEX_TOLERATED_METRIC, request_time)
  else
    Metrician.gauge(APDEX_FRUSTRATED_METRIC, request_time)
  end
end

#call(env) ⇒ Object 



18
19
20
21
22
23
24
25
26
27
28
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
 
# File 'lib/metrician/middleware/request_timing.rb', line 18

def call(env)
  process_start_time = Time.now.to_f
  response_size = 0

  if Middleware.queue_time?
    queue_start_time = self.class.extract_request_start_time(env)
    gauge(:queue_time, process_start_time - queue_start_time) if queue_start_time
  end

  if Middleware.idle?
    if @request_end_time
      gauge(:idle, process_start_time - @request_end_time)
      @request_end_time = nil
    end
  end

  begin
    status, headers, body = @app.call(env)
    [status, headers, body]
  ensure
    if need_route?
      current_route = self.class.extract_route(
        controller: env[ENV_CONTROLLER_PATH],
        path: env[ENV_REQUEST_PATH]
      )
      if Middleware.request_timing_required?
        request_time = env[ENV_REQUEST_TOTAL_TIME].to_f
        env[ENV_REQUEST_TOTAL_TIME] = nil
      end
      if Middleware.request?
        gauge(:request, request_time, current_route)
      end
      if Middleware.apdex?
        apdex(request_time)
      end
      if Middleware.error?
        # We to_i the status because in some circumstances it is a
        # Fixnum and some it is a string. Because why not.
        increment(:error, current_route) if $ERROR_INFO || status.to_i >= 500
      end
      if Middleware.response_size?
        # Note that 30xs don't have content-length, so cached
        # items will report other metrics but not this one
        response_size = self.class.get_response_size(headers: headers, body: body)
        if response_size && !response_size.to_s.strip.empty?
          gauge(:response_size, response_size.to_i, current_route)
        end
      end
    end

    if Middleware.middleware?
      middleware_time = (Time.now.to_f - process_start_time) - request_time
      gauge(:middleware, middleware_time)
    end

    @request_end_time = Time.now.to_f
  end
end

#gauge(kind, value, route = nil) ⇒ Object 



77
78
79
80
81
82
 
# File 'lib/metrician/middleware/request_timing.rb', line 77

def gauge(kind, value, route = nil)
  Metrician.gauge("#{WEB_METRIC}.#{kind}", value)
  if route && Middleware.route_tracking?
    Metrician.gauge("#{WEB_METRIC}.#{kind}.#{route}", value)
  end
end

#increment(kind, route = nil) ⇒ Object 



84
85
86
87
88
89
 
# File 'lib/metrician/middleware/request_timing.rb', line 84

def increment(kind, route = nil)
  Metrician.increment("#{WEB_METRIC}.#{kind}")
  if route && Middleware.route_tracking?
    Metrician.increment("#{WEB_METRIC}.#{kind}.#{route}")
  end
end

#need_route? ⇒ Boolean

Returns:

  • (Boolean) 


91
92
93
94
95
 
# File 'lib/metrician/middleware/request_timing.rb', line 91

def need_route?
  Middleware.request? ||
    Middleware.error? ||
    Middleware.response_size?
end