Skip to content

Commit

Permalink
Add query times back
Browse files Browse the repository at this point in the history
  • Loading branch information
@thesecretmaster
thesecretmaster committed Jul 14, 2020
1 parent 796d293 commit d5f0634
Show file tree
Hide file tree
Showing 6 changed files with 107 additions and 82 deletions.
58 changes: 29 additions & 29 deletions app/controllers/application_controller.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -84,35 +84,35 @@ def smokey_route?
end

def redis_log_request
# Rack::MiniProfiler.step('Logging to redis') do
# redis = redis(logger: true)
# @request_time ||= Time.now.to_f
# request.set_header 'redis_logs.log_key', redis_log_key
# request.set_header 'redis_logs.timestamp', @request_time
# request.set_header 'redis_logs.request_id', request.uuid
# unless session[:redis_log_id].present? || smokey_route?
# session[:redis_log_id] = SecureRandom.base64
# session[:redis_log_id] = SecureRandom.base64 while redis.exists("session/#{session[:redis_log_id]}")
# end
# RedisLogJob.perform_later(
# {
# path: request.filtered_path,
# impersonator_id: session[:impersonator_id],
# user_id: user_signed_in? ? current_user.id : nil,
# session_id: smokey_route? ? params[:key] : session[:redis_log_id],
# sha: CurrentCommit,
# smoke_detector_id: smokey_route? ? SmokeDetector.find_by(access_token: params[:key])&.id : nil
# },
# subspaces: {
# request_headers: headers.to_h,
# params: request.filtered_parameters.except(:controller, :action)
# },
# time: @request_time,
# uuid: request.uuid,
# session_id: session[:redis_log_id],
# user_id: user_signed_in? ? current_user.id : nil
# )
# end
Rack::MiniProfiler.step('Logging to redis') do
# redis = redis(logger: true)
@request_time ||= Time.now.to_f
request.set_header 'redis_logs.log_key', redis_log_key
request.set_header 'redis_logs.timestamp', @request_time
request.set_header 'redis_logs.request_id', request.uuid
# unless session[:redis_log_id].present? || smokey_route?
# session[:redis_log_id] = SecureRandom.base64
# session[:redis_log_id] = SecureRandom.base64 while redis.exists("session/#{session[:redis_log_id]}")
# end
# RedisLogJob.perform_later(
# {
# path: request.filtered_path,
# impersonator_id: session[:impersonator_id],
# user_id: user_signed_in? ? current_user.id : nil,
# session_id: smokey_route? ? params[:key] : session[:redis_log_id],
# sha: CurrentCommit,
# smoke_detector_id: smokey_route? ? SmokeDetector.find_by(access_token: params[:key])&.id : nil
# },
# subspaces: {
# request_headers: headers.to_h,
# params: request.filtered_parameters.except(:controller, :action)
# },
# time: @request_time,
# uuid: request.uuid,
# session_id: session[:redis_log_id],
# user_id: user_signed_in? ? current_user.id : nil
# )
end
end

def redis_log_key
Expand Down
12 changes: 8 additions & 4 deletions app/controllers/dashboard_controller.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -54,13 +54,17 @@ def spam_by_site
end

def query_times
@query_times = redis(logger: true).scan_each(match: 'request_timings/db/by_path/*').map do |k|
Redis::QueryAverage.new(*k.split('/', 5)[3..-1])
end.sort_by(&:average).reverse
@query_times = redis(logger: true).smembers('request_timings/path_strings')
.map { |path_str| Redis::QueryAverage.new(*path_str.split('/', 2)) }
.sort_by { |h| -h.average(:total) }
end

def reset_query_time
QueryAverage.find(params[:id]).update(counter: 0, average: 0)
if !redis(logger: true).sismember('request_timings/path_strings', params[:path])
flash[:warning] = 'Invalid path to reset'
else
Redis::QueryAverage.new(*params[:path].split('/', 2)).reset
end
redirect_back fallback_location: root_path
end

Expand Down
24 changes: 19 additions & 5 deletions app/models/redis/query_average.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,18 +4,32 @@ class Redis::QueryAverage
def initialize(method, path)
@method = method
@path = path
@redis_key = "request_timings/db/by_path/#{@method}/#{@path}"
end

