Adds fetch/xhr interception to e2e tests

In adding request interception, we are able to log api errors as well as wait for fetch requests to finish, which the tests were not previously doing

Adds fetch/xhr interception to e2e tests
In adding request interception, we are able to log api errors as well as wait for fetch requests to finish, which the tests were not previously doing
a5a2a6ed · Sean Gregory · Dan Davison · 4c05bcaf · a5a2a6ed · a5a2a6ed
Commit a5a2a6ed authored Mar 22, 2022 by Sean Gregory Committed by Dan Davison Mar 22, 2022
8 changed files
--- a/qa/qa/fixtures/script_extensions/test.html
+++ b/qa/qa/fixtures/script_extensions/test.html
+<html>
+    <head></head>
+    <body>
+        <h1>Hello world</h1>
+    </body>
+</html>
--- a/qa/qa/runtime/browser.rb
+++ b/qa/qa/runtime/browser.rb
@@ -194,6 +194,8 @@ module QA
        def initialize(instance, page_class)
          @session_address = Runtime::Address.new(instance, page_class)
          @page_class = page_class
+
+          Session.enable_interception if Runtime::Env.can_intercept?
        end

        def url
@@ -255,6 +257,27 @@ module QA
          @network_conditions_configured = false
        end

+        def self.enable_interception
+          script = File.read("#{__dir__}/script_extensions/interceptor.js")
+          command = {
+            cmd: 'Page.addScriptToEvaluateOnNewDocument',
+            params: {
+              source: script
+            }
+          }
+          @interceptor_script_params = Capybara.current_session.driver.browser.send(:bridge).send_command(command)
+        end
+
+        def self.disable_interception
+          return unless @interceptor_script_params
+
+          command = {
+            cmd: 'Page.removeScriptToEvaluateOnNewDocument',
+            params: @interceptor_script_params
+          }
+          Capybara.current_session.driver.browser.send(:bridge).send_command(command)
+        end
+
        private

        def simulate_slow_connection

--- a/qa/qa/runtime/env.rb
+++ b/qa/qa/runtime/env.rb
@@ -37,6 +37,14 @@ module QA
        ENV['QA_PRAEFECT_REPOSITORY_STORAGE']
      end

+      def interception_enabled?
+        enabled?(ENV['INTERCEPT_REQUESTS'], default: true)
+      end
+
+      def can_intercept?
+        browser == :chrome && interception_enabled?
+      end
+
      def ci_job_url
        ENV['CI_JOB_URL']
      end

