diff --git a/lib/discourse_logstash_logger.rb b/lib/discourse_logstash_logger.rb index 42003f6fbd4..96f8ca653de 100644 --- a/lib/discourse_logstash_logger.rb +++ b/lib/discourse_logstash_logger.rb @@ -91,12 +91,18 @@ class DiscourseLogstashLogger < Logger event["exception.class"] = $1 event["exception.message"] = $2.strip end + + ALLOWED_HEADERS_FROM_ENV.each do |header| + event["request.headers.#{header.downcase}"] = opts.dig(:env, header) + end end - if (env = opts&.dig(:env)).present? - ALLOWED_HEADERS_FROM_ENV.each do |header| - event["request.headers.#{header.downcase}"] = opts[:env][header] - end + if progname == "sidekiq-exception" + event["job.class"] = opts.dig(:context, :job) + event["job.opts"] = opts.dig(:context, :opts) + event["job.problem_db"] = opts.dig(:context, :problem_db) + event["exception.class"] = opts[:exception_class] + event["exception.message"] = opts[:exception_message] end end diff --git a/lib/sidekiq_logster_reporter.rb b/lib/sidekiq_logster_reporter.rb index 2c37e970729..d7be5939665 100644 --- a/lib/sidekiq_logster_reporter.rb +++ b/lib/sidekiq_logster_reporter.rb @@ -9,13 +9,21 @@ class SidekiqLogsterReporter fake_env = {} context.each { |key, value| Logster.add_to_env(fake_env, key, value) } - text = "Job exception: #{ex}\n" + text = "Job exception: #{ex}" Logster.add_to_env(fake_env, :backtrace, ex.backtrace) if ex.backtrace - Logster.add_to_env(fake_env, :current_hostname, Discourse.current_hostname) Thread.current[Logster::Logger::LOGSTER_ENV] = fake_env - Logster.logger.error(text) + + Logster.logger.add_with_opts( + ::Logger::Severity::ERROR, + text, + "sidekiq-exception", + backtrace: ex.backtrace, + exception_class: ex.class.to_s, + exception_message: ex.message.strip, + context:, + ) rescue => e Logster.logger.fatal( "Failed to log exception #{ex} #{hash}\nReason: #{e.class} #{e}\n#{e.backtrace.join("\n")}", diff --git a/spec/lib/discourse_logstash_logger_spec.rb b/spec/lib/discourse_logstash_logger_spec.rb index 9e739be2047..54a2048055a 100644 --- a/spec/lib/discourse_logstash_logger_spec.rb +++ b/spec/lib/discourse_logstash_logger_spec.rb @@ -49,36 +49,102 @@ RSpec.describe DiscourseLogstashLogger do expect(parsed["message"]).to eq("error message") end - it "logs a JSON string with the `exception_class` and `exception_message` fields when `progname` is `web-exception`" do - logger = described_class.logger(logdev: output, type: "test") + context "when `progname` is `sidekiq-exception`" do + it "logs a JSON string with the `exception.class`, `exception.message`, `job.class`, `job.opts` and `job.problem_db` fields" do + logger = described_class.logger(logdev: output, type: "test") - logger.add( - Logger::ERROR, - "Some::StandardError (this is a normal message)\ntest", - "web-exception", - ) + logger.add_with_opts( + Logger::ERROR, + "Job exception: some job error message", + "sidekiq-exception", + exception_class: "Some::StandardError", + exception_message: "some job error message", + context: { + opts: { + user_id: 1, + }, + problem_db: "some_db", + job: "SomeJob", + }, + ) - output.rewind - parsed = JSON.parse(output.read.chomp) + output.rewind + parsed = JSON.parse(output.read.chomp) - expect(parsed["exception.class"]).to eq("Some::StandardError") - expect(parsed["exception.message"]).to eq("this is a normal message") + expect(parsed["exception.class"]).to eq("Some::StandardError") + expect(parsed["exception.message"]).to eq("some job error message") + expect(parsed["job.class"]).to eq("SomeJob") + expect(parsed["job.opts"]).to eq({ "user_id" => 1 }) + expect(parsed["job.problem_db"]).to eq("some_db") + end end - it "logs a JSON string with the `exception_class` and `exception_message` fields when `progname` is `web-exception` and the exception message contains newlines" do - logger = described_class.logger(logdev: output, type: "test") + context "when `progname` is `web-exception`" do + it "logs a JSON string with the `exception.class` and `exception.message` fields" do + logger = described_class.logger(logdev: output, type: "test") - logger.add( - Logger::ERROR, - "Some::StandardError (\n\nsome error message\n\nsomething else\n\n)\ntest", - "web-exception", - ) + logger.add( + Logger::ERROR, + "Some::StandardError (this is a normal message)\ntest", + "web-exception", + ) - output.rewind - parsed = JSON.parse(output.read.chomp) + output.rewind + parsed = JSON.parse(output.read.chomp) - expect(parsed["exception.class"]).to eq("Some::StandardError") - expect(parsed["exception.message"]).to eq("some error message\n\nsomething else") + expect(parsed["exception.class"]).to eq("Some::StandardError") + expect(parsed["exception.message"]).to eq("this is a normal message") + end + + it "logs a JSON string with the `exception_class` and `exception_message` fields when the exception message contains newlines" do + logger = described_class.logger(logdev: output, type: "test") + + logger.add( + Logger::ERROR, + "Some::StandardError (\n\nsome error message\n\nsomething else\n\n)\ntest", + "web-exception", + ) + + output.rewind + parsed = JSON.parse(output.read.chomp) + + expect(parsed["exception.class"]).to eq("Some::StandardError") + expect(parsed["exception.message"]).to eq("some error message\n\nsomething else") + end + + described_class::ALLOWED_HEADERS_FROM_ENV.each do |header| + it "includes `#{header}` from `env` keyword argument in the logged JSON string" do + logger.add( + Logger::ERROR, + lograge_logstash_formatter_formatted_message, + "web-exception", + env: { + header => "header", + }, + ) + + output.rewind + parsed = JSON.parse(output.read.chomp) + + expect(parsed["request.headers.#{header.downcase}"]).to eq("header") + end + end + + it "does not include keys from `env` keyword argument in the logged JSOn string which are not in the allow list" do + logger.add( + Logger::ERROR, + lograge_logstash_formatter_formatted_message, + "web-exception", + env: { + "SOME_RANDOM_HEADER" => "header", + }, + ) + + output.rewind + parsed = JSON.parse(output.read.chomp) + + expect(parsed).not_to have_key("request.headers.some_random_header") + end end it "logs a JSON string with the right fields when `customize_event` attribute is set" do @@ -124,56 +190,6 @@ RSpec.describe DiscourseLogstashLogger do expect(parsed["backtrace"]).to eq("backtrace") end - described_class::ALLOWED_HEADERS_FROM_ENV.each do |header| - it "does not include `#{header}` from `env` keyword argument in the logged JSON string when severity is less than `Logger::WARN`" do - logger.add( - Logger::INFO, - lograge_logstash_formatter_formatted_message, - nil, - env: { - header => "header", - }, - ) - - output.rewind - parsed = JSON.parse(output.read.chomp) - - expect(parsed).not_to have_key("request.headers.#{header.downcase}") - end - - it "includes `#{header}` from `env` keyword argument in the logged JSON string when severity is at least `Logger::WARN`" do - logger.add( - Logger::ERROR, - lograge_logstash_formatter_formatted_message, - nil, - env: { - header => "header", - }, - ) - - output.rewind - parsed = JSON.parse(output.read.chomp) - - expect(parsed["request.headers.#{header.downcase}"]).to eq("header") - end - end - - it "does not include keys from `env` keyword argument in the logged JSOn string which are not in the allow list" do - logger.add( - Logger::ERROR, - lograge_logstash_formatter_formatted_message, - nil, - env: { - "SOME_RANDOM_HEADER" => "header", - }, - ) - - output.rewind - parsed = JSON.parse(output.read.chomp) - - expect(parsed).not_to have_key("request.headers.some_random_header") - end - it "does not log the event if message matches a pattern configured by `Logster.store.ignore`" do original_logster_store_ignore = Logster.store.ignore Logster.store.ignore = [/^Some::StandardError/]