Merge branch 'sh-log-cloudflare-headers' into 'master'

Log Cloudflare request headers

See merge request gitlab-org/gitlab!31532

app/controllers/application_controller.rb

@@ -18,6 +18,7 @@ class ApplicationController < ActionController::Base
   include Gitlab::Tracking::ControllerConcern
   include Gitlab::Experimentation::ControllerConcern
   include InitializesCurrentUserMode
+  include Gitlab::Logging::CloudflareHelper
 
   before_action :authenticate_user!, except: [:route_not_found]
   before_action :enforce_terms!, if: :should_enforce_terms?
@@ -151,6 +152,8 @@ class ApplicationController < ActionController::Base
     end
 
     payload[:queue_duration_s] = request.env[::Gitlab::Middleware::RailsQueueDuration::GITLAB_RAILS_QUEUE_DURATION_KEY]
+
+    store_cloudflare_headers!(payload, request)
   end
 
   ##

changelogs/unreleased/sh-log-cloudflare-headers.yml

+---
+title: Log Cloudflare request headers
+merge_request: 31532
+author:
+type: added

lib/gitlab/grape_logging/loggers/cloudflare_logger.rb

+# frozen_string_literal: true
+
+module Gitlab
+  module GrapeLogging
+    module Loggers
+      class CloudflareLogger < ::GrapeLogging::Loggers::Base
+        include ::Gitlab::Logging::CloudflareHelper
+
+        def parameters(request, _response)
+          data = {}
+          store_cloudflare_headers!(data, request)
+
+          data
+        end
+      end
+    end
+  end
+end

lib/gitlab/logging/cloudflare_helper.rb

+# frozen_string_literal: true
+
+module Gitlab
+  module Logging
+    module CloudflareHelper
+      CLOUDFLARE_CUSTOM_HEADERS = { 'Cf-Ray' => :cf_ray, 'Cf-Request-Id' => :cf_request_id }.freeze
+
+      def store_cloudflare_headers!(payload, request)
+        CLOUDFLARE_CUSTOM_HEADERS.each do |header, value|
+          payload[value] = request.headers[header] if valid_cloudflare_header?(request.headers[header])
+        end
+      end
+
+      def valid_cloudflare_header?(value)
+        return false unless value.present?
+        return false if value.length > 64
+        return false if value.index(/[^[:alnum:]]/)
+
+        true
+      end
+    end
+  end
+end

lib/gitlab/lograge/custom_options.rb

@@ -3,6 +3,8 @@
 module Gitlab
   module Lograge
     module CustomOptions
+      include ::Gitlab::Logging::CloudflareHelper
+
       LIMITED_ARRAY_SENTINEL = { key: 'truncated', value: '...' }.freeze
       IGNORE_PARAMS = Set.new(%w(controller action format)).freeze
 
@@ -31,6 +33,10 @@ module Gitlab
           payload[:cpu_s] = cpu_s.round(2)
         end
 
+        CLOUDFLARE_CUSTOM_HEADERS.each do |_, value|
+          payload[value] = event.payload[value] if event.payload[value]
+        end
+
         # https://github.com/roidrage/lograge#logging-errors--exceptions
         exception = event.payload[:exception_object]
 

spec/lib/gitlab/grape_logging/loggers/cloudflare_logger_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+describe Gitlab::GrapeLogging::Loggers::CloudflareLogger do
+  subject { described_class.new }
+
+  describe "#parameters" do
+    let(:mock_request) { ActionDispatch::Request.new({}) }
+    let(:start_time) { Time.new(2018, 01, 01) }
+
+    describe 'with no Cloudflare headers' do
+      it 'returns an empty hash' do
+        expect(subject.parameters(mock_request, nil)).to eq({})
+      end
+    end
+
+    describe 'with Cloudflare headers' do
+      before do
+        mock_request.headers['Cf-Ray'] = SecureRandom.hex
+        mock_request.headers['Cf-Request-Id'] = SecureRandom.hex
+      end
+
+      it 'returns the correct duration in seconds' do
+        data = subject.parameters(mock_request, nil)
+
+        expect(data.keys).to contain_exactly(:cf_ray, :cf_request_id)
+      end
+    end
+  end
+end

spec/lib/gitlab/logging/cloudflare_helper_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+describe Gitlab::Logging::CloudflareHelper do
+  let(:helper) do
+    Class.new do
+      include Gitlab::Logging::CloudflareHelper
+    end.new
+  end
+
+  describe '#store_cloudflare_headers!' do
+    let(:payload) { {} }
+    let(:env) { {} }
+    let(:request) { ActionDispatch::Request.new(env) }
+
+    before do
+      request.headers.merge!(headers)
+    end
+
+    context 'with normal headers' do
+      let(:headers) { { 'Cf-Ray' => SecureRandom.hex, 'Cf-Request-Id' => SecureRandom.hex } }
+
+      it 'adds Cf-Ray-Id and Cf-Request-Id' do
+        helper.store_cloudflare_headers!(payload, request)
+
+        expect(payload[:cf_ray]).to eq(headers['Cf-Ray'])
+        expect(payload[:cf_request_id]).to eq(headers['Cf-Request-Id'])
+      end
+    end
+
+    context 'with header values with long strings' do
+      let(:headers) { { 'Cf-Ray' => SecureRandom.hex(33), 'Cf-Request-Id' => SecureRandom.hex(33) } }
+
+      it 'filters invalid header values' do
+        helper.store_cloudflare_headers!(payload, request)
+
+        expect(payload.keys).not_to include(:cf_ray, :cf_request_id)
+      end
+    end
+
+    context 'with header values with non-alphanumeric characters' do
+      let(:headers) { { 'Cf-Ray' => "Bad\u0000ray", 'Cf-Request-Id' => "Bad\u0000req" } }
+
+      it 'filters invalid header values' do
+        helper.store_cloudflare_headers!(payload, request)
+
+        expect(payload.keys).not_to include(:cf_ray, :cf_request_id)
+      end
+    end
+  end
+end

spec/lib/gitlab/lograge/custom_options_spec.rb

@@ -19,7 +19,12 @@ describe Gitlab::Lograge::CustomOptions do
         1,
         2,
         'transaction_id',
-        { params: params, user_id: 'test' }
+        {
+          params: params,
+          user_id: 'test',
+          cf_ray: SecureRandom.hex,
+          cf_request_id: SecureRandom.hex
+        }
       )
     end
 
@@ -46,5 +51,10 @@ describe Gitlab::Lograge::CustomOptions do
     it 'adds the user id' do
       expect(subject[:user_id]).to eq('test')
     end
+
+    it 'adds Cloudflare headers' do
+      expect(subject[:cf_ray]).to eq(event.payload[:cf_ray])
+      expect(subject[:cf_request_id]).to eq(event.payload[:cf_request_id])
+    end
   end
 end