diff --git a/ruby/.rubocop_todo.yml b/ruby/.rubocop_todo.yml index 87453d9e6443b3aedf35fbfd1a38f6e561baa6fb..8b0b6d9c0438dd7a906917ac1a1a68025eb2b0ce 100644 --- a/ruby/.rubocop_todo.yml +++ b/ruby/.rubocop_todo.yml @@ -74,6 +74,7 @@ Lint/SuppressedException: # Configuration parameters: AllowUnusedKeywordArguments, IgnoreEmptyMethods, IgnoreNotImplementedMethods. Lint/UnusedMethodArgument: Exclude: + - 'lib/gitaly_server/logging_interceptor.rb' - 'lib/gitaly_server/sentry_interceptor.rb' - 'lib/gitlab/git/conflict/parser.rb' @@ -233,6 +234,7 @@ Style/RedundantSelf: Style/RescueStandardError: Exclude: - 'lib/gitaly_server/exception_sanitizer_interceptor.rb' + - 'lib/gitaly_server/logging_interceptor.rb' - 'lib/gitaly_server/sentry_interceptor.rb' - 'spec/lib/gitaly_server/exception_sanitizer_interceptor_spec.rb' - 'spec/lib/gitaly_server/sentry/url_sanitizer_spec.rb' diff --git a/ruby/bin/gitaly-ruby b/ruby/bin/gitaly-ruby index 257226b57bd857ec60aaac97c829d2f2f5556b0d..ec1d95a73b4054378793856a1c78bd9114851112 100755 --- a/ruby/bin/gitaly-ruby +++ b/ruby/bin/gitaly-ruby @@ -13,6 +13,7 @@ require 'gitlab-labkit' require 'rugged' require_relative '../lib/gitaly_server.rb' +require_relative '../lib/gitaly_server/logging_interceptor.rb' require_relative '../lib/gitaly_server/sentry_interceptor.rb' require_relative '../lib/gitaly_server/exception_sanitizer_interceptor.rb' require_relative '../lib/gitaly_server/rugged_interceptor.rb' @@ -116,6 +117,10 @@ end def build_server_interceptor_chain chain = [] chain << Labkit::Correlation::GRPC::ServerInterceptor.new + chain << GitalyServer::LoggingInterceptor.new( + File.open(File.join(ENV['GITALY_LOG_DIR'], 'gitaly_ruby_json.log'), 'a'), + { type: 'gitaly-ruby' } + ) chain << GitalyServer::SentryInterceptor.new chain << Labkit::Tracing::GRPC::ServerInterceptor.new if Labkit::Tracing.enabled? chain << GitalyServer::ExceptionSanitizerInterceptor.new diff --git a/ruby/lib/gitaly_server/logging_interceptor.rb b/ruby/lib/gitaly_server/logging_interceptor.rb new file mode 100644 index 0000000000000000000000000000000000000000..d69abe2b71f15847de43b72f589adabce7a14229 --- /dev/null +++ b/ruby/lib/gitaly_server/logging_interceptor.rb @@ -0,0 +1,87 @@ +# frozen_string_literal: true + +require 'grpc' +require 'json' + +module GitalyServer + class LoggingInterceptor < GRPC::ServerInterceptor + CODE_STRINGS = { + GRPC::Core::StatusCodes::OK => 'OK', + GRPC::Core::StatusCodes::CANCELLED => 'Canceled', + GRPC::Core::StatusCodes::UNKNOWN => 'Unknown', + GRPC::Core::StatusCodes::INVALID_ARGUMENT => 'InvalidArgument', + GRPC::Core::StatusCodes::DEADLINE_EXCEEDED => 'DeadlineExceeded', + GRPC::Core::StatusCodes::NOT_FOUND => 'NotFound', + GRPC::Core::StatusCodes::ALREADY_EXISTS => 'AlreadyExists', + GRPC::Core::StatusCodes::PERMISSION_DENIED => 'PermissionDenied', + GRPC::Core::StatusCodes::RESOURCE_EXHAUSTED => 'ResourceExhausted', + GRPC::Core::StatusCodes::FAILED_PRECONDITION => 'FailedPrecondition', + GRPC::Core::StatusCodes::ABORTED => 'Aborted', + GRPC::Core::StatusCodes::OUT_OF_RANGE => 'OutOfRange', + GRPC::Core::StatusCodes::UNIMPLEMENTED => 'Unimplemented', + GRPC::Core::StatusCodes::INTERNAL => 'Internal', + GRPC::Core::StatusCodes::UNAVAILABLE => 'Unavailable', + GRPC::Core::StatusCodes::DATA_LOSS => 'DataLoss', + GRPC::Core::StatusCodes::UNAUTHENTICATED => 'Unauthenticated' + }.freeze + + def initialize(log_file, default_tags) + @log_file = log_file + @log_file.sync = true + @default_tags = default_tags + + super() + end + + def request_response(request: nil, call: nil, method: nil) + log_request(method, call) { yield } + end + + def server_streamer(request: nil, call: nil, method: nil) + log_request(method, call) { yield } + end + + def client_streamer(call: nil, method: nil) + log_request(method, call) { yield } + end + + def bidi_streamer(requests: nil, call: nil, method: nil) + log_request(method, call) { yield } + end + + private + + def log_request(method, call, &block) + start = Time.now + code = GRPC::Core::StatusCodes::OK + + block.call + rescue => ex + code = ex.is_a?(GRPC::BadStatus) ? ex.code : GRPC::Core::StatusCodes::UNAVAILABLE + + raise + ensure + message = @default_tags.merge( + { + 'grpc.time_ms': ((Time.now - start) * 1000.0).truncate(3), + 'grpc.code': CODE_STRINGS[code] || code.to_s, + 'grpc.method': method_name(method) || '(Unknown)', + 'grpc.service': method.owner.service_name, + pid: Process.pid, + correlation_id: call.metadata['x-gitlab-correlation-id'], + time: Time.now.utc.strftime('%Y-%m-%dT%H:%M:%S.%LZ') + } + ) + + @log_file.puts(JSON.dump(message)) + end + + def method_name(method) + result, = method.owner.rpc_descs.find do |k, _| + GRPC::GenericService.underscore(k.to_s) == method.name.to_s + end + + result + end + end +end