Merge branch 'sh-log-token-failure-data-16-6' into '16-6-stable-ee'

Backport token logging improvements

See merge request https://gitlab.com/gitlab-org/gitlab/-/merge_requests/158525



Merged-by: John Skarbek <jskarbek@gitlab.com>
Approved-by: Imre Farkas <ifarkas@gitlab.com>
Approved-by: Sofia Vistas <svistas@gitlab.com>
Co-authored-by: Alex Pooley <apooley@gitlab.com>
Co-authored-by: Dylan Griffith <dyl.griffith@gmail.com>
Co-authored-by: Imre Farkas <ifarkas@gitlab.com>
Co-authored-by: GitLab Release Tools Bot <delivery-team+release-tools@gitlab.com>
Co-authored-by: Aboobacker MK <akarakath@gitlab.com>

app/channels/application_cable/channel.rb

@@ -3,6 +3,15 @@
 module ApplicationCable
   class Channel < ActionCable::Channel::Base
     include Logging
+    include Gitlab::Auth::AuthFinders
+
+    before_subscribe :validate_token_scope
+
+    def validate_token_scope
+      validate_and_save_access_token!(scopes: [:api, :read_api])
+    rescue Gitlab::Auth::AuthenticationError
+      reject
+    end
     private

app/channels/application_cable/connection.rb

@@ -3,13 +3,16 @@
 module ApplicationCable
   class Connection < ActionCable::Connection::Base
     include Logging
+    include Gitlab::Auth::AuthFinders
     identified_by :current_user
     public :request
     def connect
-      self.current_user = find_user_from_session_store
+      self.current_user = find_user_from_bearer_token || find_user_from_session_store
+    rescue Gitlab::Auth::AuthenticationError
+      reject_unauthorized_connection
     end
     private

app/channels/graphql_channel.rb

@@ -48,7 +48,8 @@ def unsubscribed
   # Objects added to the context may also need to be reloaded in
   # `Subscriptions::BaseSubscription` so that they are not stale
   def context
-    # is_sessionless_user is always false because we only support cookie auth in ActionCable
-    { channel: self, current_user: current_user, is_sessionless_user: false }
+    request_authenticator = Gitlab::Auth::RequestAuthenticator.new(request)
+    scope_validator = ::Gitlab::Auth::ScopeValidator.new(current_user, request_authenticator)
+    { channel: self, current_user: current_user, is_sessionless_user: false, scope_validator: scope_validator }
   end
 end

app/graphql/mutations/admin/sidekiq_queues/delete_jobs.rb

@@ -8,7 +8,7 @@ class DeleteJobs < BaseMutation
         ADMIN_MESSAGE = 'You must be an admin to use this mutation'
-        ::Gitlab::ApplicationContext.known_keys.each do |key|
+        ::Gitlab::ApplicationContext.allowed_job_keys.each do |key|
           argument key,
                    GraphQL::Types::String,
                    required: false,

app/graphql/resolvers/base_resolver.rb

@@ -174,7 +174,7 @@ def self.authorization
     end
     def self.authorized?(object, context)
-      authorization.ok?(object, context[:current_user])
+      authorization.ok?(object, context[:current_user], scope_validator: context[:scope_validator])
     end
   end
 end

app/graphql/types/base_enum.rb

@@ -65,7 +65,7 @@ def authorize(*abilities)
       end
       def authorized?(object, context)
-        authorization.ok?(object, context[:current_user])
+        authorization.ok?(object, context[:current_user], scope_validator: context[:scope_validator])
       end
     end
   end

app/graphql/types/base_field.rb

@@ -97,7 +97,7 @@ def constant_complexity?
     def field_authorized?(object, ctx)
       object = object.node if object.is_a?(GraphQL::Pagination::Connection::Edge)
-      authorization.ok?(object, ctx[:current_user])
+      authorization.ok?(object, ctx[:current_user], scope_validator: ctx[:scope_validator])
     end
     # Historically our resolvers have used declarative permission checks only

app/graphql/types/base_object.rb

@@ -32,7 +32,7 @@ def self.authorization
     end
     def self.authorized?(object, context)
-      authorization.ok?(object, context[:current_user])
+      authorization.ok?(object, context[:current_user], scope_validator: context[:scope_validator])
     end
     def current_user

lib/api/helpers.rb

@@ -16,7 +16,6 @@ module Helpers
     GITLAB_SHELL_JWT_ISSUER = "gitlab-shell"
     SUDO_PARAM = :sudo
     API_USER_ENV = 'gitlab.api.user'
