Merge 27aa9c4cb1 into fa4dfd4efe

searx/metrics/error_recorder.py

@@ -3,6 +3,7 @@
 
 import typing
 import inspect
+import logging
 from json import JSONDecodeError
 from urllib.parse import urlparse
 from httpx import HTTPError, HTTPStatusError
@@ -30,10 +31,20 @@ class ErrorContext:  # pylint: disable=missing-class-docstring
         'log_message',
         'log_parameters',
         'secondary',
+        'log_level',
     )
 
     def __init__(  # pylint: disable=too-many-arguments
-        self, filename, function, line_no, code, exception_classname, log_message, log_parameters, secondary
+        self,
+        filename,
+        function,
+        line_no,
+        code,
+        exception_classname,
+        log_message,
+        log_parameters,
+        secondary,
+        log_level=logging.WARN,
     ):
         self.filename = filename
         self.function = function
@@ -43,6 +54,7 @@ class ErrorContext:  # pylint: disable=missing-class-docstring
         self.log_message = log_message
         self.log_parameters = log_parameters
         self.secondary = secondary
+        self.log_level: int = log_level
 
     def __eq__(self, o) -> bool:  # pylint: disable=invalid-name
         if not isinstance(o, ErrorContext):
@@ -56,6 +68,7 @@ class ErrorContext:  # pylint: disable=missing-class-docstring
             and self.log_message == o.log_message
             and self.log_parameters == o.log_parameters
             and self.secondary == o.secondary
+            and self.log_level == o.log_level
         )
 
     def __hash__(self):
@@ -69,11 +82,12 @@ class ErrorContext:  # pylint: disable=missing-class-docstring
                 self.log_message,
                 self.log_parameters,
                 self.secondary,
+                self.log_level,
             )
         )
 
     def __repr__(self):