def counter
redis(logger: true).zcard(@redis_key).to_i
def counter(t)
redis(logger: true).zcard(redis_key(t)).to_i
end

def average
redis(logger: true).zrange(@redis_key, 0, -1).map(&:to_f).sum / counter
def average(t)
redis(logger: true).zrange(redis_key(t), 0, -1).map(&:to_f).sum / counter(t)
end

def path
"#{@method} #{@path}"
end

def raw_path
"#{@method}/#{@path}"
end

def reset
%i[db total view].each do |t|
redis(logger: true).del(redis_key(t))
end
redis(logger: true).srem 'request_timings/path_strings', raw_path
end

def redis_key(t)
"request_timings/#{t}/by_path/#{@method}/#{@path}"
end
end
12 changes: 7 additions & 5 deletions app/views/dashboard/query_times.html.erb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,8 @@
<th>Path</th>
<th>Average Runtime</th>
<th>Hits</th>
<th>DB Time Spent on Route</th>
<th>DB Time</th>
<th>View Time</th>
<% if current_user&.has_role?(:developer) %>
<th class="no-sort"></th>
<% end %>
Expand All @@ -16,11 +17,12 @@
<% @query_times.each do |qt| %>
<tr>
<td><%= qt.path %></td>
<td data-sort-value="<%= (qt.average * 100).to_i %>"><%= qt.average.round(2) %></td>
<td data-sort-value="<%= qt.counter %>"><%= qt.counter %></td>
<td data-sort-value="<%= (qt.counter * qt.average * 100).to_i %>"><%= (qt.counter * qt.average).round(2) %></td>
<td data-sort-value="<%= (qt.average(:total) * 100).to_i %>"><%= qt.average(:total).round(2) %></td>
<td data-sort-value="<%= qt.counter(:total) %>"><%= qt.counter(:total) %></td>
<td data-sort-value="<%= (qt.average(:db) * 100).to_i %>"><%= (qt.average(:db)).round(2) %></td>
<td data-sort-value="<%= (qt.average(:view) * 100).to_i %>"><%= (qt.average(:view)).round(2) %></td>
<% if current_user&.has_role?(:developer) %>
<td><%= link_to 'Reset', reset_query_time_path(qt), method: :post, class: 'text-danger' %></td>
<td><%= link_to 'Reset', reset_query_time_path(path: qt.raw_path), method: :post, class: 'text-danger' %></td>
<% end %>
</tr>
<% end %>
Expand Down
81 changes: 43 additions & 38 deletions config/initializers/redis_logging.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,58 +5,63 @@
REDIS_LOG_EXPIRATION = 1.day.seconds.to_i

# rubocop:disable Metrics/ParameterLists
def log_timestamps(ts, status:, action:, controller:, format:, method:, view_runtime:, db_runtime:, path:, uuid:)
def log_timestamps(ts, status:, action:, controller:, format:, method:, # rubocop:disable Lint/UnusedMethodArgument
view_runtime:, db_runtime:, path:, uuid:) # rubocop:disable Lint/UnusedMethodArgument
# rubocop:enable Metrics/ParameterLists
redis = redis(logger: true)
view_runtime = view_runtime.to_f
db_runtime = db_runtime.to_f

return if path.nil?
path = Rails.sensible_routes.match_for(path)&.path || path.split('?').first
redis.zadd "request_timings/view/by_path/#{method.upcase}/#{path}.#{format}", ts, view_runtime
redis.zadd "request_timings/db/by_path/#{method.upcase}/#{path}.#{format}", ts, db_runtime
redis.zadd "request_timings/total/by_path/#{method.upcase}/#{path}.#{format}", ts, (db_runtime + view_runtime)
path_string = "#{method.upcase}/#{path}.#{format}"
# controller_action_string = "#{controller}##{action}"
redis.sadd 'request_timings/path_strings', path_string
# redis.sadd "request_timings/controller_action_strings", controller_action_string
redis.zadd "request_timings/view/by_path/#{path_string}", ts, view_runtime
redis.zadd "request_timings/db/by_path/#{path_string}", ts, db_runtime
redis.zadd "request_timings/total/by_path/#{path_string}", ts, (db_runtime + view_runtime)