-    API_TOKEN_ENV = 'gitlab.api.token'
     API_EXCEPTION_ENV = 'gitlab.api.exception'
     API_RESPONSE_STATUS_CODE = 'gitlab.api.response_status_code'
     INTEGER_ID_REGEX = /^-?\d+$/
@@ -85,12 +84,10 @@ def current_user
       sudo!
-      validate_access_token!(scopes: scopes_registered_for_endpoint) unless sudo?
+      validate_and_save_access_token!(scopes: scopes_registered_for_endpoint) unless sudo?
       save_current_user_in_env(@current_user) if @current_user
-      save_current_token_in_env
-
       if @current_user
         load_balancer_stick_request(::ApplicationRecord, :user, @current_user.id)
       end
@@ -103,13 +100,6 @@ def save_current_user_in_env(user)
       env[API_USER_ENV] = { user_id: user.id, username: user.username }
     end
-    def save_current_token_in_env
-      token = access_token
-      env[API_TOKEN_ENV] = { token_id: token.id, token_type: token.class } if token
-
-    rescue Gitlab::Auth::UnauthorizedError
-    end
-
     def sudo?
       initial_current_user != current_user
     end
@@ -820,7 +810,7 @@ def sudo!
         forbidden!('Must be authenticated using an OAuth or Personal Access Token to use sudo')
       end
-      validate_access_token!(scopes: [:sudo])
+      validate_and_save_access_token!(scopes: [:sudo])
       sudoed_user = find_user(sudo_identifier)
       not_found!("User with ID or username '#{sudo_identifier}'") unless sudoed_user

lib/api/helpers/kubernetes/agent_helpers.rb

@@ -100,7 +100,7 @@ def retrieve_user_from_session_cookie
         def retrieve_user_from_personal_access_token
           return unless access_token.present?
-          validate_access_token!(scopes: [Gitlab::Auth::K8S_PROXY_SCOPE])
+          validate_and_save_access_token!(scopes: [Gitlab::Auth::K8S_PROXY_SCOPE])
           ::PersonalAccessTokens::LastUsedService.new(access_token).execute

lib/gitlab/application_context.rb

@@ -26,10 +26,18 @@ class ApplicationContext
       :artifacts_dependencies_size,
       :artifacts_dependencies_count,
       :root_caller_id,
-      :merge_action_status
+      :merge_action_status,
+      :auth_fail_reason,
+      :auth_fail_token_id
     ].freeze
     private_constant :KNOWN_KEYS
+    WEB_ONLY_KEYS = [
+      :auth_fail_reason,
+      :auth_fail_token_id
+    ].freeze
+    private_constant :WEB_ONLY_KEYS
+
     APPLICATION_ATTRIBUTES = [
       Attribute.new(:project, Project),
       Attribute.new(:namespace, Namespace),
@@ -45,7 +53,9 @@ class ApplicationContext
       Attribute.new(:artifacts_dependencies_size, Integer),
       Attribute.new(:artifacts_dependencies_count, Integer),
       Attribute.new(:root_caller_id, String),
-      Attribute.new(:merge_action_status, String)
+      Attribute.new(:merge_action_status, String),
+      Attribute.new(:auth_fail_reason, String),
+      Attribute.new(:auth_fail_token_id, String)
     ].freeze
     private_constant :APPLICATION_ATTRIBUTES
@@ -53,6 +63,12 @@ def self.known_keys
       KNOWN_KEYS
     end
+    # Sidekiq jobs may be deleted by matching keys in ApplicationContext.
+    # Filter out keys that aren't available in Sidekiq jobs.
+    def self.allowed_job_keys
+      known_keys - WEB_ONLY_KEYS
+    end
+
     def self.application_attributes
       APPLICATION_ATTRIBUTES
     end
@@ -106,6 +122,8 @@ def to_lazy_hash
         assign_hash_if_value(hash, :artifacts_dependencies_size)
         assign_hash_if_value(hash, :artifacts_dependencies_count)
         assign_hash_if_value(hash, :merge_action_status)
+        assign_hash_if_value(hash, :auth_fail_reason)
+        assign_hash_if_value(hash, :auth_fail_token_id)
         hash[:user] = -> { username } if include_user?
         hash[:user_id] = -> { user_id } if include_user?

lib/gitlab/auth/auth_finders.rb

@@ -23,6 +23,7 @@ module AuthFinders
       include ActionController::HttpAuthentication::Basic
       include ActionController::HttpAuthentication::Token
+      API_TOKEN_ENV = 'gitlab.api.token'
       PRIVATE_TOKEN_HEADER = 'HTTP_PRIVATE_TOKEN'
       PRIVATE_TOKEN_PARAM = :private_token
       JOB_TOKEN_HEADER = 'HTTP_JOB_TOKEN'
