Log page actions

Override page object methods to log the actions taken by the methods
before or after the action, as appropriate.

Allow page object action logging to be turned on via a QA_DEBUG env var.
Unlike CHROME_HEADLESS (and the soon to arrive VERBOSE), QA_DEBUG
is false by default.

QA_DEBUG is used instead of just DEBUG because that enables Selenium
debug logging.

Mask passwords entered into fields with a QA selector with 'password'
in the name. Doesn't mask sensitive data entered into any other field.

qa/qa.rb

@@ -317,6 +317,16 @@ module QA
       end
     end
   end
+
+  # Classes that provide support to other parts of the framework.
+  #
+  module Support
+    autoload :Logger, 'qa/support/logger'
+
+    module Page
+      autoload :Logging, 'qa/support/page/logging'
+    end
+  end
 end
 QA::Runtime::Release.extend_autoloads!

qa/qa/page/base.rb

@@ -5,6 +5,7 @@ require 'capybara/dsl'
 module QA
   module Page
     class Base
+      prepend Support::Page::Logging if Runtime::Env.debug?
       include Capybara::DSL
       include Scenario::Actable
       extend SingleForwardable

qa/qa/runtime/env.rb

+# frozen_string_literal: true
+
 module QA
   module Runtime
     module Env
       extend self
+      def debug?
+        enabled?(ENV['QA_DEBUG'], default: false)
+      end
+
+      def log_destination
+        ENV['QA_LOG_PATH'] || STDOUT
+      end
+
       # set to 'false' to have Chrome run visibly instead of headless
       def chrome_headless?
         enabled?(ENV['CHROME_HEADLESS'])

qa/qa/support/logger.rb

+# frozen_string_literal: true
+
+require 'active_support/core_ext/module/delegation'
+require 'logger'
+
+module QA
+  module Support
+    class Logger
+      class << self
+        delegate :debug, :info, :error, :warn, :fatal, :unknown, to: :logger
+
+        def logger
+          return @logger unless @logger.nil?
+          @logger = ::Logger.new Runtime::Env.log_destination
+          @logger.level = ::Logger::DEBUG
+          @logger
+        end
+      end
+    end
+  end
+end
\ No newline at end of file

qa/qa/support/page/logging.rb

