From 91a6d80e8291852264abdcda83c203dfb5770381 Mon Sep 17 00:00:00 2001 From: Alexandre Flament Date: Mon, 6 Sep 2021 21:42:30 +0200 Subject: [PATCH] [mod] debug mode: log HTTP requests with network name For example wikipedia requests use the logger name "searx.network.wikipedia" Log is disable when searx_debug is False --- searx/network/client.py | 16 ++++++++++++--- searx/network/network.py | 42 +++++++++++++++++++++++++++++----------- 2 files changed, 44 insertions(+), 14 deletions(-) diff --git a/searx/network/client.py b/searx/network/client.py index 187ae5366..e1abff05a 100644 --- a/searx/network/client.py +++ b/searx/network/client.py @@ -194,7 +194,7 @@ def new_client( # pylint: disable=too-many-arguments enable_http, verify, enable_http2, max_connections, max_keepalive_connections, keepalive_expiry, - proxies, local_address, retries, max_redirects ): + proxies, local_address, retries, max_redirects, hook_log_response ): limit = httpx.Limits( max_connections=max_connections, max_keepalive_connections=max_keepalive_connections, @@ -221,7 +221,17 @@ def new_client( mounts['http://'] = AsyncHTTPTransportNoHttp() transport = get_transport(verify, enable_http2, local_address, None, limit, retries) - return httpx.AsyncClient(transport=transport, mounts=mounts, max_redirects=max_redirects) + + event_hooks = None + if hook_log_response: + event_hooks = {'response': [ hook_log_response ]} + + return httpx.AsyncClient( + transport=transport, + mounts=mounts, + max_redirects=max_redirects, + event_hooks=event_hooks, + ) def get_loop(): @@ -231,7 +241,7 @@ def get_loop(): def init(): # log - for logger_name in ('hpack.hpack', 'hpack.table'): + for logger_name in ('hpack.hpack', 'hpack.table', 'httpx._client'): logging.getLogger(logger_name).setLevel(logging.WARNING) # loop diff --git a/searx/network/network.py b/searx/network/network.py index d09a2ee0e..9954f0507 100644 --- a/searx/network/network.py +++ b/searx/network/network.py @@ -10,9 +10,11 @@ from itertools import cycle import httpx +from searx import logger, searx_debug from .client import new_client, get_loop +logger = logger.getChild('network') DEFAULT_NAME = '__DEFAULT__' NETWORKS = {} # requests compatibility when reading proxy settings from settings.yml @@ -41,7 +43,7 @@ class Network: 'enable_http', 'verify', 'enable_http2', 'max_connections', 'max_keepalive_connections', 'keepalive_expiry', 'local_addresses', 'proxies', 'max_redirects', 'retries', 'retry_on_http_error', - '_local_addresses_cycle', '_proxies_cycle', '_clients' + '_local_addresses_cycle', '_proxies_cycle', '_clients', '_logger' ) def __init__( @@ -57,7 +59,8 @@ class Network: local_addresses=None, retries=0, retry_on_http_error=None, - max_redirects=30 ): + max_redirects=30, + logger_name=None): self.enable_http = enable_http self.verify = verify @@ -73,6 +76,7 @@ class Network: self._local_addresses_cycle = self.get_ipaddress_cycle() self._proxies_cycle = self.get_proxy_cycles() self._clients = {} + self._logger = logger.getChild(logger_name) if logger_name else logger self.check_parameters() def check_parameters(self): @@ -130,12 +134,25 @@ class Network: # pylint: disable=stop-iteration-return yield tuple((pattern, next(proxy_url_cycle)) for pattern, proxy_url_cycle in proxy_settings.items()) + async def log_response(self, response: httpx.Response): + request = response.request + status = f"{response.status_code} {response.reason_phrase}" + response_line = f"{response.http_version} {status}" + if hasattr(response, "_elapsed"): + elapsed_time = f"{response.elapsed.total_seconds()} sec" + else: + elapsed_time = "stream" + self._logger.debug( + f'HTTP Request: {request.method} {request.url} "{response_line}" ({elapsed_time})' + ) + def get_client(self, verify=None, max_redirects=None): verify = self.verify if verify is None else verify max_redirects = self.max_redirects if max_redirects is None else max_redirects local_address = next(self._local_addresses_cycle) proxies = next(self._proxies_cycle) # is a tuple so it can be part of the key key = (verify, max_redirects, local_address, proxies) + hook_log_response = self.log_response if searx_debug else None if key not in self._clients or self._clients[key].is_closed: self._clients[key] = new_client( self.enable_http, @@ -147,7 +164,8 @@ class Network: dict(proxies), local_address, 0, - max_redirects + max_redirects, + hook_log_response ) return self._clients[key] @@ -243,11 +261,13 @@ def initialize(settings_engines=None, settings_outgoing=None): 'retry_on_http_error': None, } - def new_network(params): + def new_network(params, logger_name=None): nonlocal default_params result = {} result.update(default_params) result.update(params) + if logger_name: + result['logger_name'] = logger_name return Network(**result) def iter_networks(): @@ -263,13 +283,13 @@ def initialize(settings_engines=None, settings_outgoing=None): if NETWORKS: done() NETWORKS.clear() - NETWORKS[DEFAULT_NAME] = new_network({}) - NETWORKS['ipv4'] = new_network({'local_addresses': '0.0.0.0'}) - NETWORKS['ipv6'] = new_network({'local_addresses': '::'}) + NETWORKS[DEFAULT_NAME] = new_network({}, logger_name='default') + NETWORKS['ipv4'] = new_network({'local_addresses': '0.0.0.0'}, logger_name='ipv4') + NETWORKS['ipv6'] = new_network({'local_addresses': '::'}, logger_name='ipv6') # define networks from outgoing.networks for network_name, network in settings_outgoing['networks'].items(): - NETWORKS[network_name] = new_network(network) + NETWORKS[network_name] = new_network(network, logger_name=network_name) # define networks from engines.[i].network (except references) for engine_name, engine, network in iter_networks(): @@ -280,9 +300,9 @@ def initialize(settings_engines=None, settings_outgoing=None): network[attribute_name] = getattr(engine, attribute_name) else: network[attribute_name] = attribute_value - NETWORKS[engine_name] = new_network(network) + NETWORKS[engine_name] = new_network(network, logger_name=engine_name) elif isinstance(network, dict): - NETWORKS[engine_name] = new_network(network) + NETWORKS[engine_name] = new_network(network, logger_name=engine_name) # define networks from engines.[i].network (references) for engine_name, engine, network in iter_networks(): @@ -295,7 +315,7 @@ def initialize(settings_engines=None, settings_outgoing=None): if 'image_proxy' not in NETWORKS: image_proxy_params = default_params.copy() image_proxy_params['enable_http2'] = False - NETWORKS['image_proxy'] = new_network(image_proxy_params) + NETWORKS['image_proxy'] = new_network(image_proxy_params, logger_name='image_proxy') @atexit.register