diff --git a/securedrop_proxy/entrypoint.py b/securedrop_proxy/entrypoint.py index 2bf7211..33c84d5 100755 --- a/securedrop_proxy/entrypoint.py +++ b/securedrop_proxy/entrypoint.py @@ -6,18 +6,39 @@ # called with exactly one argument: the path to its config file. See # the README for configuration options. -import sys import json -import uuid +import logging +import os import subprocess +import sys +import uuid + +from logging.handlers import TimedRotatingFileHandler -from . import proxy -from . import config -from . import callbacks -from . import main +from securedrop_proxy import callbacks +from securedrop_proxy import config +from securedrop_proxy import main +from securedrop_proxy import proxy +from securedrop_proxy.version import version + + +DEFAULT_HOME = os.path.join(os.path.expanduser("~"), ".securedrop_proxy") +LOGLEVEL = os.environ.get('LOGLEVEL', 'info').upper() def start(): + ''' + Set up a new proxy object with an error handler, configuration that we read from argv[1], and + the original user request from STDIN. + ''' + try: + configure_logging() + except Exception as e: + print(e) + return + + logging.debug('Starting SecureDrop Proxy {}'.format(version)) + # a fresh, new proxy object p = proxy.Proxy() @@ -44,3 +65,42 @@ def start(): incoming = "\n".join(incoming) main.__main__(incoming, p) + + +def excepthook(*exc_args): + ''' + This function is called in the event of a catastrophic failure. + Log exception and exit cleanly. + ''' + logging.error('Unrecoverable error', exc_info=(exc_args)) + sys.__excepthook__(*exc_args) + print('') # force terminal prompt on to a new line + sys.exit(1) + + +def configure_logging() -> None: + ''' + All logging related settings are set up by this function. + ''' + log_folder = os.path.join(DEFAULT_HOME, 'logs') + if not os.path.exists(log_folder): + os.makedirs(log_folder) + + log_file = os.path.join(DEFAULT_HOME, 'logs', 'proxy.log') + + # set logging format + log_fmt = ('%(asctime)s - %(name)s:%(lineno)d(%(funcName)s) %(levelname)s: %(message)s') + formatter = logging.Formatter(log_fmt) + + # define log handlers such as for rotating log files + handler = TimedRotatingFileHandler(log_file) + handler.setFormatter(formatter) + handler.setLevel(logging.DEBUG) + + # set up primary log + log = logging.getLogger() + log.setLevel(LOGLEVEL) + log.addHandler(handler) + + # override excepthook to capture a log of catastrophic failures. + sys.excepthook = excepthook diff --git a/securedrop_proxy/main.py b/securedrop_proxy/main.py index 2333bb1..6fadafa 100644 --- a/securedrop_proxy/main.py +++ b/securedrop_proxy/main.py @@ -1,24 +1,33 @@ import json +import logging from securedrop_proxy import callbacks from securedrop_proxy import proxy +logger = logging.getLogger(__name__) + + def __main__(incoming, p): - # deserialize incoming request + ''' + Deserialize incoming request in order to build and send a proxy request. + ''' + logging.debug('Creating request to be sent by proxy') + client_req = None try: client_req = json.loads(incoming) - except json.decoder.JSONDecodeError: + except json.decoder.JSONDecodeError as e: + logging.error(e) p.simple_error(400, 'Invalid JSON in request') p.on_done(p.res) - # build request oject req = proxy.Req() try: req.method = client_req['method'] req.path_query = client_req['path_query'] - except KeyError: + except KeyError as e: + logging.error(e) p.simple_error(400, 'Missing keys in request') p.on_done(p.res) @@ -28,7 +37,6 @@ def __main__(incoming, p): if "body" in client_req: req.body = client_req['body'] - # complete proxy object p.req = req p.on_save = callbacks.on_save p.on_done = callbacks.on_done diff --git a/securedrop_proxy/proxy.py b/securedrop_proxy/proxy.py index 9e0f3a1..cc30b32 100644 --- a/securedrop_proxy/proxy.py +++ b/securedrop_proxy/proxy.py @@ -1,12 +1,16 @@ -import requests import furl -import tempfile import json +import logging +import requests +import tempfile import werkzeug import securedrop_proxy.version as version +logger = logging.getLogger(__name__) + + class Req: def __init__(self): self.method = "" @@ -71,7 +75,7 @@ def prep_request(self): try: url = furl.furl("{}://{}:{}/{}".format(scheme, host, port, path)) except Exception as e: - + logging.error(e) self.simple_error(500, "Proxy error while generating URL to request") raise ValueError("Error generating URL from provided values") @@ -114,6 +118,7 @@ def handle_non_json_response(self): self.res = res def handle_response(self): + logging.debug('Handling response') ctype = werkzeug.http.parse_options_header(self._presp.headers["content-type"]) @@ -134,11 +139,13 @@ def proxy(self): raise ValueError("Request callback is not set.") self.prep_request() + logging.debug('Sending request') s = requests.Session() self._presp = s.send(self._prepared_request) self.handle_response() - except ValueError: + except ValueError as e: + logging.error(e) # effectively a 4xx error # we have set self.response to indicate an error