[rb] output driver logs when SE_DEBUG is enabled (#16901)

* [rb] driver logs sent to stderr at verbose level when SE_DEBUG environment variable is set

* [rb] warn when SE_DEBUG overrides user logging settings

* Add Logger#debug! and Logger#stderr! to force settings and prevent overrides

Author: titusfortner

rb/lib/selenium/webdriver.rb

@@ -96,7 +96,12 @@ def self.for(*)
 
     def self.logger(**)
       level = $DEBUG || ENV.key?('DEBUG') || ENV.key?('SE_DEBUG') ? :debug : :info
-      @logger ||= WebDriver::Logger.new('Selenium', default_level: level, **)
+      @logger ||= WebDriver::Logger.new('Selenium', default_level: level, **).tap do |logger|
+        if ENV.key?('SE_DEBUG')
+          logger.debug!
+          logger.stderr!
+        end
+      end
     end
   end # WebDriver
 end # Selenium

rb/lib/selenium/webdriver/chrome/service.rb

@@ -26,6 +26,16 @@ class Service < WebDriver::Service
         SHUTDOWN_SUPPORTED = true
         DRIVER_PATH_ENV_KEY = 'SE_CHROMEDRIVER'
 
+        def initialize(args: nil, **)
+          if ENV.key?('SE_DEBUG')
+            args = Array(args.dup)
+            warn_driver_log_override if args.reject! { |arg| arg.include?('log-level') || arg.include?('silent') }
+            args << '--verbose'
+          end
+
+          super
+        end
+
         def log
           return @log unless @log.is_a? String
 

rb/lib/selenium/webdriver/common/logger.rb

@@ -55,9 +55,32 @@ def initialize(progname = 'Selenium', default_level: nil, ignored: nil, allowed:
         @ignored = Array(ignored)
         @allowed = Array(allowed)
         @first_warning = false
+        @level_forced = false
+        @output_forced = false
+      end
+
+      #
+      # Forces debug level and prevents it from being overridden.
+      #
+      def debug!
+        @level_forced = true
+        @logger.level = :debug
+      end
+
+      #
+      # Forces output to stderr and prevents it from being overridden.
+      #
+      def stderr!
+        @output_forced = true
+        @logger.reopen($stderr)
       end
 
       def level=(level)
+        if @level_forced
+          warn('Logger level is forced; ignoring override', id: :logger)
+          return
+        end
+
         if level == :info && @logger.level == :info
           info(':info is now the default log level, to see additional logging, set log level to :debug')
         end
@@ -71,6 +94,11 @@ def level=(level)
       # @param [String] io
       #
       def output=(io)
+        if @output_forced
+          warn('Logger output is forced; ignoring override', id: :logger)
+          return
+        end
+
         @logger.reopen(io)
       end
 

rb/lib/selenium/webdriver/common/service.rb

@@ -104,6 +104,12 @@ def find_driver_path
       def env_path
         ENV.fetch(self.class::DRIVER_PATH_ENV_KEY, nil)
       end
+
+      private
+
+      def warn_driver_log_override
+        WebDriver.logger.warn('SE_DEBUG is set; overriding user-specified driver logging settings', id: :se_debug)
+      end
     end # Service
   end # WebDriver
 end # Selenium

rb/lib/selenium/webdriver/common/service_manager.rb

@@ -80,7 +80,13 @@ def uri
       def build_process(*command)
         WebDriver.logger.debug("Executing Process #{command}", id: :driver_service)
         @process = ChildProcess.build(*command)
-        @io ||= WebDriver.logger.io if WebDriver.logger.debug?
+        if ENV.key?('SE_DEBUG')
+          if @io && @io != WebDriver.logger.io
+            WebDriver.logger.warn('SE_DEBUG is set; overriding user-specified driver log output to use stderr',
+                                  id: :se_debug)
+          end
+          @io = WebDriver.logger.io
+        end
         @process.io = @io if @io
 
         @process

rb/lib/selenium/webdriver/edge/service.rb

@@ -25,6 +25,17 @@ class Service < WebDriver::Service
         EXECUTABLE = 'msedgedriver'
         SHUTDOWN_SUPPORTED = true
         DRIVER_PATH_ENV_KEY = 'SE_EDGEDRIVER'
+
+        def initialize(args: nil, **)
+          if ENV.key?('SE_DEBUG')
+            args = Array(args.dup)
+            warn_driver_log_override if args.reject! { |arg| arg.include?('log-level') || arg.include?('silent') }
+            args << '--verbose'
+          end
+
+          super
+        end
+
         def log
           return @log unless @log.is_a? String
 

rb/lib/selenium/webdriver/firefox/service.rb

@@ -26,14 +26,33 @@ class Service < WebDriver::Service
         SHUTDOWN_SUPPORTED = false
         DRIVER_PATH_ENV_KEY = 'SE_GECKODRIVER'
 
-        def initialize(path: nil, port: nil, log: nil, args: nil)
-          args ||= []
+        def initialize(args: nil, **)
+          args = Array(args.dup)
           unless args.any? { |arg| arg.include?('--connect-existing') || arg.include?('--websocket-port') }
             args << '--websocket-port'
             args << '0'
           end
+
+          if ENV.key?('SE_DEBUG')
+            remove_log_args(args)
+            args << '-v'
+          end
+
           super
         end
+
+        private
+
+        def remove_log_args(args)
+          if (index = args.index('--log'))
+            args.delete_at(index) # delete '--log'
+            args.delete_at(index) if args[index] && !args[index].start_with?('-') # delete value if present
+            warn_driver_log_override
+          elsif (index = args.index { |arg| arg.start_with?('--log=') })
+            args.delete_at(index)
+            warn_driver_log_override
+          end
+        end
       end # Service
     end # Firefox
   end # WebDriver

rb/lib/selenium/webdriver/ie/service.rb

@@ -25,6 +25,16 @@ class Service < WebDriver::Service
         EXECUTABLE = 'IEDriverServer'
         SHUTDOWN_SUPPORTED = true
         DRIVER_PATH_ENV_KEY = 'SE_IEDRIVER'
+
+        def initialize(args: nil, **)
+          if ENV.key?('SE_DEBUG')
+            args = Array(args.dup)
+            warn_driver_log_override if args.reject! { |arg| arg.include?('log-level') || arg.include?('silent') }
+            args << '--log-level=DEBUG'
+          end
+
+          super
+        end
       end # Server
     end # IE
   end # WebDriver

rb/sig/lib/selenium/webdriver/chrome/service.rbs

@@ -12,6 +12,8 @@ module Selenium
 
         SHUTDOWN_SUPPORTED: bool
 
+        def initialize: (?args: Array[String]?, **untyped) -> void
+
         def log: () -> untyped
       end
     end

rb/sig/lib/selenium/webdriver/common/logger.rbs

@@ -4,15 +4,21 @@ module Selenium
 
       @allowed: Array[Symbol]
       @first_warning: bool
+      @level_forced: bool
+      @output_forced: bool
 
       @ignored: Array[Symbol]
       @logger: ::Logger
 
       def initialize: (?::String progname, ?default_level: Symbol? default_level, ?ignored: Array[Symbol]? ignored, ?allowed: Array[Symbol]? allowed) -> void
 
-      def level=: (Symbol level) -> Symbol
+      def debug!: () -> void
 
-      def output=: (String io) -> ::Logger
+      def stderr!: () -> void
+
+      def level=: (Symbol level) -> Symbol?
+
+      def output=: (String io) -> ::Logger?
 
       def io: () -> IO