Commit 5bdcdb97 authored by Sean McGivern's avatar Sean McGivern

Allow Sentry processors to be used directly or in before_send

We want to upgrade the version of the Sentry gem we're currently using
to the latest version. However, this makes some breaking changes. One of
the biggest for our purposes is that it no longer supports processors -
these were classes to pre-process the event hash before sending to
Sentry.

In the latest version, these are no longer available, but we can still
use any logic we like in a custom `before_send` hook. So we can manually
chain our existing processors there. However, there's a catch:
processors in the current version take an event hash, but the
`before_send` hook takes an Event object. (Raven::Event in the current
version, Sentry::Event in the new one.)

This change adds a feature flag - sentry_processors_before_send - that
defaults to off. When it's off, we use the processors as we do now. When
it's on:

1. All the processors become no-ops when called as processors.
2. We enable them in a `before_send` chain through a different
   interface.

Because they take a different type of argument, this makes the
processors in this change a little ugly. We can tidy that up once we've
validated this feature flag in production, even before upgrading the
gem. We also add specs to test each processor both with and without the
feature flag enabled.
parent ecec0453
---
name: sentry_processors_before_send
introduced_by_url:
rollout_issue_url: https://gitlab.com/gitlab-com/gl-infra/scalability/-/issues/849#processors
milestone: '13.11'
type: development
group: team::Scalability
default_enabled: false
......@@ -16,6 +16,12 @@ module Gitlab
Rack::Timeout::RequestTimeoutException
].freeze
PROCESSORS = [
::Gitlab::ErrorTracking::Processor::SidekiqProcessor,
::Gitlab::ErrorTracking::Processor::GrpcErrorProcessor,
::Gitlab::ErrorTracking::Processor::ContextPayloadProcessor
].freeze
class << self
def configure
Raven.configure do |config|
......@@ -97,7 +103,9 @@ module Gitlab
inject_context_for_exception(event, hint[:exception])
custom_fingerprinting(event, hint[:exception])
event
PROCESSORS.reduce(event) do |processed_event, processor|
processor.call(processed_event)
end
end
def process_exception(exception, sentry: false, logging: true, extra:)
......
......@@ -9,9 +9,21 @@ module Gitlab
# integrations are re-implemented and use Gitlab::ErrorTracking, this
# processor should be removed.
def process(payload)
return payload if ::Feature.enabled?(:sentry_processors_before_send, default_enabled: :yaml)
context_payload = Gitlab::ErrorTracking::ContextPayloadGenerator.generate(nil, {})
payload.deep_merge!(context_payload)
end
def self.call(event)
return event unless ::Feature.enabled?(:sentry_processors_before_send, default_enabled: :yaml)
Gitlab::ErrorTracking::ContextPayloadGenerator.generate(nil, {}).each do |key, value|
event.public_send(key).deep_merge!(value) # rubocop:disable GitlabSecurity/PublicSend
end
event
end
end
end
end
......
......@@ -6,60 +6,126 @@ module Gitlab
class GrpcErrorProcessor < ::Raven::Processor
DEBUG_ERROR_STRING_REGEX = RE2('(.*) debug_error_string:(.*)')
def process(value)
process_first_exception_value(value)
process_custom_fingerprint(value)
def process(payload)
return payload if ::Feature.enabled?(:sentry_processors_before_send, default_enabled: :yaml)
value
end
# Sentry can report multiple exceptions in an event. Sanitize
# only the first one since that's what is used for grouping.
def process_first_exception_value(value)
exceptions = value.dig(:exception, :values)
return unless exceptions.is_a?(Array)
entry = exceptions.first
return unless entry.is_a?(Hash)
exception_type = entry[:type]
raw_message = entry[:value]
return unless exception_type&.start_with?('GRPC::')
return unless raw_message.present?
message, debug_str = split_debug_error_string(raw_message)
entry[:value] = message if message
extra = value[:extra] || {}
extra[:grpc_debug_error_string] = debug_str if debug_str
end
def process_custom_fingerprint(value)
fingerprint = value[:fingerprint]
return value unless custom_grpc_fingerprint?(fingerprint)
self.class.process_first_exception_value(payload)
self.class.process_custom_fingerprint(payload)
message, _ = split_debug_error_string(fingerprint[1])
fingerprint[1] = message if message
payload
end
private
def custom_grpc_fingerprint?(fingerprint)
fingerprint.is_a?(Array) && fingerprint.length == 2 && fingerprint[0].start_with?('GRPC::')
end
def split_debug_error_string(message)
return unless message
match = DEBUG_ERROR_STRING_REGEX.match(message)
return unless match
[match[1], match[2]]
class << self
def call(event)
return event unless ::Feature.enabled?(:sentry_processors_before_send, default_enabled: :yaml)
process_first_exception_value(event)
process_custom_fingerprint(event)
event
end
# Sentry can report multiple exceptions in an event. Sanitize
# only the first one since that's what is used for grouping.
def process_first_exception_value(event_or_payload)
exceptions = exceptions(event_or_payload)
return unless exceptions.is_a?(Array)
exception = exceptions.first
return unless valid_exception?(exception)
exception_type, raw_message = type_and_value(exception)
return unless exception_type&.start_with?('GRPC::')
return unless raw_message.present?
message, debug_str = split_debug_error_string(raw_message)
set_new_values!(event_or_payload, exception, message, debug_str)
end
def process_custom_fingerprint(event)
fingerprint = fingerprint(event)
return event unless custom_grpc_fingerprint?(fingerprint)
message, _ = split_debug_error_string(fingerprint[1])
fingerprint[1] = message if message
end
private
def custom_grpc_fingerprint?(fingerprint)
fingerprint.is_a?(Array) && fingerprint.length == 2 && fingerprint[0].start_with?('GRPC::')
end
def split_debug_error_string(message)
return unless message
match = DEBUG_ERROR_STRING_REGEX.match(message)
return unless match
[match[1], match[2]]
end
# The below methods can be removed once we remove the
# sentry_processors_before_send feature flag, and we can
# assume we always have an Event object
def exceptions(event_or_payload)
case event_or_payload
when Raven::Event
# Better in new version, will be event_or_payload.exception.values
event_or_payload.instance_variable_get(:@interfaces)[:exception]&.values
when Hash
event_or_payload.dig(:exception, :values)
end
end
def valid_exception?(exception)
case exception
when Raven::SingleExceptionInterface
exception&.value
when Hash
true
else
false
end
end
def type_and_value(exception)
case exception
when Raven::SingleExceptionInterface
[exception.type, exception.value]
when Hash
exception.values_at(:type, :value)
end
end
def set_new_values!(event_or_payload, exception, message, debug_str)
case event_or_payload
when Raven::Event
# Worse in new version, no setter! Have to poke at the
# instance variable
exception.value = message if message
event_or_payload.extra[:grpc_debug_error_string] = debug_str if debug_str
when Hash
exception[:value] = message if message
extra = event_or_payload[:extra] || {}
extra[:grpc_debug_error_string] = debug_str if debug_str
end
end
def fingerprint(event_or_payload)
case event_or_payload
when Raven::Event
event_or_payload.fingerprint
when Hash
event_or_payload[:fingerprint]
end
end
end
end
end
......
......@@ -8,39 +8,66 @@ module Gitlab
class SidekiqProcessor < ::Raven::Processor
FILTERED_STRING = '[FILTERED]'
def self.filter_arguments(args, klass)
args.lazy.with_index.map do |arg, i|
case arg
when Numeric
arg
else
if permitted_arguments_for_worker(klass).include?(i)
class << self
def filter_arguments(args, klass)
args.lazy.with_index.map do |arg, i|
case arg
when Numeric
arg
else
FILTERED_STRING
if permitted_arguments_for_worker(klass).include?(i)
arg
else
FILTERED_STRING
end
end
end
end
end
def self.permitted_arguments_for_worker(klass)
@permitted_arguments_for_worker ||= {}
@permitted_arguments_for_worker[klass] ||=
begin
klass.constantize&.loggable_arguments&.to_set
rescue
Set.new
def permitted_arguments_for_worker(klass)
@permitted_arguments_for_worker ||= {}
@permitted_arguments_for_worker[klass] ||=
begin
klass.constantize&.loggable_arguments&.to_set
rescue
Set.new
end
end
def loggable_arguments(args, klass)
Gitlab::Utils::LogLimitedArray
.log_limited_array(filter_arguments(args, klass))
.map(&:to_s)
.to_a
end
def call(event)
return event unless ::Feature.enabled?(:sentry_processors_before_send, default_enabled: :yaml)
sidekiq = event&.extra&.dig(:sidekiq)
return event unless sidekiq
sidekiq = sidekiq.deep_dup
sidekiq.delete(:jobstr)
# 'args' in this hash => from Gitlab::ErrorTracking.track_*
# 'args' in :job => from default error handler
job_holder = sidekiq.key?('args') ? sidekiq : sidekiq[:job]
if job_holder['args']
job_holder['args'] = filter_arguments(job_holder['args'], job_holder['class']).to_a
end
end
def self.loggable_arguments(args, klass)
Gitlab::Utils::LogLimitedArray
.log_limited_array(filter_arguments(args, klass))
.map(&:to_s)
.to_a
event.extra[:sidekiq] = sidekiq
event
end
end
def process(value, key = nil)
return value if ::Feature.enabled?(:sentry_processors_before_send, default_enabled: :yaml)
sidekiq = value.dig(:extra, :sidekiq)
return value unless sidekiq
......
# frozen_string_literal: true
require 'fast_spec_helper'
require 'spec_helper'
RSpec.describe Gitlab::ErrorTracking::Processor::ContextPayloadProcessor do
subject(:processor) { described_class.new }
before do
allow_next_instance_of(Gitlab::ErrorTracking::ContextPayloadGenerator) do |generator|
allow(generator).to receive(:generate).and_return(
user: { username: 'root' },
tags: { locale: 'en', program: 'test', feature_category: 'feature_a', correlation_id: 'cid' },
extra: { some_info: 'info' }
)
shared_examples 'processing an exception' do
before do
allow_next_instance_of(Gitlab::ErrorTracking::ContextPayloadGenerator) do |generator|
allow(generator).to receive(:generate).and_return(
user: { username: 'root' },
tags: { locale: 'en', program: 'test', feature_category: 'feature_a', correlation_id: 'cid' },
extra: { some_info: 'info' }
)
end
end
end
it 'merges the context payload into event payload' do
payload = {
user: { ip_address: '127.0.0.1' },
tags: { priority: 'high' },
extra: { sidekiq: { class: 'SomeWorker', args: ['[FILTERED]', 1, 2] } }
}
processor.process(payload)
expect(payload).to eql(
user: {
ip_address: '127.0.0.1',
username: 'root'
},
tags: {
priority: 'high',
locale: 'en',
program: 'test',
feature_category: 'feature_a',
correlation_id: 'cid'
},
extra: {
some_info: 'info',
sidekiq: { class: 'SomeWorker', args: ['[FILTERED]', 1, 2] }
let(:payload) do
{
user: { ip_address: '127.0.0.1' },
tags: { priority: 'high' },
extra: { sidekiq: { class: 'SomeWorker', args: ['[FILTERED]', 1, 2] } }
}
)
end
it 'merges the context payload into event payload', :aggregate_failures do
expect(result_hash[:user]).to eq(ip_address: '127.0.0.1', username: 'root')
expect(result_hash[:tags])
.to eq(priority: 'high',
locale: 'en',
program: 'test',
feature_category: 'feature_a',
correlation_id: 'cid')
expect(result_hash[:extra])
.to include(some_info: 'info',
sidekiq: { class: 'SomeWorker', args: ['[FILTERED]', 1, 2] })
end
end
describe '.call' do
let(:event) { Raven::Event.new(payload) }
let(:result_hash) { described_class.call(event).to_hash }
it_behaves_like 'processing an exception'
context 'when followed by #process' do
let(:result_hash) { described_class.new.process(described_class.call(event).to_hash) }
it_behaves_like 'processing an exception'
end
end
describe '#process' do
let(:event) { Raven::Event.new(payload) }
let(:result_hash) { described_class.new.process(event.to_hash) }
context 'with sentry_processors_before_send disabled' do
before do
stub_feature_flags(sentry_processors_before_send: false)
end
it_behaves_like 'processing an exception'
end
end
end
......@@ -3,73 +3,83 @@
require 'spec_helper'
RSpec.describe Gitlab::ErrorTracking::Processor::GrpcErrorProcessor do
describe '#process' do
subject { described_class.new }
shared_examples 'processing an exception' do
context 'when there is no GRPC exception' do
let(:exception) { RuntimeError.new }
let(:data) { { fingerprint: ['ArgumentError', 'Missing arguments'] } }
it 'leaves data unchanged' do
expect(subject.process(data)).to eq(data)
expect(result_hash).to include(data)
end
end
context 'when there is a GPRC exception with a debug string' do
let(:exception) { GRPC::DeadlineExceeded.new('Deadline Exceeded', {}, '{"hello":1}') }
let(:data) do
{
exception: {
values: [
{
type: "GRPC::DeadlineExceeded",
value: "4:DeadlineExceeded. debug_error_string:{\"hello\":1}"
}
]
},
extra: {
caller: 'test'
},
fingerprint: [
"GRPC::DeadlineExceeded",
"4:Deadline Exceeded. debug_error_string:{\"created\":\"@1598938192.005782000\",\"description\":\"Error received from peer unix:/home/git/gitalypraefect.socket\",\"file\":\"src/core/lib/surface/call.cc\",\"file_line\":1055,\"grpc_message\":\"Deadline Exceeded\",\"grpc_status\":4}"
'GRPC::DeadlineExceeded',
'4:Deadline Exceeded. debug_error_string:{"created":"@1598938192.005782000","description":"Error received from peer unix:/home/git/gitalypraefect.socket","file":"src/core/lib/surface/call.cc","file_line":1055,"grpc_message":"Deadline Exceeded","grpc_status":4}'
]
}
end
let(:expected) do
{
fingerprint: [
"GRPC::DeadlineExceeded",
"4:Deadline Exceeded."
],
exception: {
values: [
{
type: "GRPC::DeadlineExceeded",
value: "4:DeadlineExceeded."
}
]
},
extra: {
caller: 'test',
grpc_debug_error_string: "{\"hello\":1}"
}
}
end
it 'removes the debug error string and stores it as an extra field' do
expect(subject.process(data)).to eq(expected)
expect(result_hash[:fingerprint])
.to eq(['GRPC::DeadlineExceeded', '4:Deadline Exceeded.'])
expect(result_hash[:exception][:values].first)
.to include(type: 'GRPC::DeadlineExceeded', value: '4:Deadline Exceeded.')
expect(result_hash[:extra])
.to include(caller: 'test', grpc_debug_error_string: '{"hello":1}')
end
context 'with no custom fingerprint' do
before do
data.delete(:fingerprint)
expected.delete(:fingerprint)
let(:data) do
{ extra: { caller: 'test' } }
end
it 'removes the debug error string and stores it as an extra field' do
expect(subject.process(data)).to eq(expected)
expect(result_hash).not_to include(:fingerprint)
expect(result_hash[:exception][:values].first)
.to include(type: 'GRPC::DeadlineExceeded', value: '4:Deadline Exceeded.')
expect(result_hash[:extra])
.to include(caller: 'test', grpc_debug_error_string: '{"hello":1}')
end
end
end
end
describe '.call' do
let(:event) { Raven::Event.from_exception(exception, data) }
let(:result_hash) { described_class.call(event).to_hash }
it_behaves_like 'processing an exception'
context 'when followed by #process' do
let(:result_hash) { described_class.new.process(described_class.call(event).to_hash) }
it_behaves_like 'processing an exception'
end
end
describe '#process' do
let(:event) { Raven::Event.from_exception(exception, data) }
let(:result_hash) { described_class.new.process(event.to_hash) }
context 'with sentry_processors_before_send disabled' do
before do
stub_feature_flags(sentry_processors_before_send: false)
end
it_behaves_like 'processing an exception'
end
end
end
......@@ -94,28 +94,37 @@ RSpec.describe Gitlab::ErrorTracking::Processor::SidekiqProcessor do
end
end
describe '#process' do
shared_examples 'processing an exception' do
context 'when there is Sidekiq data' do
let(:wrapped_value) { { extra: { sidekiq: value } } }
shared_examples 'Sidekiq arguments' do |args_in_job_hash: true|
let(:path) { [:extra, :sidekiq, args_in_job_hash ? :job : nil, 'args'].compact }
let(:args) { [1, 'string', { a: 1 }, [1, 2]] }
it 'only allows numeric arguments for an unknown worker' do
value = { 'args' => args, 'class' => 'UnknownWorker' }
context 'for an unknown worker' do
let(:value) do
hash = { 'args' => args, 'class' => 'UnknownWorker' }
value = { job: value } if args_in_job_hash
args_in_job_hash ? { job: hash } : hash
end
expect(subject.process(extra_sidekiq(value)).dig(*path))
.to eq([1, described_class::FILTERED_STRING, described_class::FILTERED_STRING, described_class::FILTERED_STRING])
it 'only allows numeric arguments for an unknown worker' do
expect(result_hash.dig(*path))
.to eq([1, described_class::FILTERED_STRING, described_class::FILTERED_STRING, described_class::FILTERED_STRING])
end
end
it 'allows all argument types for a permitted worker' do
value = { 'args' => args, 'class' => 'PostReceive' }
context 'for a permitted worker' do
let(:value) do
hash = { 'args' => args, 'class' => 'PostReceive' }
value = { job: value } if args_in_job_hash
args_in_job_hash ? { job: hash } : hash
end
expect(subject.process(extra_sidekiq(value)).dig(*path))
.to eq(args)
it 'allows all argument types for a permitted worker' do
expect(result_hash.dig(*path)).to eq(args)
end
end
end
......@@ -127,39 +136,62 @@ RSpec.describe Gitlab::ErrorTracking::Processor::SidekiqProcessor do
include_examples 'Sidekiq arguments', args_in_job_hash: false
end
it 'removes a jobstr field if present' do
value = {
job: { 'args' => [1] },
jobstr: { 'args' => [1] }.to_json
}
context 'when a jobstr field is present' do
let(:value) do
{
job: { 'args' => [1] },
jobstr: { 'args' => [1] }.to_json
}
end
expect(subject.process(extra_sidekiq(value)))
.to eq(extra_sidekiq(value.except(:jobstr)))
it 'removes the jobstr' do
expect(result_hash.dig(:extra, :sidekiq)).to eq(value.except(:jobstr))
end
end
it 'does nothing with no jobstr' do
value = { job: { 'args' => [1] } }
context 'when no jobstr value is present' do
let(:value) { { job: { 'args' => [1] } } }
expect(subject.process(extra_sidekiq(value)))
.to eq(extra_sidekiq(value))
it 'does nothing' do
expect(result_hash.dig(:extra, :sidekiq)).to eq(value)
end
end
end
context 'when there is no Sidekiq data' do
it 'does nothing' do
value = {
request: {
method: 'POST',
data: { 'key' => 'value' }
}
}
let(:value) { { tags: { foo: 'bar', baz: 'quux' } } }
let(:wrapped_value) { value }
expect(subject.process(value)).to eq(value)
it 'does nothing' do
expect(result_hash).to include(value)
expect(result_hash.dig(:extra, :sidekiq)).to be_nil
end
end
end
describe '.call' do
let(:event) { Raven::Event.new(wrapped_value) }
let(:result_hash) { described_class.call(event).to_hash }
it_behaves_like 'processing an exception'
context 'when followed by #process' do
let(:result_hash) { described_class.new.process(described_class.call(event).to_hash) }
it_behaves_like 'processing an exception'
end
end
describe '#process' do
let(:event) { Raven::Event.new(wrapped_value) }
let(:result_hash) { described_class.new.process(event.to_hash) }
context 'with sentry_processors_before_send disabled' do
before do
stub_feature_flags(sentry_processors_before_send: false)
end
def extra_sidekiq(hash)
{ extra: { sidekiq: hash } }
it_behaves_like 'processing an exception'
end
end
end
......@@ -7,6 +7,7 @@ require 'raven/transports/dummy'
RSpec.describe Gitlab::ErrorTracking do
let(:exception) { RuntimeError.new('boom') }
let(:issue_url) { 'http://gitlab.com/gitlab-org/gitlab-foss/issues/1' }
let(:extra) { { issue_url: issue_url, some_other_info: 'info' } }
let(:user) { create(:user) }
......@@ -135,8 +136,6 @@ RSpec.describe Gitlab::ErrorTracking do
end
describe '.track_exception' do
let(:extra) { { issue_url: issue_url, some_other_info: 'info' } }
subject(:track_exception) { described_class.track_exception(exception, extra) }
before do
......@@ -197,6 +196,55 @@ RSpec.describe Gitlab::ErrorTracking do
end
end
context 'when the error is kind of an `ActiveRecord::StatementInvalid`' do
let(:exception) { ActiveRecord::StatementInvalid.new(sql: 'SELECT "users".* FROM "users" WHERE "users"."id" = 1 AND "users"."foo" = $1') }
it 'injects the normalized sql query into extra' do
track_exception
expect(sentry_event.dig('extra', 'sql')).to eq('SELECT "users".* FROM "users" WHERE "users"."id" = $2 AND "users"."foo" = $1')
end
end
context 'when the `ActiveRecord::StatementInvalid` is wrapped in another exception' do
it 'injects the normalized sql query into extra' do
allow(exception).to receive(:cause).and_return(ActiveRecord::StatementInvalid.new(sql: 'SELECT "users".* FROM "users" WHERE "users"."id" = 1 AND "users"."foo" = $1'))
track_exception
expect(sentry_event.dig('extra', 'sql')).to eq('SELECT "users".* FROM "users" WHERE "users"."id" = $2 AND "users"."foo" = $1')
end
end
end
shared_examples 'event processors' do
subject(:track_exception) { described_class.track_exception(exception, extra) }
before do
allow(Raven).to receive(:capture_exception).and_call_original
allow(Gitlab::ErrorTracking::Logger).to receive(:error)
end
context 'custom GitLab context when using Raven.capture_exception directly' do
subject(:raven_capture_exception) { Raven.capture_exception(exception) }
it 'merges a default set of tags into the existing tags' do
allow(Raven.context).to receive(:tags).and_return(foo: 'bar')
raven_capture_exception
expect(sentry_event['tags']).to include('correlation_id', 'feature_category', 'foo', 'locale', 'program')
end
it 'merges the current user information into the existing user information' do
Raven.user_context(id: -1)
raven_capture_exception
expect(sentry_event['user']).to eq('id' => -1, 'username' => user.username)
end
end
context 'with sidekiq args' do
context 'when the args does not have anything sensitive' do
let(:extra) { { sidekiq: { 'class' => 'PostReceive', 'args' => [1, { 'id' => 2, 'name' => 'hello' }, 'some-value', 'another-value'] } } }
......@@ -263,25 +311,21 @@ RSpec.describe Gitlab::ErrorTracking do
end
end
end
end
context 'when the error is kind of an `ActiveRecord::StatementInvalid`' do
let(:exception) { ActiveRecord::StatementInvalid.new(sql: 'SELECT "users".* FROM "users" WHERE "users"."id" = 1 AND "users"."foo" = $1') }
it 'injects the normalized sql query into extra' do
track_exception
expect(sentry_event.dig('extra', 'sql')).to eq('SELECT "users".* FROM "users" WHERE "users"."id" = $2 AND "users"."foo" = $1')
end
context 'with sentry_processors_before_send enabled' do
before do
stub_feature_flags(sentry_processors_before_send: true)
end
context 'when the `ActiveRecord::StatementInvalid` is wrapped in another exception' do
it 'injects the normalized sql query into extra' do
allow(exception).to receive(:cause).and_return(ActiveRecord::StatementInvalid.new(sql: 'SELECT "users".* FROM "users" WHERE "users"."id" = 1 AND "users"."foo" = $1'))
track_exception
include_examples 'event processors'
end
expect(sentry_event.dig('extra', 'sql')).to eq('SELECT "users".* FROM "users" WHERE "users"."id" = $2 AND "users"."foo" = $1')
end
context 'with sentry_processors_before_send disabled' do
before do
stub_feature_flags(sentry_processors_before_send: false)
end
include_examples 'event processors'
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