-        return "ErrorContext({!r}, {!r}, {!r}, {!r}, {!r}, {!r}) {!r}".format(
+        return "ErrorContext({!r}, {!r}, {!r}, {!r}, {!r}, {!r}), {!r}, {!r}".format(
             self.filename,
             self.line_no,
             self.code,
@@ -81,13 +95,14 @@ class ErrorContext:  # pylint: disable=missing-class-docstring
             self.log_message,
             self.log_parameters,
             self.secondary,
+            self.log_level,
         )
 
 
 def add_error_context(engine_name: str, error_context: ErrorContext) -> None:
     errors_for_engine = errors_per_engines.setdefault(engine_name, {})
     errors_for_engine[error_context] = errors_for_engine.get(error_context, 0) + 1
-    engines[engine_name].logger.warning('%s', str(error_context))
+    engines[engine_name].logger.log(error_context.log_level, '%s', str(error_context))
 
 
 def get_trace(traces):
@@ -157,7 +172,9 @@ def get_exception_classname(exc: Exception) -> str:
     return exc_module + '.' + exc_name
 
 
-def get_error_context(framerecords, exception_classname, log_message, log_parameters, secondary) -> ErrorContext:
+def get_error_context(
+    framerecords, exception_classname, log_message, log_parameters, secondary, log_level: int
+) -> ErrorContext:
     searx_frame = get_trace(framerecords)
     filename = searx_frame.filename
     if filename.startswith(searx_parent_dir):
@@ -166,30 +183,36 @@ def get_error_context(framerecords, exception_classname, log_message, log_parame
     line_no = searx_frame.lineno
     code = searx_frame.code_context[0].strip()
     del framerecords
-    return ErrorContext(filename, function, line_no, code, exception_classname, log_message, log_parameters, secondary)
+    return ErrorContext(
+        filename, function, line_no, code, exception_classname, log_message, log_parameters, secondary, log_level
+    )
 
 
-def count_exception(engine_name: str, exc: Exception, secondary: bool = False) -> None:
+def count_exception(engine_name: str, exc: Exception, secondary: bool = False, log_level=logging.WARN) -> None:
     if not settings['general']['enable_metrics']:
         return
     framerecords = inspect.trace()
     try:
         exception_classname = get_exception_classname(exc)
         log_parameters = get_messages(exc, framerecords[-1][1])
-        error_context = get_error_context(framerecords, exception_classname, None, log_parameters, secondary)
+        error_context = get_error_context(framerecords, exception_classname, None, log_parameters, secondary, log_level)
         add_error_context(engine_name, error_context)
     finally:
         del framerecords
 
 
 def count_error(
-    engine_name: str, log_message: str, log_parameters: typing.Optional[typing.Tuple] = None, secondary: bool = False
+    engine_name: str,
+    log_message: str,
+    log_parameters: typing.Optional[typing.Tuple] = None,
+    secondary: bool = False,
+    log_level: int = logging.WARN,
 ) -> None:
     if not settings['general']['enable_metrics']:
         return
     framerecords = list(reversed(inspect.stack()[1:]))
     try:
-        error_context = get_error_context(framerecords, None, log_message, log_parameters or (), secondary)
+        error_context = get_error_context(framerecords, None, log_message, log_parameters or (), secondary, log_level)
         add_error_context(engine_name, error_context)
     finally:
         del framerecords

searx/search/checker/impl.py

@@ -357,6 +357,7 @@ class Checker:  # pylint: disable=missing-class-docstring
 
     def __init__(self, processor: EngineProcessor):
         self.processor = processor
+        self.processor.log_engine_exc_info = False  # Remove exception information from errors to reduce verbosity
         self.tests = self.processor.get_tests()
         self.test_results = TestResults()
 
@@ -418,8 +419,10 @@ class Checker:  # pylint: disable=missing-class-docstring
         result_container_check.check_basic()
         return result_container_check
 
-    def run_test(self, test_name):
+    def run_test(self, test_name: str):
         test_parameters = self.tests[test_name]
+        #  Not really a warning, but an info log will not appear
+        logger.warning('---%s---', test_name)
         search_query_list = list(Checker.search_query_matrix_iterator(self.engineref_list, test_parameters['matrix']))
         rct_list = [self.get_result_container_tests(test_name, search_query) for search_query in search_query_list]
         stop_test = False

searx/search/processors/abstract.py

@@ -3,6 +3,8 @@
 
 """
 
+import logging
+from logging import Logger
 import threading
 from abc import abstractmethod, ABC
 from timeit import default_timer
@@ -58,12 +60,13 @@ class SuspendedStatus:
 class EngineProcessor(ABC):
     """Base classes used for all types of request processors."""
 
-    __slots__ = 'engine', 'engine_name', 'lock', 'suspended_status', 'logger'
+    __slots__ = 'engine', 'engine_name', 'lock', 'suspended_status', 'logger', 'log_engine_exc_info'
 
     def __init__(self, engine, engine_name: str):
         self.engine = engine
         self.engine_name = engine_name
-        self.logger = engines[engine_name].logger
+        self.logger: Logger = engines[engine_name].logger
+        self.log_engine_exc_info = True
         key = get_network(self.engine_name)
         key = id(key) if key else self.engine_name
         self.suspended_status = SUSPENDED_STATUS.setdefault(key, SuspendedStatus())
@@ -82,6 +85,10 @@ class EngineProcessor(ABC):
     def has_initialize_function(self):
         return hasattr(self.engine, 'init')
 
+    @property
+    def metrics_log_level(self) -> int:
+        return logging.WARN if self.log_engine_exc_info else logging.NOTSET
+
     def handle_exception(self, result_container, exception_or_message, suspend=False):
         # update result_container
         if isinstance(exception_or_message, BaseException):
@@ -95,9 +102,9 @@ class EngineProcessor(ABC):
         # metrics
         counter_inc('engine', self.engine_name, 'search', 'count', 'error')
         if isinstance(exception_or_message, BaseException):
-            count_exception(self.engine_name, exception_or_message)
+            count_exception(self.engine_name, exception_or_message, log_level=self.metrics_log_level)
         else:
-            count_error(self.engine_name, exception_or_message)
+            count_error(self.engine_name, exception_or_message, log_level=self.metrics_log_level)
         # suspend the engine ?
         if suspend:
             suspended_time = None

searx/search/processors/online.py

@@ -127,6 +127,7 @@ class OnlineProcessor(EngineProcessor):
                 '{} redirects, maximum: {}'.format(len(response.history), soft_max_redirects),
                 (status_code, reason, hostname),
                 secondary=True,
+                log_level=self.metrics_log_level,
             )
 
         return response
@@ -180,20 +181,21 @@ class OnlineProcessor(EngineProcessor):
             self.logger.exception(
                 "requests exception (search duration : {0} s, timeout: {1} s) : {2}".format(
                     default_timer() - start_time, timeout_limit, e
-                )
+                ),
+                exc_info=self.log_engine_exc_info,
             )
         except SearxEngineCaptchaException as e:
             self.handle_exception(result_container, e, suspend=True)
-            self.logger.exception('CAPTCHA')
+            self.logger.exception('CAPTCHA', exc_info=self.log_engine_exc_info)
         except SearxEngineTooManyRequestsException as e:
             self.handle_exception(result_container, e, suspend=True)
-            self.logger.exception('Too many requests')
+            self.logger.exception('Too many requests', exc_info=self.log_engine_exc_info)
         except SearxEngineAccessDeniedException as e:
             self.handle_exception(result_container, e, suspend=True)
-            self.logger.exception('SearXNG is blocked')
+            self.logger.exception('SearXNG is blocked', exc_info=self.log_engine_exc_info)
         except Exception as e:  # pylint: disable=broad-except
             self.handle_exception(result_container, e)
-            self.logger.exception('exception : {0}'.format(e))
+            self.logger.exception('exception : {0}'.format(e), exc_info=self.log_engine_exc_info)
 
     def get_default_tests(self):
         tests = {}