diff options
author | Stan Hu <stanhu@gmail.com> | 2018-04-01 00:46:52 -0700 |
---|---|---|
committer | Stan Hu <stanhu@gmail.com> | 2018-04-04 05:04:00 -0700 |
commit | 6415ac9e994640474eaa5b0fee3914934d85b35b (patch) | |
tree | 2640006fbc3745039799bb76bf8a654f5ce592c0 /lib | |
parent | eaed588bf228c833cb666a61bc7d25cf21d5f94b (diff) | |
download | gitlab-ce-6415ac9e994640474eaa5b0fee3914934d85b35b.tar.gz |
Add support for Sidekiq JSON logging
Closes #20060
Diffstat (limited to 'lib')
-rw-r--r-- | lib/gitlab/sidekiq_logging/json_formatter.rb | 21 | ||||
-rw-r--r-- | lib/gitlab/sidekiq_logging/structured_logger.rb | 96 |
2 files changed, 117 insertions, 0 deletions
diff --git a/lib/gitlab/sidekiq_logging/json_formatter.rb b/lib/gitlab/sidekiq_logging/json_formatter.rb new file mode 100644 index 00000000000..98f8222fd03 --- /dev/null +++ b/lib/gitlab/sidekiq_logging/json_formatter.rb @@ -0,0 +1,21 @@ +module Gitlab + module SidekiqLogging + class JSONFormatter + def call(severity, timestamp, progname, data) + output = { + severity: severity, + time: timestamp.utc.iso8601(3) + } + + case data + when String + output[:message] = data + when Hash + output.merge!(data) + end + + output.to_json + "\n" + end + end + end +end diff --git a/lib/gitlab/sidekiq_logging/structured_logger.rb b/lib/gitlab/sidekiq_logging/structured_logger.rb new file mode 100644 index 00000000000..9a89ae70b98 --- /dev/null +++ b/lib/gitlab/sidekiq_logging/structured_logger.rb @@ -0,0 +1,96 @@ +module Gitlab + module SidekiqLogging + class StructuredLogger + START_TIMESTAMP_FIELDS = %w[created_at enqueued_at].freeze + DONE_TIMESTAMP_FIELDS = %w[started_at retried_at failed_at completed_at].freeze + + def call(job, queue) + started_at = current_time + base_payload = parse_job(job) + + Sidekiq.logger.info log_job_start(started_at, base_payload) + + yield + + Sidekiq.logger.info log_job_done(started_at, base_payload) + rescue => job_exception + Sidekiq.logger.warn log_job_done(started_at, base_payload, job_exception) + + raise + end + + private + + def base_message(payload) + "#{payload['class']} JID-#{payload['jid']}" + end + + def log_job_start(started_at, payload) + payload['message'] = "#{base_message(payload)}: start" + payload['job_status'] = 'start' + + payload + end + + def log_job_done(started_at, payload, job_exception = nil) + payload = payload.dup + payload['duration'] = elapsed(started_at) + payload['completed_at'] = Time.now.utc + + message = base_message(payload) + + if job_exception + payload['message'] = "#{message}: fail: #{payload['duration']} sec" + payload['job_status'] = 'fail' + payload['error_message'] = job_exception.message + payload['error'] = job_exception.class + payload['error_backtrace'] = backtrace_cleaner.clean(job_exception.backtrace) + else + payload['message'] = "#{message}: done: #{payload['duration']} sec" + payload['job_status'] = 'done' + end + + convert_to_iso8601(payload, DONE_TIMESTAMP_FIELDS) + + payload + end + + def parse_job(job) + job = job.dup + + # Add process id params + job['pid'] = ::Process.pid + + job.delete('args') unless ENV['SIDEKIQ_LOG_ARGUMENTS'] + + convert_to_iso8601(job, START_TIMESTAMP_FIELDS) + + job + end + + def convert_to_iso8601(payload, keys) + keys.each do |key| + payload[key] = format_time(payload[key]) if payload[key] + end + end + + def elapsed(start) + (current_time - start).round(3) + end + + def current_time + Gitlab::Metrics::System.monotonic_time + end + + def backtrace_cleaner + @backtrace_cleaner ||= ActiveSupport::BacktraceCleaner.new + end + + def format_time(timestamp) + return timestamp if timestamp.is_a?(String) + + Time.at(timestamp).utc.iso8601(3) + end + end + end +end |