diff --git a/searx/metrics/error_recorder.py b/searx/metrics/error_recorder.py index df25e8d41..bb3d76adc 100644 --- a/searx/metrics/error_recorder.py +++ b/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 diff --git a/searx/search/checker/impl.py b/searx/search/checker/impl.py index cf1f03449..659c9c50b 100644 --- a/searx/search/checker/impl.py +++ b/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 diff --git a/searx/search/processors/abstract.py b/searx/search/processors/abstract.py index f89302a92..dd6e1c13d 100644 --- a/searx/search/processors/abstract.py +++ b/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 diff --git a/searx/search/processors/online.py b/searx/search/processors/online.py index acc3792f5..cad63aae0 100644 --- a/searx/search/processors/online.py +++ b/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 = {}