diff --git a/qa/qa.rb b/qa/qa.rb index 7feca22478a..36a37dbb270 100644 --- a/qa/qa.rb +++ b/qa/qa.rb @@ -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! diff --git a/qa/qa/factory/base.rb b/qa/qa/factory/base.rb index a8ecac2a1e6..e1dc23d350d 100644 --- a/qa/qa/factory/base.rb +++ b/qa/qa/factory/base.rb @@ -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}>" diff --git a/qa/qa/page/base.rb b/qa/qa/page/base.rb index 160ec58cf2c..91e229c4c8c 100644 --- a/qa/qa/page/base.rb +++ b/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 diff --git a/qa/qa/runtime/env.rb b/qa/qa/runtime/env.rb index 533ed87453a..c7052a9f300 100644 --- a/qa/qa/runtime/env.rb +++ b/qa/qa/runtime/env.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + module QA module Runtime module Env @@ -5,8 +7,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 diff --git a/qa/qa/runtime/logger.rb b/qa/qa/runtime/logger.rb new file mode 100644 index 00000000000..3baa24de0ec --- /dev/null +++ b/qa/qa/runtime/logger.rb @@ -0,0 +1,23 @@ +# 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 diff --git a/qa/qa/support/page/logging.rb b/qa/qa/support/page/logging.rb new file mode 100644 index 00000000000..cf5cd3a79f8 --- /dev/null +++ b/qa/qa/support/page/logging.rb @@ -0,0 +1,100 @@ +# 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 diff --git a/qa/spec/factory/base_spec.rb b/qa/spec/factory/base_spec.rb index 184802a7903..229f93a1041 100644 --- a/qa/spec/factory/base_spec.rb +++ b/qa/spec/factory/base_spec.rb @@ -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\.\-]+/) diff --git a/qa/spec/page/logging_spec.rb b/qa/spec/page/logging_spec.rb new file mode 100644 index 00000000000..9f17de4edbf --- /dev/null +++ b/qa/spec/page/logging_spec.rb @@ -0,0 +1,88 @@ +# 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 diff --git a/qa/spec/runtime/env_spec.rb b/qa/spec/runtime/env_spec.rb index b5ecf1afb80..c59c415c148 100644 --- a/qa/spec/runtime/env_spec.rb +++ b/qa/spec/runtime/env_spec.rb @@ -1,3 +1,5 @@ +# 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 diff --git a/qa/spec/runtime/logger_spec.rb b/qa/spec/runtime/logger_spec.rb new file mode 100644 index 00000000000..794e1f9bfe6 --- /dev/null +++ b/qa/spec/runtime/logger_spec.rb @@ -0,0 +1,27 @@ +# 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 diff --git a/qa/spec/spec_helper.rb b/qa/spec/spec_helper.rb index 8e6613cd688..8e01da01340 100644 --- a/qa/spec/spec_helper.rb +++ b/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 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