Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

WIP: display activerecord query cache hits #393

Closed
wants to merge 1 commit into from
Closed

WIP: display activerecord query cache hits #393

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
64 changes: 33 additions & 31 deletions lib/html/includes.css
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -82,70 +82,72 @@
margin-left: 0px; }
.profiler-result .profiler-timings tfoot td a.profiler-custom-link {
float: left; }
.profiler-result .profiler-queries {
.profiler-result .cached-queries {
height: 100vh; }
.profiler-result .profiler-queries, .profiler-result .cached-queries {
font-family: Helvetica, Arial, sans-serif; }
.profiler-result .profiler-queries .profiler-stack-trace {
.profiler-result .profiler-queries .profiler-stack-trace, .profiler-result .cached-queries .profiler-stack-trace {
margin-bottom: 15px; }
.profiler-result .profiler-queries tbody tr {
.profiler-result .profiler-queries tbody tr, .profiler-result .cached-queries tbody tr {
border-bottom: 1px solid #f1f1f1; }
.profiler-result .profiler-queries tr {
.profiler-result .profiler-queries tr, .profiler-result .cached-queries tr {
background-color: #FFF; }
.profiler-result .profiler-queries tr.slow {
.profiler-result .profiler-queries tr.slow, .profiler-result .cached-queries tr.slow {
background-color: #FEE; }
.profiler-result .profiler-queries tr.very-slow {
.profiler-result .profiler-queries tr.very-slow, .profiler-result .cached-queries tr.very-slow {
background-color: #FDD; }
.profiler-result .profiler-queries tr.very-very-slow {
.profiler-result .profiler-queries tr.very-very-slow, .profiler-result .cached-queries tr.very-very-slow {
background-color: #FCC; }
.profiler-result .profiler-queries pre {
.profiler-result .profiler-queries pre, .profiler-result .cached-queries pre {
font-family: Consolas, monospace, serif;
white-space: pre-wrap; }
.profiler-result .profiler-queries th {
.profiler-result .profiler-queries th, .profiler-result .cached-queries th {
background-color: #fff;
border-bottom: 1px solid #555;
font-weight: bold;
padding: 15px;
white-space: nowrap; }
.profiler-result .profiler-queries td {
.profiler-result .profiler-queries td, .profiler-result .cached-queries td {
padding: 15px;
text-align: left; }
.profiler-result .profiler-queries td:last-child {
.profiler-result .profiler-queries td:last-child, .profiler-result .cached-queries td:last-child {
padding-right: 25px; }
.profiler-result .profiler-queries .profiler-since-start, .profiler-result .profiler-queries .profiler-duration {
.profiler-result .profiler-queries .profiler-since-start, .profiler-result .profiler-queries .profiler-duration, .profiler-result .cached-queries .profiler-since-start, .profiler-result .cached-queries .profiler-duration {
text-align: right; }
.profiler-result .profiler-queries .profiler-info div {
.profiler-result .profiler-queries .profiler-info div, .profiler-result .cached-queries .profiler-info div {
text-align: right;
margin-bottom: 5px; }
.profiler-result .profiler-queries .profiler-gap-info, .profiler-result .profiler-queries .profiler-gap-info td {
.profiler-result .profiler-queries .profiler-gap-info, .profiler-result .profiler-queries .profiler-gap-info td, .profiler-result .cached-queries .profiler-gap-info, .profiler-result .cached-queries .profiler-gap-info td {
background-color: #ccc; }
.profiler-result .profiler-queries .profiler-gap-info .profiler-unit {
.profiler-result .profiler-queries .profiler-gap-info .profiler-unit, .profiler-result .cached-queries .profiler-gap-info .profiler-unit {
color: #777; }
.profiler-result .profiler-queries .profiler-gap-info .profiler-info {
.profiler-result .profiler-queries .profiler-gap-info .profiler-info, .profiler-result .cached-queries .profiler-gap-info .profiler-info {
text-align: right; }
.profiler-result .profiler-queries .profiler-gap-info.profiler-trivial-gaps {
.profiler-result .profiler-queries .profiler-gap-info.profiler-trivial-gaps, .profiler-result .cached-queries .profiler-gap-info.profiler-trivial-gaps {
display: none; }
.profiler-result .profiler-queries .profiler-trivial-gap-container {
.profiler-result .profiler-queries .profiler-trivial-gap-container, .profiler-result .cached-queries .profiler-trivial-gap-container {
text-align: center; }
.profiler-result .profiler-queries .str {
.profiler-result .profiler-queries .str, .profiler-result .cached-queries .str {
color: maroon; }
.profiler-result .profiler-queries .kwd {
.profiler-result .profiler-queries .kwd, .profiler-result .cached-queries .kwd {
color: #00008b; }
.profiler-result .profiler-queries .com {
.profiler-result .profiler-queries .com, .profiler-result .cached-queries .com {
color: gray; }
.profiler-result .profiler-queries .typ {
.profiler-result .profiler-queries .typ, .profiler-result .cached-queries .typ {
color: #2b91af; }
.profiler-result .profiler-queries .lit {
.profiler-result .profiler-queries .lit, .profiler-result .cached-queries .lit {
color: maroon; }
.profiler-result .profiler-queries .pun {
.profiler-result .profiler-queries .pun, .profiler-result .cached-queries .pun {
color: #000; }
.profiler-result .profiler-queries .pln {
.profiler-result .profiler-queries .pln, .profiler-result .cached-queries .pln {
color: #000; }
.profiler-result .profiler-queries .tag {
.profiler-result .profiler-queries .tag, .profiler-result .cached-queries .tag {
color: maroon; }
.profiler-result .profiler-queries .atn {
.profiler-result .profiler-queries .atn, .profiler-result .cached-queries .atn {
color: red; }
.profiler-result .profiler-queries .atv {
.profiler-result .profiler-queries .atv, .profiler-result .cached-queries .atv {
color: blue; }
.profiler-result .profiler-queries .dec {
.profiler-result .profiler-queries .dec, .profiler-result .cached-queries .dec {
color: purple; }
.profiler-result .profiler-warning, .profiler-result .profiler-warning *, .profiler-result .profiler-warning .profiler-queries-show, .profiler-result .profiler-warning .profiler-queries-show .profiler-unit {
color: #f00; }
Expand Down Expand Up @@ -266,14 +268,14 @@
padding-bottom: 3px; }
.profiler-results .profiler-popup .profiler-timings .profiler-label {
max-width: 275px; }
.profiler-results .profiler-queries {
.profiler-results .profiler-queries, .profiler-results .cached-queries {
display: none;
z-index: 2147483643;
position: absolute;
overflow-y: auto;
overflow-x: auto;
background-color: #fff; }
.profiler-results .profiler-queries th {
.profiler-results .profiler-queries th, .profiler-results .cached-queries th {
font-size: 17px; }
.profiler-results.profiler-min .profiler-result {
display: none; }
Expand Down
25 changes: 21 additions & 4 deletions lib/html/includes.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -192,6 +192,10 @@ var MiniProfiler = (function () {
// lightbox in the queries
popup.find('.profiler-queries-show').on('click', function () { queriesShow($(this), result); });

popup.find('.cached-queries-show').on('click', function () {
cachedQueriesShow($(this), $(document));
});

// limit count
if (container.find('.profiler-result').length > options.maxTracesToShow)
container.find('.profiler-result').first().remove();
Expand Down Expand Up @@ -279,21 +283,33 @@ var MiniProfiler = (function () {
popup.hide();
};

var queriesShow = function (link, result) {
var cachedQueriesShow = function (link, result) {
var queries = result.find('.cached-queries');
showQueriesWrapper(queries)
queries.show();
}

var showQueriesWrapper = function(wrapper) {
var px = 30,
win = $(window),
width = win.width() - 2 * px,
height = win.height() - 2 * px,
queries = result.find('.profiler-queries');
height = win.height() - 2 * px;

// opaque background
$('<div class="profiler-queries-bg"/>').appendTo('body').css({ 'height': $(document).height() }).show();

// center the queries and ensure long content is scrolled
queries.css(options.renderVerticalPosition, px).css({'max-height': height, 'width': width }).css(options.renderHorizontalPosition, px)
wrapper.css(options.renderVerticalPosition, px).css({'max-height': height, 'width': width }).css(options.renderHorizontalPosition, px)
.find('table').css({ 'width': width });
}

var queriesShow = function (link, result) {
var queries = result.find('.profiler-queries');
showQueriesWrapper(queries)
var px = 30,
win = $(window),
width = win.width() - 2 * px,
height = win.height() - 2 * px;
// have to show everything before we can get a position for the first query
queries.show();

Expand Down Expand Up @@ -386,6 +402,7 @@ var MiniProfiler = (function () {
if (hideQueries) {
bg.remove();
queries.hide();
popup.closest('.profiler-result').find('.cached-queries').hide();
}

if (hidePopup) {
Expand Down
10 changes: 7 additions & 3 deletions lib/html/includes.scss
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,11 @@ $zindex:2147483640; // near 32bit max 2147483647
}
}

.profiler-queries {
.cached-queries {
height: 100vh;
}

.profiler-queries, .cached-queries {
font-family:$normalFonts;

.profiler-stack-trace {
Expand Down Expand Up @@ -257,7 +261,7 @@ $zindex:2147483640; // near 32bit max 2147483647

&.profiler-top {
top:0px;

&.profiler-left {
left:0px;

Expand Down Expand Up @@ -423,7 +427,7 @@ $zindex:2147483640; // near 32bit max 2147483647
}
}

.profiler-queries {
.profiler-queries, .cached-queries {
display:none;
z-index:$zindex + 3;
position:absolute;
Expand Down
38 changes: 37 additions & 1 deletion lib/html/includes.tmpl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,15 @@
</td>
{{/each}}
</tr>
{{if activerecord_query_cache_hits.length > 0}}
<tr>
<td colspan="3">&nbsp;</td>
<td colspan="2" class="profiler-number profiler-percent-in-sql" title="${activerecord_query_cache_hits} queries served by ActiveRecord::QueryCache">
<a class="cached-queries-show">${activerecord_query_cache_hits.length}</a>
<span class="profiler-unit"> queries served by ActiveRecord::QueryCache</span>
</td>
</tr>
{{/if}}
</tfoot>
</table>
{{if client_timings}}
Expand Down Expand Up @@ -121,7 +130,23 @@
</p>
</div>
{{/if}}

{{if activerecord_query_cache_hits.length > 0}}
<div class="cached-queries">
<table>
<thead>
<tr>
<th style="text-align:left">Query</th>
<th style="text-align:left">Location</th>
</tr>
</thead>
<tbody>
{{each(i, s) activerecord_query_cache_hits}}
{{tmpl({g: s}) "#queryCacheTemplate"}}
{{/each}}
</tbody>
</table>
</div>
{{/if}}
</div>

</script>
Expand Down Expand Up @@ -226,3 +251,14 @@
</tr>

</script>

<script id="queryCacheTemplate" type="text/x-jquery-tmpl">
<tr>
<td class="query">
<div>${g.sql}</div>
</td>
<td class="query">
<div>${g.location}</div>
</td>
</tr>
</script>
3 changes: 1 addition & 2 deletions lib/mini_profiler/asset_version.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
# frozen_string_literal: true

module Rack
class MiniProfiler
ASSET_VERSION = 'e7cc2f0165a64084b6ec661c38cde91f'
ASSET_VERSION = '32b3695af715620696c4fc20f843fa8f'
end
end
29 changes: 29 additions & 0 deletions lib/mini_profiler/profiler.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -76,6 +76,35 @@ def initialize(app, config = nil)
@config.storage_instance = @config.storage.new(@config.storage_options)
end
@storage = @config.storage_instance
if defined?(ActiveSupport)
ActiveSupport::Notifications.subscribe "sql.active_record" do |*args|
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sadly this is far from a zero cost thing @nateberkopec , in fact at Discourse we do stuff like this:

https://github.com/discourse/discourse/blob/b5705348b32fff406d8e7e3463def65eaf635206/config/initializers/300-perf.rb#L3-L12

I am ok with adding this stuff to rack-mini-profiler, but we are going to new a setting here and to default it off explaining that this adds cost if you turn it on.

Ideally we should measure what the actual cost of this extra subscriber is.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting!

I wonder if there's a better way to get this stuff, because all we care about is the caller locations when QueryCache is hit. We don't actually have to subscribe to all AR notifications.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am ok with adding this stuff to rack-mini-profiler, but we are going to new a setting here and to default it off explaining that this adds cost if you turn it on.

I mean this is fine with me too tbh

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I will add a configuration option and default it to be off.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think ideally it would be in pp=help and work the same way no-backtrace, normal-backtrace and full-backtrace does. Maybe call it no-ar-cache (default), show-ar-cache (option).

That way you could still use it in production and just flip it back off when you're done. You can unsubscribe from ActiveSupport notifications, right?

source_line, line_number = extract_callstack(caller_locations)
payload = args[4]
if payload[:cached]
current.current_timer.page.attributes[:activerecord_query_cache_hits] << {
sql: payload[:sql],
location: "#{source_line}:#{line_number}"
}
end
end
end
end

def gem_path_regexp
@gem_path_regexp ||= Gem.path.dup.push(RbConfig::CONFIG["rubylibdir"]).map { |p| "^#{p}" }.join('|')
end

def extract_callstack(callstack)
line = callstack.find do |frame|
frame.absolute_path && !frame.absolute_path.match?(gem_path_regexp)
end

offending_line = line || callstack.first

[
offending_line.path,
offending_line.lineno
]
end

def user(env)
Expand Down
3 changes: 2 additions & 1 deletion lib/mini_profiler/timer_struct/page.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,8 @@ def initialize(env)
executed_scalars: 0,
executed_non_queries: 0,
custom_timing_names: [],
custom_timing_stats: {}
custom_timing_stats: {},
activerecord_query_cache_hits: []
)
name = "#{env['REQUEST_METHOD']} http://#{env['SERVER_NAME']}:#{env['SERVER_PORT']}#{env['SCRIPT_NAME']}#{env['PATH_INFO']}"
self[:root] = TimerStruct::Request.createRoot(name, self)
Expand Down
2 changes: 1 addition & 1 deletion lib/mini_profiler/timer_struct/request.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ def self.createRoot(name, page)
end
end

attr_accessor :children_duration
attr_accessor :children_duration, :page

def initialize(name, page, parent)
start_millis = (Process.clock_gettime(Process::CLOCK_MONOTONIC) * 1000).to_i - page[:started]
Expand Down