Commit 00086828 authored by Sean McGivern's avatar Sean McGivern

Merge branch 'bvl-add-context-to-logging' into 'master'

Wrap requests in an ApplicationContext

See merge request gitlab-org/gitlab!20791
parents c3e879ee 3c5be56e
......@@ -301,7 +301,7 @@ gem 'sentry-raven', '~> 2.9'
gem 'premailer-rails', '~> 1.10.3'
# LabKit: Tracing and Correlation
gem 'gitlab-labkit', '~> 0.5'
gem 'gitlab-labkit', '0.8.0'
# I18n
gem 'ruby_parser', '~> 3.8', require: false
......
......@@ -117,7 +117,7 @@ GEM
activemodel (>= 5.0)
brakeman (4.2.1)
browser (2.5.3)
builder (3.2.3)
builder (3.2.4)
bullet (6.0.2)
activesupport (>= 3.0.0)
uniform_notifier (~> 1.11)
......@@ -362,7 +362,7 @@ GEM
github-markup (1.7.0)
gitlab-chronic (0.10.5)
numerizer (~> 0.2)
gitlab-labkit (0.7.0)
gitlab-labkit (0.8.0)
actionpack (>= 5.0.0, < 6.1.0)
activesupport (>= 5.0.0, < 6.1.0)
grpc (~> 1.19)
......@@ -589,7 +589,7 @@ GEM
activesupport (>= 4)
railties (>= 4)
request_store (~> 1.0)
loofah (2.3.1)
loofah (2.4.0)
crass (~> 1.0.2)
nokogiri (>= 1.5.9)
lumberjack (1.0.13)
......@@ -1204,7 +1204,7 @@ DEPENDENCIES
gitaly (~> 1.73.0)
github-markup (~> 1.7.0)
gitlab-chronic (~> 0.10.5)
gitlab-labkit (~> 0.5)
gitlab-labkit (= 0.8.0)
gitlab-license (~> 1.0)
gitlab-markup (~> 1.7.0)
gitlab-net-dns (~> 0.9.1)
......
......@@ -33,6 +33,7 @@ class ApplicationController < ActionController::Base
before_action :check_impersonation_availability
before_action :required_signup_info
around_action :set_current_context
around_action :set_locale
around_action :set_session_storage
......@@ -448,6 +449,14 @@ class ApplicationController < ActionController::Base
request.base_url
end
def set_current_context(&block)
Gitlab::ApplicationContext.with_context(
user: -> { auth_user },
project: -> { @project },
namespace: -> { @group },
&block)
end
def set_locale(&block)
Gitlab::I18n.with_user_locale(current_user, &block)
end
......
# frozen_string_literal: true
Rails.application.config.middleware.use(Gitlab::Middleware::CorrelationId)
# frozen_string_literal: true
Rails.application.config.middleware.use(Labkit::Middleware::Rack)
......@@ -2,7 +2,7 @@
if Labkit::Tracing.enabled?
Rails.application.configure do |config|
config.middleware.insert_after Gitlab::Middleware::CorrelationId, ::Labkit::Tracing::RackMiddleware
config.middleware.insert_after Labkit::Middleware::Rack, ::Labkit::Tracing::RackMiddleware
end
# Instrument the Sidekiq client
......
......@@ -13,7 +13,7 @@ module EE
end
def check_cross_project_pipelines_feature!
if job_token_authentication? && !@project.feature_available?(:cross_project_pipelines)
if job_token_authentication? && !user_project.feature_available?(:cross_project_pipelines)
not_found!('Project')
end
end
......
......@@ -43,6 +43,14 @@ module API
header['X-Content-Type-Options'] = 'nosniff'
end
before do
Gitlab::ApplicationContext.push(
user: -> { current_user },
project: -> { @project },
namespace: -> { @group }
)
end
# The locale is set to the current user's locale when `current_user` is loaded
after { Gitlab::I18n.use_default_locale }
......
......@@ -71,27 +71,27 @@ module API
ref = params[:ref]
ref ||= pipeline&.ref
ref ||= @project.repository.branch_names_contains(commit.sha).first
ref ||= user_project.repository.branch_names_contains(commit.sha).first
not_found! 'References for commit' unless ref
name = params[:name] || params[:context] || 'default'
unless pipeline
pipeline = @project.ci_pipelines.create!(
pipeline = user_project.ci_pipelines.create!(
source: :external,
sha: commit.sha,
ref: ref,
user: current_user,
protected: @project.protected_for?(ref))
protected: user_project.protected_for?(ref))
end
status = GenericCommitStatus.running_or_pending.find_or_initialize_by(
project: @project,
project: user_project,
pipeline: pipeline,
name: name,
ref: ref,
user: current_user,
protected: @project.protected_for?(ref)
protected: user_project.protected_for?(ref)
)
optional_attributes =
......@@ -117,7 +117,7 @@ module API
render_api_error!('invalid state', 400)
end
MergeRequest.where(source_project: @project, source_branch: ref)
MergeRequest.where(source_project: user_project, source_branch: ref)
.update_all(head_pipeline_id: pipeline.id) if pipeline.latest?
present status, with: Entities::CommitStatus
......
......@@ -107,8 +107,10 @@ module API
if params[:gl_repository]
@project, @repo_type = Gitlab::GlRepository.parse(params[:gl_repository])
@redirected_path = nil
else
elsif params[:project]
@project, @repo_type, @redirected_path = Gitlab::RepoPath.parse(params[:project])
else
@project, @repo_type, @redirected_path = nil, nil, nil
end
end
# rubocop:enable Gitlab/ModuleWithInstanceVariables
......
......@@ -6,6 +6,13 @@ module API
class Base < Grape::API
before { authenticate_by_gitlab_shell_token! }
before do
Gitlab::ApplicationContext.push(
user: -> { actor&.user },
project: -> { project }
)
end
helpers ::API::Helpers::InternalHelpers
UNKNOWN_CHECK_RESULT_ERROR = 'Unknown check result'.freeze
......@@ -205,7 +212,12 @@ module API
status 200
response = Gitlab::InternalPostReceive::Response.new
# Try to load the project and users so we have the application context
# available for logging before we schedule any jobs.
user = actor.user
project
push_options = Gitlab::PushOptions.new(params[:push_options])
response.reference_counter_decreased = Gitlab::ReferenceCounter.new(params[:gl_repository]).decrease
......
......@@ -355,7 +355,7 @@ module API
post ':id/unarchive' do
authorize!(:archive_project, user_project)
::Projects::UpdateService.new(@project, current_user, archived: false).execute
::Projects::UpdateService.new(user_project, current_user, archived: false).execute
present user_project, with: Entities::Project, current_user: current_user
end
......
# frozen_string_literal: true
module Gitlab
# A GitLab-rails specific accessor for `Labkit::Logging::ApplicationContext`
class ApplicationContext
include Gitlab::Utils::LazyAttributes
def self.with_context(args, &block)
application_context = new(**args)
Labkit::Context.with_context(application_context.to_lazy_hash, &block)
end
def self.push(args)
application_context = new(**args)
Labkit::Context.push(application_context.to_lazy_hash)
end
def initialize(user: nil, project: nil, namespace: nil)
@user, @project, @namespace = user, project, namespace
end
def to_lazy_hash
{ user: -> { username },
project: -> { project_path },
root_namespace: -> { root_namespace_path } }
end
private
lazy_attr_reader :user, type: User
lazy_attr_reader :project, type: Project
lazy_attr_reader :namespace, type: Namespace
def project_path
project&.full_path
end
def username
user&.username
end
def root_namespace_path
if namespace
namespace.full_path_components.first
else
project&.full_path_components&.first
end
end
end
end
# frozen_string_literal: true
# A dumb middleware that steals correlation id
# and sets it as a global context for the request
module Gitlab
module Middleware
class CorrelationId
include ActionView::Helpers::TagHelper
def initialize(app)
@app = app
end
def call(env)
::Labkit::Correlation::CorrelationId.use_id(correlation_id(env)) do
@app.call(env)
end
end
private
def correlation_id(env)
request(env).request_id
end
def request(env)
ActionDispatch::Request.new(env)
end
end
end
end
......@@ -15,7 +15,7 @@ module Gitlab
chain.add Gitlab::SidekiqMiddleware::MemoryKiller if memory_killer
chain.add Gitlab::SidekiqMiddleware::RequestStoreMiddleware if request_store
chain.add Gitlab::SidekiqMiddleware::BatchLoader
chain.add Gitlab::SidekiqMiddleware::CorrelationLogger
chain.add Labkit::Middleware::Sidekiq::Server
chain.add Gitlab::SidekiqMiddleware::InstrumentationLogger
chain.add Gitlab::SidekiqStatus::ServerMiddleware
end
......@@ -27,7 +27,7 @@ module Gitlab
def self.client_configurator
lambda do |chain|
chain.add Gitlab::SidekiqStatus::ClientMiddleware
chain.add Gitlab::SidekiqMiddleware::CorrelationInjector
chain.add Labkit::Middleware::Sidekiq::Client
end
end
end
......
# frozen_string_literal: true
module Gitlab
module SidekiqMiddleware
class CorrelationInjector
def call(worker_class, job, queue, redis_pool)
job[Labkit::Correlation::CorrelationId::LOG_KEY] ||=
Labkit::Correlation::CorrelationId.current_or_new_id
yield
end
end
end
end
# frozen_string_literal: true
module Gitlab
module SidekiqMiddleware
class CorrelationLogger
def call(worker, job, queue)
correlation_id = job[Labkit::Correlation::CorrelationId::LOG_KEY]
Labkit::Correlation::CorrelationId.use_id(correlation_id) do
yield
end
end
end
end
end
# frozen_string_literal: true
module Gitlab
module Utils
module LazyAttributes
extend ActiveSupport::Concern
include Gitlab::Utils::StrongMemoize
class_methods do
def lazy_attr_reader(*one_or_more_names, type: nil)
names = Array.wrap(one_or_more_names)
names.each { |name| define_lazy_reader(name, type: type) }
end
def lazy_attr_accessor(*one_or_more_names, type: nil)
names = Array.wrap(one_or_more_names)
names.each do |name|
define_lazy_reader(name, type: type)
define_lazy_writer(name)
end
end
private
def define_lazy_reader(name, type:)
define_method(name) do
strong_memoize("#{name}_lazy_loaded") do
value = instance_variable_get("@#{name}")
value = value.call if value.respond_to?(:call)
value = nil if type && !value.is_a?(type)
value
end
end
end
def define_lazy_writer(name)
define_method("#{name}=") do |value|
clear_memoization("#{name}_lazy_loaded")
instance_variable_set("@#{name}", value)
end
end
end
end
end
end
......@@ -895,4 +895,50 @@ describe ApplicationController do
end
end
end
context '#set_current_context' do
controller(described_class) do
def index
Labkit::Context.with_context do |context|
render json: context.to_h
end
end
end
let_it_be(:user) { create(:user) }
before do
sign_in(user)
end
it 'does not break anything when no group or project method is defined' do
get :index
expect(response).to have_gitlab_http_status(:success)
end
it 'sets the username in the context when signed in' do
get :index
expect(json_response['meta.user']).to eq(user.username)
end
it 'sets the group if it was available' do
group = build_stubbed(:group)
controller.instance_variable_set(:@group, group)
get :index, format: :json
expect(json_response['meta.root_namespace']).to eq(group.path)
end
it 'sets the project if one was available' do
project = build_stubbed(:project)
controller.instance_variable_set(:@project, project)
get :index, format: :json
expect(json_response['meta.project']).to eq(project.full_path)
end
end
end
# frozen_string_literal: true
require 'spec_helper'
describe Gitlab::ApplicationContext do
describe '.with_context' do
it 'yields the block' do
expect { |b| described_class.with_context({}, &b) }.to yield_control
end
it 'passes the expected context on to labkit' do
fake_proc = duck_type(:call)
expected_context = hash_including(user: fake_proc, project: fake_proc, root_namespace: fake_proc)
expect(Labkit::Context).to receive(:with_context).with(expected_context)
described_class.with_context(
user: build(:user),
project: build(:project),
namespace: build(:namespace)) {}
end
it 'raises an error when passing invalid options' do
expect { described_class.with_context(no: 'option') {} }.to raise_error(ArgumentError)
end
end
describe '.push' do
it 'passes the expected context on to labkit' do
fake_proc = duck_type(:call)
expected_context = hash_including(user: fake_proc, project: fake_proc, root_namespace: fake_proc)
expect(Labkit::Context).to receive(:push).with(expected_context)
described_class.push(user: build(:user))
end
it 'raises an error when passing invalid options' do
expect { described_class.push(no: 'option')}.to raise_error(ArgumentError)
end
end
describe '#to_lazy_hash' do
let(:user) { build(:user) }
let(:project) { build(:project) }
let(:namespace) { build(:group) }
let(:subgroup) { build(:group, parent: namespace) }
def result(context)
context.to_lazy_hash.transform_values { |v| v.call }
end
it 'does not call the attributes until needed' do
fake_proc = double('Proc')
expect(fake_proc).not_to receive(:call)
described_class.new(user: fake_proc, project: fake_proc, namespace: fake_proc).to_lazy_hash
end
it 'correctly loads the expected values when they are wrapped in a block' do
context = described_class.new(user: -> { user }, project: -> { project }, namespace: -> { subgroup })
expect(result(context))
.to include(user: user.username, project: project.full_path, root_namespace: namespace.full_path)
end
it 'correctly loads the expected values when passed directly' do
context = described_class.new(user: user, project: project, namespace: subgroup)
expect(result(context))
.to include(user: user.username, project: project.full_path, root_namespace: namespace.full_path)
end
it 'falls back to a projects namespace when a project is passed but no namespace' do
context = described_class.new(project: project)
expect(result(context))
.to include(project: project.full_path, root_namespace: project.full_path_components.first)
end
end
end
......@@ -654,13 +654,10 @@ describe Gitlab::ImportExport::ProjectTreeRestorer do
let(:user) { create(:user) }
let!(:project) { create(:project, :builds_disabled, :issues_disabled, name: 'project', path: 'project') }
let(:project_tree_restorer) { described_class.new(user: user, shared: shared, project: project) }
let(:correlation_id) { 'my-correlation-id' }
before do
setup_import_export_config('with_invalid_records')
# Import is running from the rake task, `correlation_id` is not assigned
expect(Labkit::Correlation::CorrelationId).to receive(:new_id).and_return(correlation_id)
subject
end
......@@ -682,7 +679,7 @@ describe Gitlab::ImportExport::ProjectTreeRestorer do
expect(import_failure.relation_index).to be_present
expect(import_failure.exception_class).to eq('ActiveRecord::RecordInvalid')
expect(import_failure.exception_message).to be_present
expect(import_failure.correlation_id_value).to eq('my-correlation-id')
expect(import_failure.correlation_id_value).not_to be_empty
expect(import_failure.created_at).to be_present
end
end
......
......@@ -84,7 +84,7 @@ describe Gitlab::Profiler do
expect(severity).to eq(Logger::DEBUG)
expect(message).to include('public').and include(described_class::FILTERED_STRING)
expect(message).not_to include(private_token)
end.twice
end.at_least(1) # This spec could be wrapped in more blocks in the future
custom_logger.debug("public #{private_token}")
end
......
# frozen_string_literal: true
require 'spec_helper'
describe Gitlab::SidekiqMiddleware::CorrelationInjector do
class TestWorker
include ApplicationWorker
end
before do |example|
Sidekiq.client_middleware do |chain|
chain.add described_class
end
end
after do |example|
Sidekiq.client_middleware do |chain|
chain.remove described_class
end
Sidekiq::Queues.clear_all
end
around do |example|
Sidekiq::Testing.fake! do
example.run
end
end
it 'injects into payload the correlation id' do
expect_next_instance_of(described_class) do |instance|
expect(instance).to receive(:call).and_call_original
end
Labkit::Correlation::CorrelationId.use_id('new-correlation-id') do
TestWorker.perform_async(1234)
end
expected_job_params = {
"class" => "TestWorker",
"args" => [1234],
"correlation_id" => "new-correlation-id"
}
expect(Sidekiq::Queues.jobs_by_worker).to a_hash_including(
"TestWorker" => a_collection_containing_exactly(
a_hash_including(expected_job_params)))
end
end
# frozen_string_literal: true
require 'spec_helper'
describe Gitlab::SidekiqMiddleware::CorrelationLogger do
class TestWorker
include ApplicationWorker
end
before do |example|
Sidekiq::Testing.server_middleware do |chain|
chain.add described_class
end
end
after do |example|
Sidekiq::Testing.server_middleware do |chain|
chain.remove described_class
end
end
it 'injects into payload the correlation id', :sidekiq_might_not_need_inline do
expect_any_instance_of(described_class).to receive(:call).and_call_original
expect_any_instance_of(TestWorker).to receive(:perform).with(1234) do
expect(Labkit::Correlation::CorrelationId.current_id).to eq('new-correlation-id')
end
Sidekiq::Client.push(
'queue' => 'test',
'class' => TestWorker,
'args' => [1234],
'correlation_id' => 'new-correlation-id')
end
end
......@@ -38,7 +38,7 @@ describe Gitlab::SidekiqMiddleware do
[
Gitlab::SidekiqMiddleware::Monitor,
Gitlab::SidekiqMiddleware::BatchLoader,
Gitlab::SidekiqMiddleware::CorrelationLogger,
Labkit::Middleware::Sidekiq::Server,
Gitlab::SidekiqMiddleware::InstrumentationLogger,
Gitlab::SidekiqStatus::ServerMiddleware,
Gitlab::SidekiqMiddleware::Metrics,
......@@ -120,7 +120,7 @@ describe Gitlab::SidekiqMiddleware do
# This test ensures that this does not happen
it "invokes the chain" do
expect_any_instance_of(Gitlab::SidekiqStatus::ClientMiddleware).to receive(:call).with(*middleware_expected_args).once.and_call_original
expect_any_instance_of(Gitlab::SidekiqMiddleware::CorrelationInjector).to receive(:call).with(*middleware_expected_args).once.and_call_original
expect_any_instance_of(Labkit::Middleware::Sidekiq::Client).to receive(:call).with(*middleware_expected_args).once.and_call_original
expect { |b| chain.invoke(worker_class_arg, job, queue, redis_pool, &b) }.to yield_control.once
end
......
# frozen_string_literal: true
require 'fast_spec_helper'
require 'active_support/concern'
describe Gitlab::Utils::LazyAttributes do
subject(:klass) do
Class.new do
include Gitlab::Utils::LazyAttributes
lazy_attr_reader :number, type: Numeric
lazy_attr_reader :reader_1, :reader_2
lazy_attr_accessor :incorrect_type, :string_attribute, :accessor_2, type: String
def initialize
@number = -> { 1 }
@reader_1, @reader_2 = 'reader_1', -> { 'reader_2' }
@incorrect_type, @accessor_2 = -> { :incorrect_type }, -> { 'accessor_2' }
end
end
end
context 'class methods' do
it { is_expected.to respond_to(:lazy_attr_reader, :lazy_attr_accessor) }
it { is_expected.not_to respond_to(:define_lazy_reader, :define_lazy_writer) }
end
context 'instance methods' do
subject(:instance) { klass.new }
it do
is_expected.to respond_to(:number, :reader_1, :reader_2, :incorrect_type,
:incorrect_type=, :accessor_2, :accessor_2=,
:string_attribute, :string_attribute=)
end
context 'reading attributes' do
it 'returns the correct values for procs', :aggregate_failures do
expect(instance.number).to eq(1)
expect(instance.reader_2).to eq('reader_2')
expect(instance.accessor_2).to eq('accessor_2')
end
it 'does not return the value if the type did not match what was specified' do
expect(instance.incorrect_type).to be_nil
end
it 'only calls the block once even if it returned `nil`', :aggregate_failures do
expect(instance.instance_variable_get('@number')).to receive(:call).once.and_call_original
expect(instance.instance_variable_get('@accessor_2')).to receive(:call).once.and_call_original
expect(instance.instance_variable_get('@incorrect_type')).to receive(:call).once.and_call_original
2.times do
instance.number
instance.incorrect_type
instance.accessor_2
end
end
end
context 'writing attributes' do
it 'sets the correct values', :aggregate_failures do
instance.string_attribute = -> { 'updated 1' }
instance.accessor_2 = nil
expect(instance.string_attribute).to eq('updated 1')
expect(instance.accessor_2).to be_nil
end
end
end
end
......@@ -389,6 +389,12 @@ describe API::Internal::Base do
end
end
end
it_behaves_like 'storing arguments in the application context' do
let(:expected_params) { { user: key.user.username, project: project.full_path } }
subject { push(key, project) }
end
end
context "access denied" do
......@@ -885,6 +891,12 @@ describe API::Internal::Base do
post api('/internal/post_receive'), params: valid_params
end
it_behaves_like 'storing arguments in the application context' do
let(:expected_params) { { user: user.username, project: project.full_path } }
subject { post api('/internal/post_receive'), params: valid_params }
end
context 'when there are merge_request push options' do
before do
valid_params[:push_options] = ['merge_request.create']
......
......@@ -1626,6 +1626,14 @@ describe API::Projects do
end
end
end
it_behaves_like 'storing arguments in the application context' do
let_it_be(:user) { create(:user) }
let_it_be(:project) { create(:project, :public) }
let(:expected_params) { { user: user.username, project: project.full_path } }
subject { get api("/projects/#{project.id}", user) }
end
end
describe 'GET /projects/:id/users' do
......
......@@ -245,6 +245,12 @@ RSpec.configure do |config|
Rails.cache = caching_store
end
config.around do |example|
# Wrap each example in it's own context to make sure the contexts don't
# leak
Labkit::Context.with_context { example.run }
end
config.around(:each, :clean_gitlab_redis_cache) do |example|
redis_cache_cleanup!
......
# frozen_string_literal: true
RSpec.shared_examples 'storing arguments in the application context' do
around do |example|
Labkit::Context.with_context { example.run }
end
it 'places the expected params in the application context' do
# Stub the clearing of the context so we can validate it later
# The `around` block above makes sure we do clean it up later
allow(Labkit::Context).to receive(:pop)
subject
Labkit::Context.with_context do |context|
expect(context.to_h)
.to include(log_hash(expected_params))
end
end
def log_hash(hash)
hash.transform_keys! { |key| "meta.#{key}" }
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