+# frozen_string_literal: true
+
+module QA
+  module Support
+    module Page
+      module Logging
+        def refresh
+          log("refreshing #{current_url}")
+
+          super
+        end
+
+        def wait(max: 60, time: 0.1, reload: true)
+          log("with wait: max #{max}; time #{time}; reload #{reload}")
+
+          element = super
+
+          log("end wait")
+
+          element
+        end
+
+        def scroll_to(selector, text: nil)
+          msg = "scrolling to :#{selector}"
+          msg += " with text: #{text}" if text
+          log(msg)
+
+          super
+        end
+
+        def asset_exists?(url)
+          exists = super
+
+          log("asset_exists? #{url} returned #{exists}")
+
+          exists
+        end
+
+        def find_element(name)
+          log("finding :#{name}")
+
+          element = super
+
+          log("found :#{name}") if element
+
+          element
+        end
+
+        def all_elements(name)
+          log("finding all :#{name}")
+
+          elements = super
+
+          log("found #{elements.size} :#{name}") if elements
+
+          elements
+        end
+
+        def click_element(name)
+          log("clicking :#{name}")
+
+          super
+        end
+
+        def fill_element(name, content)
+          masked_content = name.to_s.include?('password') ? '*****' : content
+
+          log(%Q(filling :#{name} with "#{masked_content}"))
+
+          super
+        end
+
+        def has_element?(name)
+          found = super
+
+          log("has_element? :#{name} returned #{found}")
+
+          found
+        end
+
+        def within_element(name)
+          log("within element :#{name}")
+
+          element = super
+
+          log("end within element :#{name}")
+
+          element
+        end
+
+        private
+
+        def log(msg)
+          QA::Support::Logger.debug(msg)
+        end
+      end
+    end
+  end
+end

qa/spec/page/logger_spec.rb

+# frozen_string_literal: true
+
+require 'capybara/dsl'
+
+describe QA::Support::Page::Logging do
+  let(:page) { double().as_null_object }
+
+  before do
+    allow(Capybara).to receive(:current_session).and_return(page)
+    allow(page).to receive(:current_url).and_return('a page')
+    allow(page).to receive(:has_css?).with(any_args).and_return(true)
+    allow(QA::Runtime::Env).to receive(:debug?).and_return(true)
+  end
+
+  subject { QA::Page::Base.new }
+
+  it 'logs refresh' do
+    expect { subject.refresh }
+      .to output(/refreshing a page/).to_stdout_from_any_process
+  end
+
+  it 'logs wait' do
+    expect { subject.wait(max: 0) {} }
+      .to output(/with wait/).to_stdout_from_any_process
+    expect { subject.wait(max: 0) {} }
+      .to output(/end wait/).to_stdout_from_any_process
+  end
+
+  it 'logs scroll_to' do
+    expect { subject.scroll_to(:element) }
+      .to output(/scrolling to :element/).to_stdout_from_any_process
+  end
+
+  it 'logs asset_exists?' do
+    expect { subject.asset_exists?('a url') }
+      .to output(/asset_exists\? a url returned false/).to_stdout_from_any_process
+  end
+
+  it 'logs find_element' do
+    expect { subject.find_element(:element) }
+      .to output(/found :element/).to_stdout_from_any_process
+  end
+
+  it 'logs all_elements' do
+    expect { subject.all_elements(:element) }
+      .to output(/finding all :element/).to_stdout_from_any_process
+  end
+
+  it 'logs click_element' do
+    expect { subject.click_element(:element) }
+      .to output(/clicking :element/).to_stdout_from_any_process
+  end
+
+  it 'logs fill_element' do
+    expect { subject.fill_element(:element, 'foo') }
+      .to output(/filling :element with "foo"/).to_stdout_from_any_process
+  end
+
+  it 'logs has_element?' do
+    expect { subject.has_element?(:element) }
+      .to output(/has_element\? :element returned true/).to_stdout_from_any_process
+  end
+
+  it 'logs within_element' do
+    expect { subject.within_element(:element) }
+      .to output(/within element :element/).to_stdout_from_any_process
+    expect { subject.within_element(:element) }
+      .to output(/end within element :element/).to_stdout_from_any_process
+  end
+end

qa/spec/runtime/env_spec.rb

+# frozen_string_literal: true
+
 describe QA::Runtime::Env do
   include Support::StubENV
@@ -38,6 +40,10 @@ describe QA::Runtime::Env do
     it_behaves_like 'boolean method', :signup_disabled?, 'SIGNUP_DISABLED', false
   end
+  describe '.debug?' do
+    it_behaves_like 'boolean method', :debug?, 'QA_DEBUG', false
+  end
+
   describe '.chrome_headless?' do
     it_behaves_like 'boolean method', :chrome_headless?, 'CHROME_HEADLESS', true
   end
@@ -115,4 +121,18 @@ describe QA::Runtime::Env do
       expect { described_class.require_github_access_token! }.not_to raise_error
     end
   end
+
+  describe '.log_destination' do
+    it 'returns STDOUT if QA_LOG_PATH is not defined' do
+      stub_env('QA_LOG_PATH', nil)
+
+      expect(described_class.log_destination).to eq(STDOUT)
+    end
+
+    it 'returns the path if QA_LOG_PATH is defined' do
+      stub_env('QA_LOG_PATH', 'path/to_file')
+
+      expect(described_class.log_destination).to eq('path/to_file')
+    end
+  end
 end

qa/spec/spec_helper.rb

@@ -3,6 +3,10 @@ require_relative '../qa'
 Dir[::File.join(__dir__, 'support', '**', '*.rb')].each { |f| require f }
 RSpec.configure do |config|
+  config.before(:example) do |example|
+    QA::Support::Logger.debug("Starting test: #{example.full_description}") if QA::Runtime::Env.debug?
+  end
+
   config.expect_with :rspec do |expectations|
     expectations.include_chain_clauses_in_custom_matcher_descriptions = true
   end

qa/spec/support/logger_spec.rb

+# frozen_string_literal: true
+
+describe QA::Support::Logger do
+
+  it '' do
+    expect { described_class.warn('test') }.to output(/WARN/).to_stdout_from_any_process
+  end
+end
\ No newline at end of file