Integrate logger

[redshiftzero]

we should log any unexpected exceptions (e.g. during the pilot we'll want to request this log for debugging any issues)

Relevant: freedomofpress/securedrop-workstation#19

[ntoll]

What type of logging do you expect here? E.g. to a log file, to a database, to a log "service", some sort of QubeOS log facility? If 0, Python's logging module is simplest. If something more complicated perhaps something that inherits from/mimics logging so it'll be familiar to Pythonistas while implementing the special features we need.

What sort of logging do you expect? There's "traditional" timestamped lines which look like this:

2018-09-10 19:08:23,370 - root:113(run) INFO: uname_result(system='Linux', node='heraclitus', release='4.15.0-33-generic', version='#36-Ubuntu SMP Wed Aug 15 16:00:05 UTC 2018', machine='x86_64', processor='x86_64')

Alternatively there's structured logging (e.g. a single line per entry, with each entry being some serialised data [usually JSON in my experience] containing data about the log entry). People (sysadmins?) are used to reading the first sort, although the second sort is way more easy for a machine to parse for the purposes of analysis.

Thoughts..?

[redshiftzero]

There isn't yet a Qubes-specific logging solution (though there is some discussion about that over in freedomofpress/securedrop-workstation#19) nor a plan to ingest these logs by e.g. the SecureDrop monitoring server. We'll likely iterate on this after the initial MVP of the client is complete, but for now let's do simple Python logging to a log file where each line is a traditional timestamped line. For this MVP version, the logging is primarily intended for FPF to use to debug any issues that are experienced during workstation pilots at supported news organizations (we'll provide steps to share the log with us over a secure channel, or we'd help them in an on-site visit).

For this ticket, I expect we'd just have an info level log event for application start up (in a new file that will eventually become the main file)

[conorsch]

Agreed that logging is the sane approach here. Also appreciate your forward-thinking about structured logs, @ntoll, where JSON indeed fits the bill. Right now we have little visibility into the various components for the Workstation, so having a VM-local log file to aid in debugging when things go wrong, as @redshiftzero describes, is the immediate ask here.

[ntoll]

OK... so, why not just use Python's logging module in situ in code (i.e. there's nothing special needed here except "standard" Python logging practices)..?

For instance, on app start there should probably be something that looks like this (copied from Mu):

import logging
import os
import sys

LOG_DIR = 'some pre-defined path'
LOG_FILE = os.path.join(LOG_DIR, 'securedrop_client.log')

def excepthook(*exc_args):
    """
    Log exception and exit cleanly.
    """
    logging.error('Unrecoverable error', exc_info=(exc_args))
    sys.__excepthook__(*exc_args)
    sys.exit(1)

if not os.path.exists(LOG_DIR):
    os.makedirs(LOG_DIR)

# 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, when='midnight',
                                   backupCount=5, delay=0,
                                   encoding=ENCODING)
handler.setFormatter(formatter)
handler.setLevel(logging.DEBUG)

# set up primary log
log = logging.getLogger()
log.setLevel(logging.DEBUG)
log.addHandler(handler)
sys.excepthook = excepthook
print(_('Logging to {}').format(LOG_FILE))

In each module in the application you'd just need to do this...

import logging

logger = logging.getLogger(__name__)

logger.info("Hello world")

That's it! Thoughts?

[redshiftzero]

yep, just standard logging! Looks great - want to put this in a PR maybe adding the log file setup in a new app.py?