Commit 33295c08 authored by Mark Lapierre's avatar Mark Lapierre

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.
parent 544337f7
......@@ -18,6 +18,7 @@ module QA
autoload :Address, 'qa/runtime/address'
autoload :Path, 'qa/runtime/path'
autoload :Fixtures, 'qa/runtime/fixtures'
autoload :Logger, 'qa/runtime/logger'
module API
autoload :Client, 'qa/runtime/api/client'
......@@ -324,6 +325,14 @@ module QA
end
end
end
# Classes that provide support to other parts of the framework.
#
module Support
module Page
autoload :Logging, 'qa/support/page/logging'
end
end
end
QA::Runtime::Release.extend_autoloads!
......@@ -63,7 +63,7 @@ module QA
private_class_method :do_fabricate!
def self.log_fabrication(method, factory, parents, args)
return yield unless Runtime::Env.verbose?
return yield unless Runtime::Env.debug?
start = Time.now
prefix = "==#{'=' * parents.size}>"
......
......@@ -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
......
# frozen_string_literal: true
module QA
module Runtime
module Env
......@@ -7,8 +9,12 @@ module QA
attr_writer :personal_access_token
def verbose?
enabled?(ENV['VERBOSE'], default: false)
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
......
# frozen_string_literal: true
require 'logger'
module QA
module Runtime
module Logger
extend SingleForwardable
def_delegators :logger, :debug, :info, :error, :warn, :fatal, :unknown
singleton_class.module_eval do
def logger
return @logger if @logger
@logger = ::Logger.new Runtime::Env.log_destination
@logger.level = ::Logger::DEBUG
@logger
end
end
end
end
end
# frozen_string_literal: true
module QA
module Support
module Page
module Logger
def refresh
super
log("refreshed #{current_url}")
end
def wait(max: 60, time: 0.1, reload: true)
log("with wait: max #{max}; time #{time}; reload #{reload}")
super
log("end wait")
end
def scroll_to(selector, text: nil)
log("scrolling to :#{selector}")
super
end
def asset_exists?(url)
exists = super
log("asset_exists? #{url} returned #{exists}")
exists
end
def find_element(name)
element = super
log("found :#{name}")
element
end
def all_elements(name)
elements = super
log("found all :#{name}")
elements
end
def click_element(name)
super
log("clicked :#{name}")
end
def fill_element(name, content)
super
content = '*****' if name.to_s.include? "password"
log(%Q(filled :#{name} with "#{content}"))
end
def has_element?(name)
found = super
log("has_element? :#{name} returned #{found}")
found
end
def within_element(name)
log("within element :#{name}")
super
log("end within element :#{name}")
end
private
def log(msg)
puts "debug: #{msg}"
end
end
end
end
end
# 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}")
now = Time.now
element = super
log("ended wait after #{Time.now - now} seconds")
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::Runtime::Logger.debug(msg)
end
end
end
end
end
......@@ -35,8 +35,8 @@ describe QA::Factory::Base do
end
end
it 'does not log the factory and build method when VERBOSE=false' do
stub_env('VERBOSE', 'false')
it 'does not log the factory and build method when QA_DEBUG=false' do
stub_env('QA_DEBUG', 'false')
expect(factory).to receive(fabrication_method_used).and_return(product_location)
expect { subject.public_send(fabrication_method_called, 'something', factory: factory) }
......@@ -79,8 +79,8 @@ describe QA::Factory::Base do
expect(result).to eq(product)
end
it 'logs the factory and build method when VERBOSE=true' do
stub_env('VERBOSE', 'true')
it 'logs the factory and build method when QA_DEBUG=true' do
stub_env('QA_DEBUG', 'true')
expect(factory).to receive(:fabricate_via_api!).and_return(product_location)
expect { subject.fabricate_via_api!(factory: factory, parents: []) }
......@@ -106,8 +106,8 @@ describe QA::Factory::Base do
expect(result).to eq(product)
end
it 'logs the factory and build method when VERBOSE=true' do
stub_env('VERBOSE', 'true')
it 'logs the factory and build method when QA_DEBUG=true' do
stub_env('QA_DEBUG', 'true')
expect { subject.fabricate_via_browser_ui!('something', factory: factory, parents: []) }
.to output(/==> Built a MyFactory via browser_ui with args \["something"\] in [\d\w\.\-]+/)
......
# 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('http://current-url')
allow(page).to receive(:has_css?).with(any_args).and_return(true)
end
subject do
Class.new(QA::Page::Base) do
prepend QA::Support::Page::Logging
end.new
end
it 'logs refresh' do
expect { subject.refresh }
.to output(%r{refreshing http://current-url}).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(/ended wait after .* seconds$/).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?('http://asset-url') }
.to output(%r{asset_exists\? http://asset-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 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
context 'all_elements' do
it 'logs the number of elements found' do
allow(page).to receive(:all).and_return([1, 2])
expect { subject.all_elements(:element) }
.to output(/finding all :element/).to_stdout_from_any_process
expect { subject.all_elements(:element) }
.to output(/found 2 :element/).to_stdout_from_any_process
end
it 'logs 0 if no elements are found' do
allow(page).to receive(:all).and_return([])
expect { subject.all_elements(:element) }
.to output(/finding all :element/).to_stdout_from_any_process
expect { subject.all_elements(:element) }
.not_to output(/found 0 :elements/).to_stdout_from_any_process
end
end
end
# frozen_string_literal: true
describe QA::Runtime::Env do
include Support::StubENV
......@@ -34,14 +36,14 @@ describe QA::Runtime::Env do
end
end
describe '.verbose?' do
it_behaves_like 'boolean method', :verbose?, 'VERBOSE', false
end
describe '.signup_disabled?' 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
......@@ -166,4 +168,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
# frozen_string_literal: true
describe QA::Runtime::Logger do
it 'logs debug' do
expect { described_class.debug('test') }.to output(/DEBUG -- : test/).to_stdout_from_any_process
end
it 'logs info' do
expect { described_class.info('test') }.to output(/INFO -- : test/).to_stdout_from_any_process
end
it 'logs warn' do
expect { described_class.warn('test') }.to output(/WARN -- : test/).to_stdout_from_any_process
end
it 'logs error' do
expect { described_class.error('test') }.to output(/ERROR -- : test/).to_stdout_from_any_process
end
it 'logs fatal' do
expect { described_class.fatal('test') }.to output(/FATAL -- : test/).to_stdout_from_any_process
end
it 'logs unknown' do
expect { described_class.unknown('test') }.to output(/ANY -- : test/).to_stdout_from_any_process
end
end
......@@ -3,6 +3,10 @@ require_relative '../qa'
Dir[::File.join(__dir__, 'support', '**', '*.rb')].each { |f| require f }
RSpec.configure do |config|
config.before do |example|
QA::Runtime::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
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment