Skip to content

Commit

Permalink
[rb] change logging default to :info and support ignoring any logging
Browse files Browse the repository at this point in the history
  • Loading branch information
titusfortner committed May 6, 2023
1 parent 156e7f5 commit 2d022c0
Show file tree
Hide file tree
Showing 25 changed files with 189 additions and 108 deletions.
13 changes: 10 additions & 3 deletions rb/lib/selenium/devtools.rb
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,8 @@ class << self
def load_version
require "selenium/devtools/v#{@version}"
rescue LoadError
Kernel.warn "Could not load selenium-devtools v#{@version}. Trying older versions."
WebDriver.logger.warn "Could not load selenium-devtools v#{@version}. Trying older versions.",
id: :devtools
load_older_version
end

Expand All @@ -35,13 +36,19 @@ def load_version
def load_older_version
load_old_version(@version - 1)
rescue LoadError
load_old_version(@version - 2)
begin
load_old_version(@version - 2)
rescue LoadError
raise WebDriver::Error::WebDriverError,
'Could not find a valid devtools version; use a more recent version of selenium-devtools gem'
end
end

def load_old_version(version)
require "selenium/devtools/v#{version}"
self.version = version
Kernel.warn "Using selenium-devtools version v#{version}, some features may not work as expected."
msg = "Using selenium-devtools version v#{version}, some features may not work as expected."
WebDriver.logger.warn msg, id: :devtools
end
end
end # DevTools
Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/server.rb
Original file line number Diff line number Diff line change
Expand Up @@ -254,7 +254,7 @@ def process
args = ['-jar', @jar, @role, '--port', @port.to_s]
server_command = ['java'] + properties + args + @additional_args
cp = WebDriver::ChildProcess.build(*server_command)
WebDriver.logger.debug("Executing Process #{server_command}")
WebDriver.logger.debug("Executing Process #{server_command}", id: :server)

if @log.is_a?(String)
cp.io = @log
Expand Down
8 changes: 0 additions & 8 deletions rb/lib/selenium/webdriver/common/action_builder.rb
Original file line number Diff line number Diff line change
Expand Up @@ -250,14 +250,6 @@ def add_input(device)
@devices << device
device
end

def deprecate_method(device = nil, duration = nil, number = nil, method: :pause)
return unless device || number || duration

WebDriver.logger.deprecate "ActionBuilder##{method} with ordered parameters",
':device, :duration, :number keywords',
id: method
end
end # ActionBuilder
end # WebDriver
end # Selenium
18 changes: 9 additions & 9 deletions rb/lib/selenium/webdriver/common/child_process.rb
Original file line number Diff line number Diff line change
Expand Up @@ -53,9 +53,9 @@ def start
options = {%i[out err] => io}
options[:pgroup] = true unless Platform.windows? # NOTE: this is a bug only in Windows 7

WebDriver.logger.debug("Starting process: #{@command} with #{options}")
WebDriver.logger.debug("Starting process: #{@command} with #{options}", id: :process)
@pid = Process.spawn(*@command, options)
WebDriver.logger.debug(" -> pid: #{@pid}")
WebDriver.logger.debug(" -> pid: #{@pid}", id: :process)

Process.detach(@pid) if detach
end
Expand All @@ -64,16 +64,16 @@ def stop(timeout = 3)
return unless @pid
return if exited?

WebDriver.logger.debug("Sending TERM to process: #{@pid}")
WebDriver.logger.debug("Sending TERM to process: #{@pid}", id: :process)
terminate(@pid)
poll_for_exit(timeout)

WebDriver.logger.debug(" -> stopped #{@pid}")
WebDriver.logger.debug(" -> stopped #{@pid}", id: :process)
rescue TimeoutError, Errno::EINVAL
WebDriver.logger.debug(" -> sending KILL to process: #{@pid}")
WebDriver.logger.debug(" -> sending KILL to process: #{@pid}", id: :process)
kill(@pid)
wait
WebDriver.logger.debug(" -> killed #{@pid}")
WebDriver.logger.debug(" -> killed #{@pid}", id: :process)
end

def alive?
Expand All @@ -83,18 +83,18 @@ def alive?
def exited?
return unless @pid

WebDriver.logger.debug("Checking if #{@pid} is exited:")
WebDriver.logger.debug("Checking if #{@pid} is exited:", id: :process)
_, @status = Process.waitpid2(@pid, Process::WNOHANG | Process::WUNTRACED) if @status.nil?
return if @status.nil?

exit_code = @status.exitstatus || @status.termsig
WebDriver.logger.debug(" -> exit code is #{exit_code.inspect}")
WebDriver.logger.debug(" -> exit code is #{exit_code.inspect}", id: :process)

!!exit_code
end

def poll_for_exit(timeout)
WebDriver.logger.debug("Polling #{timeout} seconds for exit of #{@pid}")
WebDriver.logger.debug("Polling #{timeout} seconds for exit of #{@pid}", id: :process)

end_time = Time.now + timeout
sleep POLL_INTERVAL until exited? || Time.now > end_time
Expand Down
3 changes: 2 additions & 1 deletion rb/lib/selenium/webdriver/common/driver_finder.rb
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,8 @@ def self.path(options, klass)
path ||= begin
SeleniumManager.driver_path(options)
rescue StandardError => e
WebDriver.logger.warn("Unable obtain driver using Selenium Manager\n #{e.message}")
WebDriver.logger.warn("Unable to obtain driver using Selenium Manager\n #{e.message}",
id: :selenium_manager)
nil
end
msg = "Unable to locate the #{klass::EXECUTABLE} executable; for more information on how to install drivers, " \
Expand Down
70 changes: 50 additions & 20 deletions rb/lib/selenium/webdriver/common/logger.rb
Original file line number Diff line number Diff line change
Expand Up @@ -38,12 +38,12 @@ class Logger

def_delegators :@logger,
:close,
:debug, :debug?,
:info, :info?,
:debug?,
:info?,
:warn?,
:error, :error?,
:fatal, :fatal?,
:level, :level=
:level

#
# @param [String] progname Allow child projects to use Selenium's Logger pattern
Expand All @@ -54,6 +54,12 @@ def initialize(progname = 'Selenium', ignored: nil)
@first_warning = false
end

def level=(level)
info(':info is now the default log level, to see additional logging, set log level to :debug') if level == :info

@logger.level = level
end

#
# Changes logger output to a new IO.
#
Expand Down Expand Up @@ -88,27 +94,44 @@ def ignore(id)
end

#
# Overrides default #warn to skip ignored messages by provided id
# Used to supply information of interest for debugging a problem
# Overrides default #debug to skip ignored messages by provided id
#
# @param [String] message
# @param [Symbol, Array<Sybmol>] id
# @yield see #deprecate
#
def warn(message, id: [])
def debug(message, id: [], &block)
discard_or_log(:debug, message, id, &block)
end

#
# Used to supply information of general interest
#
# @param [String] message
# @param [Symbol, Array<Sybmol>] id
# @yield see #deprecate
#
def info(message, id: [], &block)
unless @first_warning
@first_warning = true
warn("Details on how to use and modify Selenium logger:\n", id: [:logger_info]) do
"https://selenium.dev/documentation/webdriver/troubleshooting/logging#ruby\n"
info("Details on how to use and modify Selenium logger:\n", id: [:logger_info]) do
"https://selenium.dev/documentation/webdriver/troubleshooting/logging\n"
end
end

id = Array(id)
return if (@ignored & id).any?

msg = id.empty? ? message : "[#{id.map(&:inspect).join(', ')}] #{message} "
msg += " #{yield}" if block_given?
discard_or_log(:info, message, id, &block)
end

@logger.warn { msg }
#
# Used to supply information that suggests action be taken by user
#
# @param [String] message
# @param [Symbol, Array<Sybmol>] id
# @yield see #deprecate
#
def warn(message, id: [], &block)
discard_or_log(:warn, message, id, &block)
end

#
Expand All @@ -121,20 +144,17 @@ def warn(message, id: [])
# @yield appends additional message to end of provided template
#
def deprecate(old, new = nil, id: [], reference: '', &block)
id = Array(id)
return if @ignored.include?(:deprecations) || (@ignored & id).any?

ids = id.empty? ? '' : "[#{id.map(&:inspect).join(', ')}] "
return if @ignored.include?(:deprecations)

message = +"[DEPRECATION] #{ids}#{old} is deprecated"
message = +"[DEPRECATION] #{old} is deprecated"
message << if new
". Use #{new} instead."
else
' and will be removed in a future release.'
end
message << " See explanation for this deprecation: #{reference}." unless reference.empty?

warn message, &block
discard_or_log(:warn, message, id, &block)
end

private
Expand All @@ -151,7 +171,17 @@ def create_logger(name)
end

def default_level
$DEBUG || ENV.key?('DEBUG') ? :debug : :warn
$DEBUG || ENV.key?('DEBUG') ? :debug : :info
end

def discard_or_log(level, message, id)
id = Array(id)
return if (@ignored & id).any?

msg = id.empty? ? message : "[#{id.map(&:inspect).join(', ')}] #{message} "
msg += " #{yield}" if block_given?

@logger.send(level) { msg }
end
end # Logger
end # WebDriver
Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/webdriver/common/options.rb
Original file line number Diff line number Diff line change
Expand Up @@ -128,7 +128,7 @@ def as_json(*)

unless options.empty?
msg = 'These options are not w3c compliant and will result in failures in a future release'
WebDriver.logger.warn("#{msg}: #{options}")
WebDriver.logger.warn("#{msg}: #{options}", id: :w3c_options)
browser_options.merge!(options)
end

Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/webdriver/common/port_prober.rb
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ def self.free?(port)
Platform.interfaces.each do |host|
TCPServer.new(host, port).close
rescue *IGNORED_ERRORS => e
WebDriver.logger.debug("port prober could not bind to #{host}:#{port} (#{e.message})")
WebDriver.logger.debug("port prober could not bind to #{host}:#{port} (#{e.message})", id: :driver_service)
# ignored - some machines appear unable to bind to some of their interfaces
end