@@ -123,7 +124,7 @@ def find_user_from_lfs_token
       def find_user_from_personal_access_token
         return unless access_token
-        validate_access_token!
+        validate_and_save_access_token!
         access_token&.user || raise(UnauthorizedError)
       end
@@ -137,7 +138,7 @@ def find_user_from_personal_access_token
       def find_user_from_web_access_token(request_format, scopes: [:api])
         return unless access_token && valid_web_access_format?(request_format)
-        validate_access_token!(scopes: scopes)
+        validate_and_save_access_token!(scopes: scopes)
         ::PersonalAccessTokens::LastUsedService.new(access_token).execute
@@ -147,7 +148,7 @@ def find_user_from_web_access_token(request_format, scopes: [:api])
       def find_user_from_access_token
         return unless access_token
-        validate_access_token!
+        validate_and_save_access_token!
         ::PersonalAccessTokens::LastUsedService.new(access_token).execute
@@ -192,7 +193,7 @@ def find_runner_from_token
         ::Ci::Runner.find_by_token(token) || raise(UnauthorizedError)
       end
-      def validate_access_token!(scopes: [])
+      def validate_and_save_access_token!(scopes: [], save_auth_context: true)
         # return early if we've already authenticated via a job token
         return if @current_authenticated_job.present? # rubocop:disable Gitlab/ModuleWithInstanceVariables
@@ -203,16 +204,22 @@ def validate_access_token!(scopes: [])
         case AccessTokenValidationService.new(access_token, request: request).validate(scopes: scopes)
         when AccessTokenValidationService::INSUFFICIENT_SCOPE
+          save_auth_failure_in_application_context(access_token, :insufficient_scope) if save_auth_context
           raise InsufficientScopeError, scopes
         when AccessTokenValidationService::EXPIRED
+          save_auth_failure_in_application_context(access_token, :token_expired) if save_auth_context
           raise ExpiredError
         when AccessTokenValidationService::REVOKED
+          save_auth_failure_in_application_context(access_token, :token_revoked) if save_auth_context
           revoke_token_family(access_token)
           raise RevokedError
         when AccessTokenValidationService::IMPERSONATION_DISABLED
+          save_auth_failure_in_application_context(access_token, :impersonation_disabled) if save_auth_context
           raise ImpersonationDisabled
         end
+
+        save_current_token_in_env
       end
       def authentication_token_present?
@@ -223,6 +230,16 @@ def authentication_token_present?
       private
+      def save_current_token_in_env
+        request.env[API_TOKEN_ENV] = { token_id: access_token.id, token_type: access_token.class.to_s }
+      end
+
+      def save_auth_failure_in_application_context(access_token, cause)
+        Gitlab::ApplicationContext.push(
+          auth_fail_reason: cause.to_s,
+          auth_fail_token_id: "#{access_token.class}/#{access_token.id}")
+      end
+
       def find_user_from_job_bearer_token
         return unless route_authentication_setting[:job_token_allowed]

lib/gitlab/auth/request_authenticator.rb

@@ -70,7 +70,9 @@ def find_user_from_personal_access_token_for_api_or_git
       end
       def valid_access_token?(scopes: [])
-        validate_access_token!(scopes: scopes)
+        # We may just be checking whether the user has :admin_mode access, so
+        # don't construe an auth failure as a real failure.
+        validate_and_save_access_token!(scopes: scopes, save_auth_context: false)
         true
       rescue Gitlab::Auth::AuthenticationError

lib/gitlab/grape_logging/loggers/token_logger.rb

@@ -5,7 +5,7 @@ module GrapeLogging
     module Loggers
       class TokenLogger < ::GrapeLogging::Loggers::Base
         def parameters(request, _)
-          params = request.env[::API::Helpers::API_TOKEN_ENV]
+          params = request.env[::Gitlab::Auth::AuthFinders::API_TOKEN_ENV]
           return {} unless params

lib/gitlab/graphql/authorize/authorize_resource.rb

@@ -64,7 +64,7 @@ def authorize!(object)
         def authorized_resource?(object)
           raise ConfigurationError, "#{self.class.name} has no authorizations" if self.class.authorization.none?
-          self.class.authorization.ok?(object, current_user)
+          self.class.authorization.ok?(object, current_user, scope_validator: context[:scope_validator])
         end
         def raise_resource_not_available_error!(...)

lib/gitlab/graphql/authorize/object_authorization.rb

@@ -19,7 +19,7 @@ def any?
           abilities.present?
         end