redis.zadd "request_timings/view/by_action/#{controller}##{action}", ts, view_runtime
redis.zadd "request_timings/db/by_action/#{controller}##{action}", ts, db_runtime
redis.zadd "request_timings/total/by_action/#{controller}##{action}", ts, (db_runtime + view_runtime)
# redis.zadd "request_timings/view/by_action/#{controller_action_string}", ts, view_runtime
# redis.zadd "request_timings/db/by_action/#{controller_action_string}", ts, db_runtime
# redis.zadd "request_timings/total/by_action/#{controller_action_string}", ts, (db_runtime + view_runtime)

redis.zadd "request_timings/status_counts/by_path/#{method.upcase}/#{path}.#{format}", ts, status
redis.zadd "request_timings/status_counts/by_action/#{controller}##{action}", ts, status
redis.zadd 'request_timings/status_counts', ts, status
# redis.zadd "request_timings/status_counts/by_path/#{path_string}", ts, status
# redis.zadd "request_timings/status_counts/by_action/#{controller_action_string}", ts, status
# redis.zadd 'request_timings/status_counts', ts, status

redis.zadd "requests/by_path/#{method.upcase}/#{path}.#{format}", ts, uuid
redis.zadd "requests/by_action/#{controller}##{action}", ts, uuid
# redis.zadd "requests/by_path/#{path_string}", ts, uuid
# redis.zadd "requests/by_action/#{controller_action_string}", ts, uuid

redis.zadd 'request_timings/sha', ts, CurrentCommit, nx: true
# redis.zadd 'request_timings/sha', ts, CurrentCommit, nx: true
end

ActiveSupport::Notifications.subscribe 'process_action.action_controller' do |_name, _started, _finished, _unique_id, data|
# redis = redis(logger: true)
# request_id = data[:headers]['action_dispatch.request_id']
# # redis_log_id = data[:headers]['rack.session']['redis_log_id']
# redis_log_key = data[:headers]['redis_logs.log_key']
# request_timestamp = data[:headers]['redis_logs.timestamp']
# unless request_timestamp.nil?
# RedisLogJob.perform_later(
# data.slice(:controller, :action, :format, :method, :status, :view_runtime, :db_runtime),
# subspaces: {
# response_headers: data[:headers].to_h['action_controller.instance'].response.headers.to_h
# },
# status: data[:status],
# exception: data.slice(:exception, :exception_object),
# time: request_timestamp,
# uuid: request_id,
# completed: true
# )
# unless data[:status].nil?
# log_timestamps(request_timestamp, **data.slice(
# :action, :controller,
# :view_runtime, :db_runtime,
# :method, :format, :status
# ), path: redis.hget(redis_log_key, 'path') || data[:path], uuid: request_id)
# end
# end
redis = redis(logger: true)
request_id = data[:headers]['action_dispatch.request_id']
# redis_log_id = data[:headers]['rack.session']['redis_log_id']
redis_log_key = data[:headers]['redis_logs.log_key']
request_timestamp = data[:headers]['redis_logs.timestamp']
unless request_timestamp.nil?
# RedisLogJob.perform_later(
# data.slice(:controller, :action, :format, :method, :status, :view_runtime, :db_runtime),
# subspaces: {
# response_headers: data[:headers].to_h['action_controller.instance'].response.headers.to_h
# },
# status: data[:status],
# exception: data.slice(:exception, :exception_object),
# time: request_timestamp,
# uuid: request_id,
# completed: true
# )
unless data[:status].nil?
log_timestamps(request_timestamp, **data.slice(
:action, :controller,
:view_runtime, :db_runtime,
:method, :format, :status
), path: redis.hget(redis_log_key, 'path') || data[:path], uuid: request_id)
end
end
end

ActiveSupport::Notifications.subscribe 'endpoint_run.grape' do |_name, _started, _finished, _unique_id, data|
Expand Down
2 changes: 1 addition & 1 deletion config/routes.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@
get 'flagging', to: 'flag_settings#dashboard', as: :flagging

get 'query-times', to: 'dashboard#query_times', as: :query_times
post 'query-times/reset/:id', to: 'dashboard#reset_query_time', as: :reset_query_time
post 'query-times/reset', to: 'dashboard#reset_query_time', as: :reset_query_time

post 'statistics.json', to: 'statistics#create'
post 'feedbacks.json', to: 'feedbacks#create'
Expand Down

0 comments on commit d5f0634

Please sign in to comment.