Expand Down
12 changes: 6 additions & 6 deletions rb/lib/selenium/webdriver/common/selenium_manager.rb
Original file line number Diff line number Diff line change
Expand Up @@ -33,8 +33,8 @@ class << self
# @param [Options] options browser options.
# @return [String] the path to the correct driver.
def driver_path(options)
message = 'applicable driver not found; attempting to install with Selenium Manager'
WebDriver.logger.warn(message)
message = 'applicable driver not found; attempting to install with Selenium Manager (Beta)'
WebDriver.logger.info(message, id: :selenium_manager)

unless options.is_a?(Options)
raise ArgumentError, "SeleniumManager requires a WebDriver::Options instance, not #{options.inspect}"
Expand All @@ -52,7 +52,7 @@ def driver_path(options)
command << '--debug' if WebDriver.logger.debug?

location = run(*command)
WebDriver.logger.debug("Driver found at #{location}")
WebDriver.logger.debug("Driver found at #{location}", id: :selenium_manager)
Platform.assert_executable location

location
Expand All @@ -76,13 +76,13 @@ def binary
raise Error::WebDriverError, 'Unable to obtain Selenium Manager'
end

WebDriver.logger.debug("Selenium Manager found at #{location}")
WebDriver.logger.debug("Selenium Manager found at #{location}", id: :selenium_manager)
location
end
end

def run(*command)
WebDriver.logger.debug("Executing Process #{command}")
WebDriver.logger.debug("Executing Process #{command}", id: :selenium_manager)

begin
stdout, stderr, status = Open3.capture3(*command)
Expand All @@ -97,7 +97,7 @@ def run(*command)
end

json_output['logs'].each do |log|
WebDriver.logger.send(log['level'].downcase, log['message'])
WebDriver.logger.send(log['level'].downcase, log['message'], id: :selenium_manager)
end

result
Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/webdriver/common/service_manager.rb
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ def uri
private

def build_process(*command)
WebDriver.logger.debug("Executing Process #{command}")
WebDriver.logger.debug("Executing Process #{command}", id: :driver_service)
@process = ChildProcess.build(*command)
@process.io = @io
@process.io ||= WebDriver.logger.io if WebDriver.logger.debug?
Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/webdriver/common/socket_lock.rb
Original file line number Diff line number Diff line change
Expand Up @@ -70,7 +70,7 @@ def can_lock?
@server.close_on_exec = true
true
rescue SocketError, Errno::EADDRINUSE, Errno::EBADF => e
WebDriver.logger.debug("#{self}: #{e.message}")
WebDriver.logger.debug("#{self}: #{e.message}", id: :driver_service)
false
end

Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/webdriver/common/socket_poller.rb
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ def listening?
true
rescue *NOT_CONNECTED_ERRORS
sock&.close
WebDriver.logger.debug("polling for socket on #{[@host, @port].inspect}")
WebDriver.logger.debug("polling for socket on #{[@host, @port].inspect}", id: :driver_service)
false
end
end
Expand Down
4 changes: 2 additions & 2 deletions rb/lib/selenium/webdriver/common/websocket_connection.rb
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ def callbacks
def send_cmd(**payload)
id = next_id
data = payload.merge(id: id)
WebDriver.logger.debug "WebSocket -> #{data}"[...MAX_LOG_MESSAGE_SIZE]
WebDriver.logger.debug "WebSocket -> #{data}"[...MAX_LOG_MESSAGE_SIZE], id: :bidi
data = JSON.generate(data)
out_frame = WebSocket::Frame::Outgoing::Client.new(version: ws.version, data: data, type: 'text')
socket.write(out_frame.to_s)
Expand Down Expand Up @@ -112,7 +112,7 @@ def process_frame(frame)

message = JSON.parse(message)
messages[message['id']] = message
WebDriver.logger.debug "WebSocket <- #{message}"[...MAX_LOG_MESSAGE_SIZE]
WebDriver.logger.debug "WebSocket <- #{message}"[...MAX_LOG_MESSAGE_SIZE], id: :bidi

message
end
Expand Down
2 changes: 1 addition & 1 deletion rb/lib/selenium/webdriver/firefox/profile.rb
Original file line number Diff line number Diff line change
Expand Up @@ -160,7 +160,7 @@ def install_extensions(directory)
destination = File.join(directory, 'extensions')

@extensions.each do |name, extension|
WebDriver.logger.debug({extenstion: name}.inspect)
WebDriver.logger.debug({extension: name}.inspect, id: :firefox_profile)
extension.write_to(destination)
end
end
Expand Down
Loading

0 comments on commit 2d022c0

Please sign in to comment.