--- a/qa/qa/runtime/script_extensions/interceptor.js
+++ b/qa/qa/runtime/script_extensions/interceptor.js
+(() => {
+  const CACHE_NAME = 'INTERCEPTOR_CACHE';
+
+  /**
+   * Fetches and parses JSON from the sessionStorage cache
+   * @returns {(Object)}
+   */
+  const getCache = () => {
+    return JSON.parse(sessionStorage.getItem(CACHE_NAME));
+  };
+
+  /**
+   * Commits an object to the sessionStorage cache
+   * @param {Object} data
+   */
+  const saveCache = (data) => {
+    sessionStorage.setItem(CACHE_NAME, JSON.stringify(data));
+  };
+
+  /**
+   * Checks if the cache is available
+   * and if the current context has access to it
+   * @returns {boolean} can we access the cache?
+   */
+  const checkCache = () => {
+    try {
+      getCache();
+      return true;
+    } catch (error) {
+      // eslint-disable-next-line no-console
+      console.warn(`Couldn't access cache: ${error.toString()}`);
+      return false;
+    }
+  };
+
+  /**
+   * @callback cacheCommitCallback
+   * @param {object} cache
+   * @return {object} mutated cache
+   */
+
+  /**
+   * If the cache is available, takes a callback function that is called
+   * with an object returned from getCache,
+   * and saves whatever is returned from the callback function
+   * to the cache
+   * @param {cacheCommitCallback} cb
+   */
+  const commitToCache = (cb) => {
+    if (checkCache()) {
+      const cache = cb(getCache());
+      saveCache(cache);
+    }
+  };
+
+  window.Interceptor = {
+    saveCache,
+    commitToCache,
+    getCache,
+    checkCache,
+    activeFetchRequests: 0,
+  };
+
+  const pureFetch = window.fetch;
+  const pureXHROpen = window.XMLHttpRequest.prototype.open;
+
+  /**
+   * Replacement for XMLHttpRequest.prototype.open
+   * listens for complete xhr events
+   * if the xhr response has a status code higher than 400
+   * then commit request/response metadata to the cache
+   * @param method intercepted HTTP method (GET|POST|etc..)
+   * @param url intercepted HTTP url
+   * @param args intercepted XHR arguments (credentials, headers, options
+   * @return {Promise} the result of the original XMLHttpRequest.prototype.open implementation
+   */
+  function interceptXhr(method, url, ...args) {
+    this.addEventListener(
+      'readystatechange',
+      () => {
+        const self = this;
+        if (this.readyState === XMLHttpRequest.DONE) {
+          if (this.status >= 400 || this.status === 0) {
+            commitToCache((cache) => {
+              // eslint-disable-next-line no-param-reassign
+              cache.errors ||= [];
+              cache.errors.push({
+                status: self.status === 0 ? -1 : self.status,
+                url,
+                method,
+                headers: { 'x-request-id': self.getResponseHeader('x-request-id') },
+              });
+              return cache;
+            });
+          }
+        }
+      },
+      false,
+    );
+    return pureXHROpen.apply(this, [method, url, ...args]);
+  }
+
+  /**
+   * Replacement for fetch implementation
+   * tracks active requests, and commits metadata to the cache
+   * if the response is not ok or was cancelled.
+   * Additionally tracks activeFetchRequests on the Interceptor object
+   * @param url target HTTP url
+   * @param opts fetch options, including request method, body, etc
+   * @param args additional fetch arguments
+   * @returns {Promise<"success"|"error">} the result of the original fetch call
+   */
+  async function interceptedFetch(url, opts, ...args) {
+    const method = opts && opts.method ? opts.method : 'GET';
+    window.Interceptor.activeFetchRequests += 1;
+    try {
+      const response = await pureFetch(url, opts, ...args);
+      window.Interceptor.activeFetchRequests += -1;
+      const clone = response.clone();
+
+      if (!clone.ok) {
+        commitToCache((cache) => {
+          // eslint-disable-next-line no-param-reassign
+          cache.errors ||= [];
+          cache.errors.push({
+            status: clone.status,
+            url,
+            method,
+            headers: { 'x-request-id': clone.headers.get('x-request-id') },
+          });
+          return cache;
+        });
+      }
+      return response;
+    } catch (error) {
+      commitToCache((cache) => {
+        // eslint-disable-next-line no-param-reassign
+        cache.errors ||= [];
+        cache.errors.push({
+          status: -1,
+          url,
+          method,
+        });
+        return cache;
+      });
+
+      window.Interceptor.activeFetchRequests += -1;
+      throw error;
+    }
+  }
+
+  if (checkCache()) {
+    saveCache({});
+  }
+
+  window.fetch = interceptedFetch;
+  window.XMLHttpRequest.prototype.open = interceptXhr;
+})();
--- a/qa/qa/support/page_error_checker.rb
+++ b/qa/qa/support/page_error_checker.rb
@@ -61,6 +61,39 @@ module QA
          end
        end

+        # Log request errors triggered from async api calls from the browser
+        #
+        # If any errors are found in the session, log them
+        # using QA::Runtime::Logger
+        # @param [Capybara::Session] page
+        def log_request_errors(page)
+          return if QA::Runtime::Browser.blank_page?
+
+          url = page.driver.browser.current_url
+          QA::Runtime::Logger.debug "Fetching API error cache for #{url}"
+
+          cache = page.execute_script <<~JS
+            return !(typeof(Interceptor)==="undefined") ? Interceptor.getCache() : null;
+          JS
+
+          return unless cache&.dig('errors')
+
+          grouped_errors = group_errors(cache['errors'])
+
+          errors = grouped_errors.map do |error_metadata, request_id_string|
+            "#{error_metadata} -- #{request_id_string}"
+          end
+
+          unless errors.nil? || errors.empty?
+            QA::Runtime::Logger.error "Interceptor Api Errors\n#{errors.join("\n")}"
+          end
+
+          # clear the cache after logging the errors
+          page.execute_script <<~JS
+            Interceptor && Interceptor.saveCache({});
+          JS
+        end
+
        def error_report_for(logs)
          logs
              .map(&:message)
