httpclient: Add an improved HTTP client that logs requests

Signed-off-by: Michael Tremer <michael.tremer@ipfire.org>

diff --git a/Makefile.am b/Makefile.am
index 72175b689e20f8671c1dbfc03ff5a6cdb1f4b012..59a5cf8d6dca040b69dc39766792b9bfa25cc088 100644 (file)
--- a/Makefile.am
+++ b/Makefile.am
@@ -56,6 +56,7 @@ backend_PYTHON = \
        src/backend/database.py \
        src/backend/decorators.py \
        src/backend/fireinfo.py \
+       src/backend/httpclient.py \
        src/backend/hwdata.py \
        src/backend/iuse.py \
        src/backend/memcached.py \

diff --git a/src/backend/base.py b/src/backend/base.py
index 00497a298cfa6ce8c3e2d3909ff7e366415f59ad..476c2698cdaa643de0548ca86d64547983e3170a 100644 (file)
--- a/src/backend/base.py
+++ b/src/backend/base.py
@@ -12,6 +12,7 @@ from . import blog
 from . import campaigns
 from . import database
 from . import fireinfo
+from . import httpclient
 from . import iuse
 from . import memcached
 from . import messages
@@ -39,6 +40,8 @@ templates_dir = %(data_dir)s/templates
 """)
 
 class Backend(object):
+       version = 0
+
        def __init__(self, configfile, debug=False):
                # Read configuration file.
                self.config = self.read_config(configfile)
@@ -50,11 +53,8 @@ class Backend(object):
                self.setup_database()
 
                # Create HTTPClient
-               self.http_client = tornado.httpclient.AsyncHTTPClient(
-                       defaults = {
-                               "User-Agent" : "IPFireWebApp",
-                       }
-               )
+               self.http_client = httpclient.HTTPClient(self)
+
                # Initialize settings first.
                self.settings = settings.Settings(self)
                self.memcache = memcached.Memcached(self)

diff --git a/src/backend/httpclient.py b/src/backend/httpclient.py
new file mode 100644 (file)
index 0000000..c8150ed
--- /dev/null
+++ b/src/backend/httpclient.py
@@ -0,0 +1,184 @@
+###############################################################################
+#                                                                             #
+# Pakfire - The IPFire package management system                              #
+# Copyright (C) 2023 Pakfire development team                                 #
+#                                                                             #
+# This program is free software: you can redistribute it and/or modify        #
+# it under the terms of the GNU General Public License as published by        #
+# the Free Software Foundation, either version 3 of the License, or           #
+# (at your option) any later version.                                         #
+#                                                                             #
+# This program is distributed in the hope that it will be useful,             #
+# but WITHOUT ANY WARRANTY; without even the implied warranty of              #
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the               #
+# GNU General Public License for more details.                                #
+#                                                                             #
+# You should have received a copy of the GNU General Public License           #
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.       #
+#                                                                             #
+###############################################################################
+
+import json
+import logging
+import tornado.curl_httpclient
+import tornado.httpclient
+import urllib.parse
+
+# Setup logging
+log = logging.getLogger()
+
+# Copy exceptions
+HTTPError = tornado.httpclient.HTTPError
+
+# Copy the request object
+HTTPRequest = tornado.httpclient.HTTPRequest
+
+class HTTPClient(tornado.curl_httpclient.CurlAsyncHTTPClient):
+       """
+               This is a wrapper over Tornado's HTTP client that performs some extra
+               logging and makes it easier to compose a request.
+       """
+       def __init__(self, backend, *args, **kwargs):
+               super().__init__(*args, **kwargs)
+
+               # Store a reference to the backend
+               self.backend = backend
+
+       def _configure_proxy(self, request):
+               """
+                       Configures the proxy
+               """
+               proxy = self.backend.settings.get("proxy")
+               if not proxy:
+                       return
+
+               # Split the configuration value
+               host, delim, port = proxy.partition(":")
+
+               # Convert port to integer
+               # Set port
+               try:
+                       port = int(port)
+               except (TypeError, ValueError):
+                       log.error("Could not decode proxy setting: %s" % proxy)
+                       return
+
+               # Set values
+               request.proxy_host, request.proxy_port = host, port
+
+       async def fetch(self, request, **kwargs):
+               """
+                       Sends a request
+               """
+               if not isinstance(request, HTTPRequest):
+                       request = HTTPRequest(url=request, **kwargs)
+
+               # Configure the proxy
+               self._configure_proxy(request)
+
+               # Set User-Agent
+               request.user_agent = "IPFireWebapp/%s" % self.backend.version
+
+               # Log what we are sending
+               log.debug("Sending %s request to %s:" % (request.method, request.url))
+
+               # Log headers
+               if request.headers:
+                       log_headers(request.headers)
+
+               # Log the body
+               if request.body:
+                       log_body(request.body)
+
+               # Send the request
+               try:
+                       response = await super().fetch(request)
+
+               # Log any errors
+               except tornado.httpclient.HTTPError as e:
+                       log.error("Received status %s:" % e.code)
+
+                       # Log the response body
+                       if e.response:
+                               log_body(e.response.body, level=logging.ERROR)
+
+                       # Raise the error
+                       raise e
+
+               # Log successful responses
+               else:
+                       log.debug("Received response: %s (%s - %s) in %.2fms:" % (
+                               response.effective_url, response.code, response.reason,
+                               response.request_time * 1000.0,
+                       ))
+
+                       # Log headers
+                       if response.headers:
+                               log_headers(response.headers)
+
+                       # Log body
+                       if response.body:
+                               log_body(response.body)
+
+               # Return the response
+               return response
+
+
+def log_headers(headers):
+       """
+               Helper function to log request/response headers
+       """
+       log.debug("  Headers:")
+
+       for header in sorted(headers):
+               log.debug("    %-32s: %s" % (header, headers[header]))
+
+def decode_body(body):
+       # Try parsing this as JSON and reformat it
+       try:
+               body = json.loads(body)
+               body = json.dumps(body, indent=4, sort_keys=True)
+       except (json.JSONDecodeError, UnicodeDecodeError):
+               pass
+       else:
+               return body
+
+       # Try parsing this as query arguments
+       try:
+               query = urllib.parse.parse_qs(body, strict_parsing=True)
+               if query:
+                       body = format_query(query)
+       except ValueError:
+               pass
+       else:
+               return body
+
+       # Decode as string
+       if isinstance(body, bytes):
+               try:
+                       body = body.decode()
+               except UnicodeError:
+                       pass
+               else:
+                       return body
+
+def format_query(query):
+       lines = []
+
+       for key in sorted(query):
+               for val in query[key]:
+                       lines.append(b" %-32s : %s" % (key, val))
+
+       return b"\n".join(lines)
+
+def log_body(body, level=logging.DEBUG):
+       """
+               Helper function to log the request/response body
+       """
+       body = decode_body(body)
+
+       if body:
+               log.log(level, "  Body:")
+
+               for line in body.splitlines():
+                       log.log(level, "    %s" % line)