From 5eb2d6ea02631608095847647e02cd899613b8e1 Mon Sep 17 00:00:00 2001 From: Thong Kuah Date: Mon, 4 Mar 2019 16:28:28 +1300 Subject: Show backtrace when logging to kubernetes.log Just the error message and error class alone makes it hard to determine the full context of any errors, so we need to know where the error is occuring as well. --- app/services/clusters/applications/base_helm_service.rb | 3 ++- changelogs/unreleased/add_backtrace_to_kubernetes_log.yml | 5 +++++ .../applications/check_installation_progress_service_spec.rb | 9 ++++++++- spec/services/clusters/applications/install_service_spec.rb | 12 ++++++++---- spec/services/clusters/applications/patch_service_spec.rb | 4 ++++ spec/services/clusters/applications/upgrade_service_spec.rb | 4 ++++ 6 files changed, 31 insertions(+), 6 deletions(-) create mode 100644 changelogs/unreleased/add_backtrace_to_kubernetes_log.yml diff --git a/app/services/clusters/applications/base_helm_service.rb b/app/services/clusters/applications/base_helm_service.rb index c38b2656260..9619cba533c 100644 --- a/app/services/clusters/applications/base_helm_service.rb +++ b/app/services/clusters/applications/base_helm_service.rb @@ -19,7 +19,8 @@ module Clusters app_id: app.id, project_ids: app.cluster.project_ids, group_ids: app.cluster.group_ids, - message: error.message + message: error.message, + backtrace: Gitlab::Profiler.clean_backtrace(error.backtrace) } logger.error(meta) diff --git a/changelogs/unreleased/add_backtrace_to_kubernetes_log.yml b/changelogs/unreleased/add_backtrace_to_kubernetes_log.yml new file mode 100644 index 00000000000..26b8ac4b1ef --- /dev/null +++ b/changelogs/unreleased/add_backtrace_to_kubernetes_log.yml @@ -0,0 +1,5 @@ +--- +title: Show error backtrace when logging errors to kubernetes.log +merge_request: 25726 +author: +type: other diff --git a/spec/services/clusters/applications/check_installation_progress_service_spec.rb b/spec/services/clusters/applications/check_installation_progress_service_spec.rb index 19446ce1cf8..6e37a30d142 100644 --- a/spec/services/clusters/applications/check_installation_progress_service_spec.rb +++ b/spec/services/clusters/applications/check_installation_progress_service_spec.rb @@ -36,6 +36,7 @@ describe Clusters::Applications::CheckInstallationProgressService, '#execute' do shared_examples 'error logging' do context 'when installation raises a Kubeclient::HttpError' do let(:cluster) { create(:cluster, :provided_by_user, :project) } + let(:logger) { service.send(:logger) } before do application.update!(cluster: cluster) @@ -51,7 +52,13 @@ describe Clusters::Applications::CheckInstallationProgressService, '#execute' do end it 'should log error' do - expect(service.send(:logger)).to receive(:error) + expect(logger).to receive(:error) + + service.execute + end + + it 'logs error backtrace' do + expect(logger).to receive(:error).with(hash_including(backtrace: instance_of(Array))) service.execute end diff --git a/spec/services/clusters/applications/install_service_spec.rb b/spec/services/clusters/applications/install_service_spec.rb index 018d9822d3e..8affc135bc5 100644 --- a/spec/services/clusters/applications/install_service_spec.rb +++ b/spec/services/clusters/applications/install_service_spec.rb @@ -51,6 +51,7 @@ describe Clusters::Applications::InstallService do { exception: 'Kubeclient::HttpError', message: 'system failure', + backtrace: instance_of(Array), service: 'Clusters::Applications::InstallService', app_id: application.id, project_ids: application.cluster.project_ids, @@ -61,15 +62,16 @@ describe Clusters::Applications::InstallService do expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( error, - extra: { + extra: hash_including( exception: 'Kubeclient::HttpError', message: 'system failure', + backtrace: instance_of(Array), service: 'Clusters::Applications::InstallService', app_id: application.id, project_ids: application.cluster.project_ids, group_ids: [], error_code: 500 - } + ) ) service.execute @@ -99,6 +101,7 @@ describe Clusters::Applications::InstallService do exception: 'StandardError', error_code: nil, message: 'something bad happened', + backtrace: instance_of(Array), service: 'Clusters::Applications::InstallService', app_id: application.id, project_ids: application.cluster.projects.pluck(:id), @@ -108,15 +111,16 @@ describe Clusters::Applications::InstallService do expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( error, - extra: { + extra: hash_including( exception: 'StandardError', error_code: nil, message: 'something bad happened', + backtrace: instance_of(Array), service: 'Clusters::Applications::InstallService', app_id: application.id, project_ids: application.cluster.projects.pluck(:id), group_ids: [] - } + ) ) service.execute diff --git a/spec/services/clusters/applications/patch_service_spec.rb b/spec/services/clusters/applications/patch_service_spec.rb index d4ee3243b84..51ca84dcd67 100644 --- a/spec/services/clusters/applications/patch_service_spec.rb +++ b/spec/services/clusters/applications/patch_service_spec.rb @@ -53,6 +53,7 @@ describe Clusters::Applications::PatchService do { exception: 'Kubeclient::HttpError', message: 'system failure', + backtrace: instance_of(Array), service: 'Clusters::Applications::PatchService', app_id: application.id, project_ids: application.cluster.project_ids, @@ -66,6 +67,7 @@ describe Clusters::Applications::PatchService do extra: { exception: 'Kubeclient::HttpError', message: 'system failure', + backtrace: instance_of(Array), service: 'Clusters::Applications::PatchService', app_id: application.id, project_ids: application.cluster.project_ids, @@ -101,6 +103,7 @@ describe Clusters::Applications::PatchService do exception: 'StandardError', error_code: nil, message: 'something bad happened', + backtrace: instance_of(Array), service: 'Clusters::Applications::PatchService', app_id: application.id, project_ids: application.cluster.projects.pluck(:id), @@ -114,6 +117,7 @@ describe Clusters::Applications::PatchService do exception: 'StandardError', error_code: nil, message: 'something bad happened', + backtrace: instance_of(Array), service: 'Clusters::Applications::PatchService', app_id: application.id, project_ids: application.cluster.projects.pluck(:id), diff --git a/spec/services/clusters/applications/upgrade_service_spec.rb b/spec/services/clusters/applications/upgrade_service_spec.rb index 1822fc38dbd..22e7555d260 100644 --- a/spec/services/clusters/applications/upgrade_service_spec.rb +++ b/spec/services/clusters/applications/upgrade_service_spec.rb @@ -53,6 +53,7 @@ describe Clusters::Applications::UpgradeService do { exception: 'Kubeclient::HttpError', message: 'system failure', + backtrace: instance_of(Array), service: 'Clusters::Applications::UpgradeService', app_id: application.id, project_ids: application.cluster.project_ids, @@ -66,6 +67,7 @@ describe Clusters::Applications::UpgradeService do extra: { exception: 'Kubeclient::HttpError', message: 'system failure', + backtrace: instance_of(Array), service: 'Clusters::Applications::UpgradeService', app_id: application.id, project_ids: application.cluster.project_ids, @@ -101,6 +103,7 @@ describe Clusters::Applications::UpgradeService do exception: 'StandardError', error_code: nil, message: 'something bad happened', + backtrace: instance_of(Array), service: 'Clusters::Applications::UpgradeService', app_id: application.id, project_ids: application.cluster.projects.pluck(:id), @@ -114,6 +117,7 @@ describe Clusters::Applications::UpgradeService do exception: 'StandardError', error_code: nil, message: 'something bad happened', + backtrace: instance_of(Array), service: 'Clusters::Applications::UpgradeService', app_id: application.id, project_ids: application.cluster.projects.pluck(:id), -- cgit v1.2.1 From 7cd9cdbe540358ae94d8cee0a0dd36383c645e23 Mon Sep 17 00:00:00 2001 From: Thong Kuah Date: Tue, 2 Apr 2019 16:27:33 +1300 Subject: Refactor to share tests for base class method DRY up tests for logging error. --- .../check_installation_progress_service_spec.rb | 27 ++++---- .../clusters/applications/install_service_spec.rb | 76 ++++------------------ .../clusters/applications/patch_service_spec.rb | 74 ++++----------------- .../clusters/applications/upgrade_service_spec.rb | 74 ++++----------------- .../services/base_helm_service_shared_examples.rb | 27 ++++++++ 5 files changed, 75 insertions(+), 203 deletions(-) create mode 100644 spec/support/shared_examples/services/base_helm_service_shared_examples.rb diff --git a/spec/services/clusters/applications/check_installation_progress_service_spec.rb b/spec/services/clusters/applications/check_installation_progress_service_spec.rb index 6e37a30d142..1cca89d31d7 100644 --- a/spec/services/clusters/applications/check_installation_progress_service_spec.rb +++ b/spec/services/clusters/applications/check_installation_progress_service_spec.rb @@ -33,15 +33,22 @@ describe Clusters::Applications::CheckInstallationProgressService, '#execute' do end end - shared_examples 'error logging' do + shared_examples 'error handling' do context 'when installation raises a Kubeclient::HttpError' do let(:cluster) { create(:cluster, :provided_by_user, :project) } let(:logger) { service.send(:logger) } + let(:error) { Kubeclient::HttpError.new(401, 'Unauthorized', nil) } before do application.update!(cluster: cluster) - expect(service).to receive(:installation_phase).and_raise(Kubeclient::HttpError.new(401, 'Unauthorized', nil)) + expect(service).to receive(:installation_phase).and_raise(error) + end + + include_examples 'logs kubernetes errors' do + let(:error_name) { 'Kubeclient::HttpError' } + let(:error_message) { 'Unauthorized' } + let(:error_code) { 401 } end it 'shows the response code from the error' do @@ -50,18 +57,6 @@ describe Clusters::Applications::CheckInstallationProgressService, '#execute' do expect(application).to be_errored.or(be_update_errored) expect(application.status_reason).to eq('Kubernetes error: 401') end - - it 'should log error' do - expect(logger).to receive(:error) - - service.execute - end - - it 'logs error backtrace' do - expect(logger).to receive(:error).with(hash_including(backtrace: instance_of(Array))) - - service.execute - end end end @@ -73,7 +68,7 @@ describe Clusters::Applications::CheckInstallationProgressService, '#execute' do context 'when application is updating' do let(:application) { create(:clusters_applications_helm, :updating) } - include_examples 'error logging' + include_examples 'error handling' RESCHEDULE_PHASES.each { |phase| it_behaves_like 'a not yet terminated installation', phase } @@ -134,7 +129,7 @@ describe Clusters::Applications::CheckInstallationProgressService, '#execute' do end context 'when application is installing' do - include_examples 'error logging' + include_examples 'error handling' RESCHEDULE_PHASES.each { |phase| it_behaves_like 'a not yet terminated installation', phase } diff --git a/spec/services/clusters/applications/install_service_spec.rb b/spec/services/clusters/applications/install_service_spec.rb index 8affc135bc5..db0c33a95b2 100644 --- a/spec/services/clusters/applications/install_service_spec.rb +++ b/spec/services/clusters/applications/install_service_spec.rb @@ -39,53 +39,34 @@ describe Clusters::Applications::InstallService do expect(helm_client).to receive(:install).with(install_command).and_raise(error) end + include_examples 'logs kubernetes errors' do + let(:error_name) { 'Kubeclient::HttpError' } + let(:error_message) { 'system failure' } + let(:error_code) { 500 } + end + it 'make the application errored' do service.execute expect(application).to be_errored expect(application.status_reason).to match('Kubernetes error: 500') end - - it 'logs errors' do - expect(service.send(:logger)).to receive(:error).with( - { - exception: 'Kubeclient::HttpError', - message: 'system failure', - backtrace: instance_of(Array), - service: 'Clusters::Applications::InstallService', - app_id: application.id, - project_ids: application.cluster.project_ids, - group_ids: [], - error_code: 500 - } - ) - - expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( - error, - extra: hash_including( - exception: 'Kubeclient::HttpError', - message: 'system failure', - backtrace: instance_of(Array), - service: 'Clusters::Applications::InstallService', - app_id: application.id, - project_ids: application.cluster.project_ids, - group_ids: [], - error_code: 500 - ) - ) - - service.execute - end end context 'a non kubernetes error happens' do let(:application) { create(:clusters_applications_helm, :scheduled) } - let(:error) { StandardError.new("something bad happened") } + let(:error) { StandardError.new('something bad happened') } before do expect(application).to receive(:make_installing!).once.and_raise(error) end + include_examples 'logs kubernetes errors' do + let(:error_name) { 'StandardError' } + let(:error_message) { 'something bad happened' } + let(:error_code) { nil } + end + it 'make the application errored' do expect(helm_client).not_to receive(:install) @@ -94,37 +75,6 @@ describe Clusters::Applications::InstallService do expect(application).to be_errored expect(application.status_reason).to eq("Can't start installation process.") end - - it 'logs errors' do - expect(service.send(:logger)).to receive(:error).with( - { - exception: 'StandardError', - error_code: nil, - message: 'something bad happened', - backtrace: instance_of(Array), - service: 'Clusters::Applications::InstallService', - app_id: application.id, - project_ids: application.cluster.projects.pluck(:id), - group_ids: [] - } - ) - - expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( - error, - extra: hash_including( - exception: 'StandardError', - error_code: nil, - message: 'something bad happened', - backtrace: instance_of(Array), - service: 'Clusters::Applications::InstallService', - app_id: application.id, - project_ids: application.cluster.projects.pluck(:id), - group_ids: [] - ) - ) - - service.execute - end end end end diff --git a/spec/services/clusters/applications/patch_service_spec.rb b/spec/services/clusters/applications/patch_service_spec.rb index 51ca84dcd67..10b1379a127 100644 --- a/spec/services/clusters/applications/patch_service_spec.rb +++ b/spec/services/clusters/applications/patch_service_spec.rb @@ -41,49 +41,30 @@ describe Clusters::Applications::PatchService do expect(helm_client).to receive(:update).with(update_command).and_raise(error) end + include_examples 'logs kubernetes errors' do + let(:error_name) { 'Kubeclient::HttpError' } + let(:error_message) { 'system failure' } + let(:error_code) { 500 } + end + it 'make the application errored' do service.execute expect(application).to be_update_errored expect(application.status_reason).to match('Kubernetes error: 500') end - - it 'logs errors' do - expect(service.send(:logger)).to receive(:error).with( - { - exception: 'Kubeclient::HttpError', - message: 'system failure', - backtrace: instance_of(Array), - service: 'Clusters::Applications::PatchService', - app_id: application.id, - project_ids: application.cluster.project_ids, - group_ids: [], - error_code: 500 - } - ) - - expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( - error, - extra: { - exception: 'Kubeclient::HttpError', - message: 'system failure', - backtrace: instance_of(Array), - service: 'Clusters::Applications::PatchService', - app_id: application.id, - project_ids: application.cluster.project_ids, - group_ids: [], - error_code: 500 - } - ) - - service.execute - end end context 'a non kubernetes error happens' do let(:application) { create(:clusters_applications_knative, :scheduled) } let(:error) { StandardError.new('something bad happened') } + include_examples 'logs kubernetes errors' do + let(:error_name) { 'StandardError' } + let(:error_message) { 'something bad happened' } + let(:error_code) { nil } + end + before do expect(application).to receive(:make_updating!).once.and_raise(error) end @@ -96,37 +77,6 @@ describe Clusters::Applications::PatchService do expect(application).to be_update_errored expect(application.status_reason).to eq("Can't start update process.") end - - it 'logs errors' do - expect(service.send(:logger)).to receive(:error).with( - { - exception: 'StandardError', - error_code: nil, - message: 'something bad happened', - backtrace: instance_of(Array), - service: 'Clusters::Applications::PatchService', - app_id: application.id, - project_ids: application.cluster.projects.pluck(:id), - group_ids: [] - } - ) - - expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( - error, - extra: { - exception: 'StandardError', - error_code: nil, - message: 'something bad happened', - backtrace: instance_of(Array), - service: 'Clusters::Applications::PatchService', - app_id: application.id, - project_ids: application.cluster.projects.pluck(:id), - group_ids: [] - } - ) - - service.execute - end end end end diff --git a/spec/services/clusters/applications/upgrade_service_spec.rb b/spec/services/clusters/applications/upgrade_service_spec.rb index 22e7555d260..dd2e6e94e4f 100644 --- a/spec/services/clusters/applications/upgrade_service_spec.rb +++ b/spec/services/clusters/applications/upgrade_service_spec.rb @@ -41,43 +41,18 @@ describe Clusters::Applications::UpgradeService do expect(helm_client).to receive(:update).with(install_command).and_raise(error) end + include_examples 'logs kubernetes errors' do + let(:error_name) { 'Kubeclient::HttpError' } + let(:error_message) { 'system failure' } + let(:error_code) { 500 } + end + it 'make the application errored' do service.execute expect(application).to be_update_errored expect(application.status_reason).to match('Kubernetes error: 500') end - - it 'logs errors' do - expect(service.send(:logger)).to receive(:error).with( - { - exception: 'Kubeclient::HttpError', - message: 'system failure', - backtrace: instance_of(Array), - service: 'Clusters::Applications::UpgradeService', - app_id: application.id, - project_ids: application.cluster.project_ids, - group_ids: [], - error_code: 500 - } - ) - - expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( - error, - extra: { - exception: 'Kubeclient::HttpError', - message: 'system failure', - backtrace: instance_of(Array), - service: 'Clusters::Applications::UpgradeService', - app_id: application.id, - project_ids: application.cluster.project_ids, - group_ids: [], - error_code: 500 - } - ) - - service.execute - end end context 'a non kubernetes error happens' do @@ -88,6 +63,12 @@ describe Clusters::Applications::UpgradeService do expect(application).to receive(:make_updating!).once.and_raise(error) end + include_examples 'logs kubernetes errors' do + let(:error_name) { 'StandardError' } + let(:error_message) { 'something bad happened' } + let(:error_code) { nil } + end + it 'make the application errored' do expect(helm_client).not_to receive(:update) @@ -96,37 +77,6 @@ describe Clusters::Applications::UpgradeService do expect(application).to be_update_errored expect(application.status_reason).to eq("Can't start upgrade process.") end - - it 'logs errors' do - expect(service.send(:logger)).to receive(:error).with( - { - exception: 'StandardError', - error_code: nil, - message: 'something bad happened', - backtrace: instance_of(Array), - service: 'Clusters::Applications::UpgradeService', - app_id: application.id, - project_ids: application.cluster.projects.pluck(:id), - group_ids: [] - } - ) - - expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( - error, - extra: { - exception: 'StandardError', - error_code: nil, - message: 'something bad happened', - backtrace: instance_of(Array), - service: 'Clusters::Applications::UpgradeService', - app_id: application.id, - project_ids: application.cluster.projects.pluck(:id), - group_ids: [] - } - ) - - service.execute - end end end end diff --git a/spec/support/shared_examples/services/base_helm_service_shared_examples.rb b/spec/support/shared_examples/services/base_helm_service_shared_examples.rb new file mode 100644 index 00000000000..c38baa76b25 --- /dev/null +++ b/spec/support/shared_examples/services/base_helm_service_shared_examples.rb @@ -0,0 +1,27 @@ +# frozen_string_literal: true + +shared_examples 'logs kubernetes errors' do + let(:error_hash) do + { + exception: error_name, + message: error_message, + backtrace: instance_of(Array), + service: service.class.name, + app_id: application.id, + project_ids: application.cluster.project_ids, + group_ids: [], + error_code: error_code + } + end + + it 'logs into kubernetes.log and Sentry' do + expect(service.send(:logger)).to receive(:error).with(error_hash) + + expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( + error, + extra: hash_including(error_hash) + ) + + service.execute + end +end -- cgit v1.2.1 From 12321771ff4d2aca723e7292ba9aec180470df13 Mon Sep 17 00:00:00 2001 From: Thong Kuah Date: Thu, 4 Apr 2019 14:43:11 +1300 Subject: Don't send error backtrace to Sentry As it already has the full error sent to it --- app/services/clusters/applications/base_helm_service.rb | 9 ++++++--- .../services/base_helm_service_shared_examples.rb | 9 +++++++-- 2 files changed, 13 insertions(+), 5 deletions(-) diff --git a/app/services/clusters/applications/base_helm_service.rb b/app/services/clusters/applications/base_helm_service.rb index 9619cba533c..0e3991b47b7 100644 --- a/app/services/clusters/applications/base_helm_service.rb +++ b/app/services/clusters/applications/base_helm_service.rb @@ -19,11 +19,14 @@ module Clusters app_id: app.id, project_ids: app.cluster.project_ids, group_ids: app.cluster.group_ids, - message: error.message, - backtrace: Gitlab::Profiler.clean_backtrace(error.backtrace) + message: error.message } - logger.error(meta) + logger_meta = meta.merge( + backtrace: Gitlab::Profiler.clean_backtrace(error.backtrace) + ) + + logger.error(logger_meta) Gitlab::Sentry.track_acceptable_exception(error, extra: meta) end diff --git a/spec/support/shared_examples/services/base_helm_service_shared_examples.rb b/spec/support/shared_examples/services/base_helm_service_shared_examples.rb index c38baa76b25..e2f1a18e9f6 100644 --- a/spec/support/shared_examples/services/base_helm_service_shared_examples.rb +++ b/spec/support/shared_examples/services/base_helm_service_shared_examples.rb @@ -5,7 +5,6 @@ shared_examples 'logs kubernetes errors' do { exception: error_name, message: error_message, - backtrace: instance_of(Array), service: service.class.name, app_id: application.id, project_ids: application.cluster.project_ids, @@ -14,8 +13,14 @@ shared_examples 'logs kubernetes errors' do } end + let(:logger_hash) do + error_hash.merge( + backtrace: instance_of(Array) + ) + end + it 'logs into kubernetes.log and Sentry' do - expect(service.send(:logger)).to receive(:error).with(error_hash) + expect(service.send(:logger)).to receive(:error).with(logger_hash) expect(Gitlab::Sentry).to receive(:track_acceptable_exception).with( error, -- cgit v1.2.1 From a9c855f12c408651e1db41aa5e42aac33aac4084 Mon Sep 17 00:00:00 2001 From: Thong Kuah Date: Thu, 4 Apr 2019 14:50:43 +1300 Subject: Do not send error name and message to Sentry It's duplication information as we already send the full error object to Sentry. --- app/services/clusters/applications/base_helm_service.rb | 6 +++--- .../shared_examples/services/base_helm_service_shared_examples.rb | 4 ++-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/app/services/clusters/applications/base_helm_service.rb b/app/services/clusters/applications/base_helm_service.rb index 0e3991b47b7..adaa68b1efb 100644 --- a/app/services/clusters/applications/base_helm_service.rb +++ b/app/services/clusters/applications/base_helm_service.rb @@ -13,16 +13,16 @@ module Clusters def log_error(error) meta = { - exception: error.class.name, error_code: error.respond_to?(:error_code) ? error.error_code : nil, service: self.class.name, app_id: app.id, project_ids: app.cluster.project_ids, - group_ids: app.cluster.group_ids, - message: error.message + group_ids: app.cluster.group_ids } logger_meta = meta.merge( + exception: error.class.name, + message: error.message, backtrace: Gitlab::Profiler.clean_backtrace(error.backtrace) ) diff --git a/spec/support/shared_examples/services/base_helm_service_shared_examples.rb b/spec/support/shared_examples/services/base_helm_service_shared_examples.rb index e2f1a18e9f6..78a8e49fd76 100644 --- a/spec/support/shared_examples/services/base_helm_service_shared_examples.rb +++ b/spec/support/shared_examples/services/base_helm_service_shared_examples.rb @@ -3,8 +3,6 @@ shared_examples 'logs kubernetes errors' do let(:error_hash) do { - exception: error_name, - message: error_message, service: service.class.name, app_id: application.id, project_ids: application.cluster.project_ids, @@ -15,6 +13,8 @@ shared_examples 'logs kubernetes errors' do let(:logger_hash) do error_hash.merge( + exception: error_name, + message: error_message, backtrace: instance_of(Array) ) end -- cgit v1.2.1