@@ -70,6 +103,16 @@ module QA
        def logs(page)
          page.driver.browser.manage.logs.get(:browser)
        end
+
+        private
+
+        def group_errors(errors)
+          errors.each_with_object({}) do |error, memo|
+            url = error['url']&.split('?')&.first || 'Unknown url'
+            key = "[#{error['status']}] #{error['method']} #{url}"
+            memo[key] = "Correlation Id: #{error.dig('headers', 'x-request-id') || 'Correlation Id not found'}"
+          end
+        end
      end
    end
  end

--- a/qa/qa/support/wait_for_requests.rb
+++ b/qa/qa/support/wait_for_requests.rb
@@ -16,12 +16,16 @@ module QA
        Waiter.wait_until(log: false) do
          finished_all_ajax_requests? && (!skip_finished_loading_check ? finished_loading?(wait: 1) : true)
        end
+        QA::Support::PageErrorChecker.log_request_errors(Capybara.page) if QA::Runtime::Env.can_intercept?
      rescue Repeater::WaitExceededError
        raise $!, 'Page did not fully load. This could be due to an unending async request or loading icon.'
      end

      def finished_all_ajax_requests?
-        Capybara.page.evaluate_script('window.pendingRequests || window.pendingRailsUJSRequests || 0').zero? # rubocop:disable Style/NumericPredicate
+        requests = %w[window.pendingRequests window.pendingRailsUJSRequests 0]
+        requests.unshift('(window.Interceptor && window.Interceptor.activeFetchRequests)') if Runtime::Env.can_intercept?
+        script = requests.join(' || ')
+        Capybara.page.evaluate_script(script).zero? # rubocop:disable Style/NumericPredicate
      end

      def finished_loading?(wait: DEFAULT_MAX_WAIT_TIME)

--- a/qa/spec/runtime/script_extensions/interceptor_spec.rb
+++ b/qa/spec/runtime/script_extensions/interceptor_spec.rb
+# frozen_string_literal: true
+
+RSpec.describe 'Interceptor' do
+  let(:browser) { Capybara.current_session }
+  # need a real host for the js runtime
+  let(:url) { "file://#{__dir__}/../../../qa/fixtures/script_extensions/test.html" }
+
+  before(:context) do
+    skip 'Only can test for chrome' unless QA::Runtime::Env.can_intercept?
+
+    QA::Runtime::Browser::Session.enable_interception
+  end
+
+  after(:context) do
+    QA::Runtime::Browser::Session.disable_interception
+  end
+
+  before do
+    browser.visit url
+
+    clear_cache
+  end
+
+  after do
+    browser.visit 'about:blank'
+  end
+
+  context 'with Interceptor' do
+    context 'caching' do
+      it 'checks the cache' do
+        expect(check_cache).to be(true)
+      end
+
+      it 'returns false if the cache cannot be accessed' do
+        browser.visit 'about:blank'
+
+        expect(check_cache).to be(false)
+      end
+
+      it 'gets and sets the cache data' do
+        commit_to_cache({ foo: 'bar' })
+
+        expect(get_cache['data']).to eql({ 'foo' => 'bar' })
+      end
+    end
+
+    context 'when intercepting' do
+      let(:resource_url) { 'chrome://chrome-urls' }
+
+      it 'intercepts fetch errors' do
+        trigger_fetch(resource_url, 'GET')
+
+        errors = get_cache['errors']
+
+        expect(errors.size).to be(1)
+        expect(errors[0]['status']).to be(-1)
+        expect(errors[0]['method']).to eql('GET')
+        expect(errors[0]['url']).to eql(resource_url)
+      end
+
+      it 'intercepts xhr' do
+        trigger_xhr(resource_url, 'POST')
+
+        errors = get_cache['errors']
+
+        expect(errors.size).to be(1)
+        expect(errors[0]['status']).to be(-1)
+        expect(errors[0]['method']).to eql('POST')
+        expect(errors[0]['url']).to eql(resource_url)
+      end
+    end
+  end
+
+  def clear_cache
+    browser.execute_script <<~JS
+      Interceptor.saveCache({})
+    JS
+  end
+
+  def check_cache
+    browser.execute_script <<~JS
+      return Interceptor.checkCache()
+    JS
+  end
+
+  def trigger_fetch(url, method)
+    browser.execute_script <<~JS
+      (() => {
+        fetch('#{url}', { method: '#{method}' })
+      })()
+    JS
+  end
+
+  def trigger_xhr(url, method)
+    browser.execute_script <<~JS
+      (() => {
+        let xhr = new XMLHttpRequest();
+        xhr.open('#{method}', '#{url}')
+        xhr.send()
+      })()
+    JS
+  end
+
+  def commit_to_cache(payload)
+    browser.execute_script <<~JS
+      Interceptor.commitToCache((cache) => {
+        cache.data = JSON.parse('#{payload.to_json}');
+        return cache
+      })
+    JS
+  end
+
+  def get_cache
+    browser.execute_script <<~JS
+      return Interceptor.getCache()
+    JS
+  end
+end
--- a/qa/spec/support/page_error_checker_spec.rb
+++ b/qa/spec/support/page_error_checker_spec.rb
@@ -238,6 +238,88 @@ RSpec.describe QA::Support::PageErrorChecker do
    end
  end

+  describe '::log_request_errors' do
+    let(:page_url) { 'https://baz.foo' }
+    let(:browser) { double('browser', current_url: page_url) }
+    let(:driver) { double('driver', browser: browser) }
+    let(:session) { double('session', driver: driver) }
+
+    before do
+      allow(Capybara).to receive(:current_session).and_return(session)
+    end
+
+    it 'logs from the error cache' do
+      error = {
+        'url' => 'https://foo.bar',
+        'status' => 500,
+        'method' => 'GET',
+        'headers' => { 'x-request-id' => '12345' }
+      }
+
+      expect(page).to receive(:driver).and_return(driver)
+      expect(page).to receive(:execute_script).and_return({ 'errors' => [error] })
+      expect(page).to receive(:execute_script)
+
+      expect(QA::Runtime::Logger).to receive(:debug).with("Fetching API error cache for #{page_url}")
+      expect(QA::Runtime::Logger).to receive(:error).with(<<~ERROR.chomp)
+        Interceptor Api Errors
+        [500] GET https://foo.bar -- Correlation Id: 12345
+      ERROR
+
+      QA::Support::PageErrorChecker.log_request_errors(page)
+    end
+
+    it 'removes duplicates' do
+      error = {
+        'url' => 'https://foo.bar',
+        'status' => 500,
+        'method' => 'GET',
+        'headers' => { 'x-request-id' => '12345' }
+      }
+      expect(page).to receive(:driver).and_return(driver)
+      expect(page).to receive(:execute_script).and_return({ 'errors' => [error, error, error] })
+      expect(page).to receive(:execute_script)
+
+      expect(QA::Runtime::Logger).to receive(:debug).with("Fetching API error cache for #{page_url}")
+      expect(QA::Runtime::Logger).to receive(:error).with(<<~ERROR.chomp).exactly(1).time
+        Interceptor Api Errors
+        [500] GET https://foo.bar -- Correlation Id: 12345
+      ERROR
+
+      QA::Support::PageErrorChecker.log_request_errors(page)
+    end
+
+    it 'chops the url query string' do
+      error = {
+        'url' => 'https://foo.bar?query={ sensitive-data: 12345 }',
+        'status' => 500,
+        'method' => 'GET',
+        'headers' => { 'x-request-id' => '12345' }
+      }
+      expect(page).to receive(:driver).and_return(driver)
+      expect(page).to receive(:execute_script).and_return({ 'errors' => [error] })
+      expect(page).to receive(:execute_script)
+
+      expect(QA::Runtime::Logger).to receive(:debug).with("Fetching API error cache for #{page_url}")
+      expect(QA::Runtime::Logger).to receive(:error).with(<<~ERROR.chomp)
+        Interceptor Api Errors
+        [500] GET https://foo.bar -- Correlation Id: 12345
+      ERROR
+
+      QA::Support::PageErrorChecker.log_request_errors(page)
+    end
+
+    it 'returns if cache is nil' do
+      expect(page).to receive(:driver).and_return(driver)
+      expect(page).to receive(:execute_script).and_return(nil)
+
+      expect(QA::Runtime::Logger).to receive(:debug).with("Fetching API error cache for #{page_url}")
+      expect(QA::Runtime::Logger).not_to receive(:error)
+
+      QA::Support::PageErrorChecker.log_request_errors(page)
+    end
+  end
+
  describe '.logs' do
    before do
      logs_class = Class.new do