-        def ok?(object, current_user, scope_validator: nil)
+        def ok?(object, current_user, scope_validator:)
           scopes_ok?(scope_validator) && abilities_ok?(object, current_user)
         end

lib/gitlab/graphql/tracers/logger_tracer.rb

@@ -40,6 +40,9 @@ def log_execute_query(query: nil, duration_s: 0, exception: nil)
             query_string: query.query_string
           }
+          token_info = auth_token_info(query)
+          info.merge!(token_info) if token_info
+
           Gitlab::ExceptionLogFormatter.format!(exception, info)
           info.merge!(::Gitlab::ApplicationContext.current)
@@ -48,6 +51,13 @@ def log_execute_query(query: nil, duration_s: 0, exception: nil)
           ::Gitlab::GraphqlLogger.info(info)
         end
+        def auth_token_info(query)
+          request_env = query.context[:request]&.env
+          return unless request_env
+
+          request_env[::Gitlab::Auth::AuthFinders::API_TOKEN_ENV]
+        end
+
         def clean_variables(variables)
           filtered = ActiveSupport::ParameterFilter
             .new(::Rails.application.config.filter_parameters)

lib/gitlab/sidekiq_queue.rb

@@ -8,7 +8,7 @@ class SidekiqQueue
     InvalidQueueError = Class.new(StandardError)
     WORKER_KEY = 'worker_class'
-    ALLOWED_KEYS = Gitlab::ApplicationContext.known_keys.map(&:to_s) + [WORKER_KEY]
+    ALLOWED_KEYS = Gitlab::ApplicationContext.allowed_job_keys.map(&:to_s) + [WORKER_KEY]
     attr_reader :queue_name

spec/channels/application_cable/connection_spec.rb

@@ -43,6 +43,91 @@
     end
   end
+  context 'when bearer header is provided' do
+    context 'when it is a personal_access_token' do
+      let(:user_pat) { create(:personal_access_token) }
+      let(:app_context) { Gitlab::ApplicationContext.current }
+      let_it_be(:expired_token) { create(:personal_access_token, :expired, scopes: %w[read_api]) }
+      let_it_be(:revoked_token) { create(:personal_access_token, :revoked, scopes: %w[read_api]) }
+
+      it 'finds user by PAT' do
+        connect(ActionCable.server.config.mount_path, headers: { Authorization: "Bearer #{user_pat.token}" })
+
+        expect(connection.current_user).to eq(user_pat.user)
+      end
+
+      context 'when an expired personal_access_token' do
+        let_it_be(:user_pat) { expired_token }
+
+        it 'sets the current_user as `nil`, and rejects the connection' do
+          expect do
+            connect(ActionCable.server.config.mount_path,
+              headers: { Authorization: "Bearer #{user_pat.token}" }
+            )
+          end.to have_rejected_connection
+
+          expect(connection.current_user).to be_nil
+          expect(app_context['meta.auth_fail_reason']).to eq('token_expired')
+          expect(app_context['meta.auth_fail_token_id']).to eq("PersonalAccessToken/#{user_pat.id}")
+        end
+      end
+
+      context 'when a revoked personal_access_token' do
+        let_it_be(:user_pat) { revoked_token }
+
+        it 'sets the current_user as `nil`, and rejects the connection' do
+          expect do
+            connect(ActionCable.server.config.mount_path,
+              headers: { Authorization: "Bearer #{user_pat.token}" }
+            )
+          end.to have_rejected_connection
+
+          expect(connection.current_user).to be_nil
+          expect(app_context['meta.auth_fail_reason']).to eq('token_revoked')
+          expect(app_context['meta.auth_fail_token_id']).to eq("PersonalAccessToken/#{user_pat.id}")
+        end
+      end
+    end
+
+    context 'when it is an OAuth access token' do
+      context 'when it is a valid OAuth access token' do
+        let(:user) { create(:user) }
+
+        let(:application) do
+          Doorkeeper::Application.create!(name: "MyApp", redirect_uri: "https://app.com", owner: user)
+        end
+
+        let(:oauth_token) do
+          create(:oauth_access_token,
+            application_id: application.id,
+            resource_owner_id: user.id,
+            scopes: "api"
+          )
+        end
+
+        it 'finds user by OAuth access token' do
+          connect(ActionCable.server.config.mount_path, headers: {
+            'Authorization' => "Bearer #{oauth_token.plaintext_token}"
+          })
+
+          expect(connection.current_user).to eq(oauth_token.user)
+        end
+      end
+
+      context 'when it is an invalid OAuth access token' do
+        it 'sets the current_user as `nil`, and rejects the connection' do
+          expect do
+            connect(ActionCable.server.config.mount_path, headers: {
+              'Authorization' => "Bearer invalid_token"
+            })
+          end.to have_rejected_connection
+
+          expect(connection.current_user).to be_nil
+        end
+      end
+    end
+  end
+
   context 'when session cookie is not set' do
     it 'sets current_user to nil' do
       connect

spec/channels/graphql_channel_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+RSpec.describe GraphqlChannel, feature_category: :api do
+  let_it_be(:merge_request) { create(:merge_request) }
+  let_it_be(:user) { create(:user).tap { |u| merge_request.project.add_developer(u) } }
+  let_it_be(:read_api_token) { create(:personal_access_token, scopes: ['read_api'], user: user) }
+  let_it_be(:read_user_token) { create(:personal_access_token, scopes: ['read_user'], user: user) }
+  let_it_be(:read_api_and_read_user_token) do
+    create(:personal_access_token, scopes: %w[read_user read_api], user: user)
+  end
+
+  let_it_be(:expired_token) { create(:personal_access_token, :expired, scopes: %w[read_api], user: user) }
+  let_it_be(:revoked_token) { create(:personal_access_token, :revoked, scopes: %w[read_api], user: user) }
+
+  describe '#subscribed' do
+    let(:query) do
+      <<~GRAPHQL
+      subscription mergeRequestReviewersUpdated($issuableId: IssuableID!) {
+        mergeRequestReviewersUpdated(issuableId: $issuableId) {
+          ... on MergeRequest { id title }
+        }
+      }
+      GRAPHQL
+    end
+
+    let(:subscribe_params) do
+      {
+        query: query,
+        variables: { issuableId: merge_request.to_global_id }
+      }
+    end
+
+    before do
+      stub_action_cable_connection current_user: user
+    end
+
+    it 'subscribes to the given graphql subscription' do
+      subscribe(subscribe_params)
+
+      expect(subscription).to be_confirmed
+      expect(subscription.streams).to include(/graphql-event::mergeRequestReviewersUpdated:issuableId/)
+    end
+
+    context 'with a personal access token' do
+      let(:app_context) { Gitlab::ApplicationContext.current }
+
+      before do
+        stub_action_cable_connection current_user: user, access_token: access_token
+      end
+
+      context 'with an api scoped personal access token' do
+        let(:access_token) { read_api_token }
+
+        it 'subscribes to the given graphql subscription' do
+          subscribe(subscribe_params)
+
+          expect(subscription).to be_confirmed
+          expect(subscription.streams).to include(/graphql-event::mergeRequestReviewersUpdated:issuableId/)
+          expect(app_context.keys).not_to include('meta.auth_fail_reason', 'meta.auth_fail_token_id')
+        end
+      end
+
+      context 'with a read_user personal access token' do
+        let(:access_token) { read_user_token }
+
+        it 'does not subscribe to the given graphql subscription' do
+          subscribe(subscribe_params)
+
+          expect(subscription).not_to be_confirmed
+          expect(app_context['meta.auth_fail_reason']).to eq('insufficient_scope')
+          expect(app_context['meta.auth_fail_token_id']).to eq("PersonalAccessToken/#{access_token.id}")
+        end
+      end
+
+      context 'with a read_api and read_user personal access token' do
+        let(:access_token) { read_api_and_read_user_token }
+
+        it 'subscribes to the given graphql subscription' do
+          subscribe(subscribe_params)
+
+          expect(subscription).to be_confirmed
+          expect(subscription.streams).to include(/graphql-event::mergeRequestReviewersUpdated:issuableId/)
+          expect(app_context.keys).not_to include('meta.auth_fail_reason', 'meta.auth_fail_token_id')
+        end
+      end
+
+      context 'with an expired read_user personal access token' do
+        let(:access_token) { expired_token }
+
+        it 'does not subscribe to the given graphql subscription' do
+          subscribe(subscribe_params)
+
+          expect(subscription).not_to be_confirmed
+          expect(app_context['meta.auth_fail_reason']).to eq('token_expired')
+          expect(app_context['meta.auth_fail_token_id']).to eq("PersonalAccessToken/#{access_token.id}")
+        end
+      end
+
+      context 'with a revoked read_user personal access token' do
+        let(:access_token) { revoked_token }
+
+        it 'does not subscribe to the given graphql subscription' do
+          subscribe(subscribe_params)
+
+          expect(subscription).not_to be_confirmed
+          expect(app_context['meta.auth_fail_reason']).to eq('token_revoked')
+          expect(app_context['meta.auth_fail_token_id']).to eq("PersonalAccessToken/#{access_token.id}")
+        end
+      end
+    end
+  end
+end