Commit 51e753a8 authored by Igor Drozdov's avatar Igor Drozdov

Add Bullet notifications to Performance bar

Bullet gem helps to detect N+1 problems for SQL queries. It mostly
recognized the simple cases, but even those are regularly encountered
in our code base.

In order to enable the gem, one should ENABLE_BULLET=1. Then bullet
notifications will appear in the js console. Unfortunately, js console
messages don't call to action.

What about putting the notifications in the Performance bar?
parent 0f6c4880
...@@ -343,7 +343,7 @@ group :development do ...@@ -343,7 +343,7 @@ group :development do
end end
group :development, :test do group :development, :test do
gem 'bullet', '~> 6.0.2', require: !!ENV['ENABLE_BULLET'] gem 'bullet', '~> 6.0.2'
gem 'pry-byebug', '~> 3.5.1', platform: :mri gem 'pry-byebug', '~> 3.5.1', platform: :mri
gem 'pry-rails', '~> 0.3.9' gem 'pry-rails', '~> 0.3.9'
......
...@@ -39,6 +39,11 @@ export default { ...@@ -39,6 +39,11 @@ export default {
metricDetails() { metricDetails() {
return this.currentRequest.details[this.metric]; return this.currentRequest.details[this.metric];
}, },
metricDetailsLabel() {
return this.metricDetails.duration
? `${this.metricDetails.duration} / ${this.metricDetails.calls}`
: this.metricDetails.calls;
},
detailsList() { detailsList() {
return this.metricDetails.details; return this.metricDetails.details;
}, },
...@@ -68,7 +73,7 @@ export default { ...@@ -68,7 +73,7 @@ export default {
type="button" type="button"
data-toggle="modal" data-toggle="modal"
> >
{{ metricDetails.duration }} / {{ metricDetails.calls }} {{ metricDetailsLabel }}
</button> </button>
<gl-modal <gl-modal
:id="`modal-peek-${metric}-details`" :id="`modal-peek-${metric}-details`"
...@@ -80,7 +85,9 @@ export default { ...@@ -80,7 +85,9 @@ export default {
<template v-if="detailsList.length"> <template v-if="detailsList.length">
<tr v-for="(item, index) in detailsList" :key="index"> <tr v-for="(item, index) in detailsList" :key="index">
<td> <td>
<span>{{ sprintf(__('%{duration}ms'), { duration: item.duration }) }}</span> <span v-if="item.duration">{{
sprintf(__('%{duration}ms'), { duration: item.duration })
}}</span>
</td> </td>
<td> <td>
<div class="js-toggle-container"> <div class="js-toggle-container">
......
...@@ -37,6 +37,11 @@ export default { ...@@ -37,6 +37,11 @@ export default {
header: s__('PerformanceBar|SQL queries'), header: s__('PerformanceBar|SQL queries'),
keys: ['sql'], keys: ['sql'],
}, },
{
metric: 'bullet',
header: s__('PerformanceBar|Bullet notifications'),
keys: ['notification'],
},
{ {
metric: 'gitaly', metric: 'gitaly',
header: s__('PerformanceBar|Gitaly calls'), header: s__('PerformanceBar|Gitaly calls'),
......
if defined?(Bullet) && ENV['ENABLE_BULLET'] def bullet_enabled?
Gitlab::Utils.to_boolean(ENV['ENABLE_BULLET'].to_s)
end
if defined?(Bullet) && (bullet_enabled? || Rails.env.development?)
Rails.application.configure do Rails.application.configure do
config.after_initialize do config.after_initialize do
Bullet.enable = true Bullet.enable = true
Bullet.bullet_logger = true Bullet.bullet_logger = bullet_enabled?
Bullet.console = true Bullet.console = bullet_enabled?
Bullet.raise = Rails.env.test? Bullet.raise = Rails.env.test?
end end
end end
......
...@@ -10,5 +10,6 @@ Peek.into Peek::Views::ActiveRecord ...@@ -10,5 +10,6 @@ Peek.into Peek::Views::ActiveRecord
Peek.into Peek::Views::Gitaly Peek.into Peek::Views::Gitaly
Peek.into Peek::Views::RedisDetailed Peek.into Peek::Views::RedisDetailed
Peek.into Peek::Views::Rugged Peek.into Peek::Views::Rugged
Peek.into Peek::Views::BulletDetailed if defined?(Bullet)
Peek.into Peek::Views::Tracing if Labkit::Tracing.tracing_url_enabled? Peek.into Peek::Views::Tracing if Labkit::Tracing.tracing_url_enabled?
...@@ -107,9 +107,13 @@ Recorded transactions can be found by navigating to `/sherlock/transactions`. ...@@ -107,9 +107,13 @@ Recorded transactions can be found by navigating to `/sherlock/transactions`.
## Bullet ## Bullet
Bullet is a Gem that can be used to track down N+1 query problems. Because Bullet is a Gem that can be used to track down N+1 query problems. Bullet section is
Bullet adds quite a bit of logging noise it's disabled by default. To enable displayed on the [performance-bar](../administration/monitoring/performance/performance_bar.md).
Bullet, set the environment variable `ENABLE_BULLET` to a non-empty value before
![Bullet](img/bullet_v13_0.png)
Because Bullet adds quite a bit of logging noise the logging is disabled by default.
To enable the logging, set the environment variable `ENABLE_BULLET` to a non-empty value before
starting GitLab. For example: starting GitLab. For example:
```shell ```shell
......
# frozen_string_literal: true
module Peek
module Views
class BulletDetailed < DetailedView
WARNING_MESSAGE = "Unoptimized queries detected"
def key
'bullet'
end
def results
return {} unless ::Bullet.enable?
return {} unless calls > 0
{
calls: calls,
details: details,
warnings: [WARNING_MESSAGE]
}
end
private
def details
notifications.map do |notification|
# there is no public method which returns pure backtace:
# https://github.com/flyerhzm/bullet/blob/9cda9c224a46786ecfa894480c4dd4d304db2adb/lib/bullet/notification/n_plus_one_query.rb
backtrace = notification.body_with_caller
{
notification: "#{notification.title}: #{notification.body}",
backtrace: backtrace
}
end
end
def calls
notifications.size
end
def notifications
::Bullet.notification_collector&.collection || []
end
end
end
end
...@@ -15371,6 +15371,9 @@ msgstr "" ...@@ -15371,6 +15371,9 @@ msgstr ""
msgid "Performance optimization" msgid "Performance optimization"
msgstr "" msgstr ""
msgid "PerformanceBar|Bullet notifications"
msgstr ""
msgid "PerformanceBar|Download" msgid "PerformanceBar|Download"
msgstr "" msgstr ""
......
import { shallowMount } from '@vue/test-utils'; import { shallowMount } from '@vue/test-utils';
import DetailedMetric from '~/performance_bar/components/detailed_metric.vue'; import DetailedMetric from '~/performance_bar/components/detailed_metric.vue';
import RequestWarning from '~/performance_bar/components/request_warning.vue'; import RequestWarning from '~/performance_bar/components/request_warning.vue';
import { trimText } from 'helpers/text_helper';
describe('detailedMetric', () => { describe('detailedMetric', () => {
const createComponent = props => let wrapper;
shallowMount(DetailedMetric, {
const createComponent = props => {
wrapper = shallowMount(DetailedMetric, {
propsData: { propsData: {
...props, ...props,
}, },
}); });
};
afterEach(() => {
wrapper.destroy();
});
describe('when the current request has no details', () => { describe('when the current request has no details', () => {
const wrapper = createComponent({ beforeEach(() => {
currentRequest: {}, createComponent({
metric: 'gitaly', currentRequest: {},
header: 'Gitaly calls', metric: 'gitaly',
details: 'details', header: 'Gitaly calls',
keys: ['feature', 'request'], details: 'details',
keys: ['feature', 'request'],
});
}); });
it('does not render the element', () => { it('does not render the element', () => {
...@@ -31,20 +41,22 @@ describe('detailedMetric', () => { ...@@ -31,20 +41,22 @@ describe('detailedMetric', () => {
]; ];
describe('with a default metric name', () => { describe('with a default metric name', () => {
const wrapper = createComponent({ beforeEach(() => {
currentRequest: { createComponent({
details: { currentRequest: {
gitaly: { details: {
duration: '123ms', gitaly: {
calls: '456', duration: '123ms',
details: requestDetails, calls: '456',
warnings: ['gitaly calls: 456 over 30'], details: requestDetails,
warnings: ['gitaly calls: 456 over 30'],
},
}, },
}, },
}, metric: 'gitaly',
metric: 'gitaly', header: 'Gitaly calls',
header: 'Gitaly calls', keys: ['feature', 'request'],
keys: ['feature', 'request'], });
}); });
it('displays details', () => { it('displays details', () => {
...@@ -87,25 +99,49 @@ describe('detailedMetric', () => { ...@@ -87,25 +99,49 @@ describe('detailedMetric', () => {
}); });
describe('when using a custom metric title', () => { describe('when using a custom metric title', () => {
const wrapper = createComponent({ beforeEach(() => {
createComponent({
currentRequest: {
details: {
gitaly: {
duration: '123ms',
calls: '456',
details: requestDetails,
},
},
},
metric: 'gitaly',
title: 'custom',
header: 'Gitaly calls',
keys: ['feature', 'request'],
});
});
it('displays the custom title', () => {
expect(wrapper.text()).toContain('custom');
});
});
});
describe('when the details has no duration', () => {
beforeEach(() => {
createComponent({
currentRequest: { currentRequest: {
details: { details: {
gitaly: { bullet: {
duration: '123ms',
calls: '456', calls: '456',
details: requestDetails, details: [{ notification: 'notification', backtrace: 'backtrace' }],
}, },
}, },
}, },
metric: 'gitaly', metric: 'bullet',
title: 'custom', header: 'Bullet notifications',
header: 'Gitaly calls', keys: ['notification'],
keys: ['feature', 'request'],
}); });
});
it('displays the custom title', () => { it('renders only the number of calls', () => {
expect(wrapper.text()).toContain('custom'); expect(trimText(wrapper.text())).toEqual('456 notification backtrace bullet');
});
}); });
}); });
}); });
# frozen_string_literal: true
require 'spec_helper'
describe Peek::Views::BulletDetailed do
subject { described_class.new }
before do
allow(Bullet).to receive(:enable?).and_return(bullet_enabled)
end
context 'bullet disabled' do
let(:bullet_enabled) { false }
it 'returns empty results' do
expect(subject.results).to eq({})
end
end
context 'bullet enabled' do
let(:bullet_enabled) { true }
before do
allow(Bullet).to receive_message_chain(:notification_collector, :collection).and_return(notifications)
end
context 'where there are no notifications' do
let(:notifications) { [] }
it 'returns empty results' do
expect(subject.results).to eq({})
end
end
context 'when notifications exist' do
let(:notifications) do
[
double(title: 'Title 1', body: 'Body 1', body_with_caller: "first\nsecond\n"),
double(title: 'Title 2', body: 'Body 2', body_with_caller: "first\nsecond\n")
]
end
it 'returns empty results' do
expect(subject.key).to eq('bullet')
expect(subject.results[:calls]).to eq(2)
expect(subject.results[:warnings]).to eq([Peek::Views::BulletDetailed::WARNING_MESSAGE])
expect(subject.results[:details]).to eq([
{ notification: 'Title 1: Body 1', backtrace: "first\nsecond\n" },
{ notification: 'Title 2: Body 2', backtrace: "first\nsecond\n" }
])
end
end
end
end
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment