Python Logging - moving file on startup

Question

In my Flask application I have implemented a logging system using the logging library. It is currently run in a function below:

if __name__ == "__main__":
    """[Runs the webserver.
    Finally block is used for some logging management. It will first shut down
    logging, to ensure no files are open, then renames the file to 'log_'
    + the current date, and finally moves the file to the /logs archive
    directory]
    """
    try:
        session_management.clean_uploads_on_start(UPLOAD_FOLDER)
        app.run(debug=False)
    finally:
        try:
            logging.shutdown()
            new_log_file_name = log_management.rename_log(app.config['DEFAULT_LOG_NAME'])
            log_management.move_log(new_log_file_name)
        except FileNotFoundError:
            logging.warning("Current log file not found")
        except PermissionError:
            logging.warning("Permissions lacking to rename or move log.")

I discovered that the file is not renamed and moved if (either) the cmd prompt is force closed, or if the server crashes. I thought it might be better to put the rename and move into the initial 'try' block of the function, prior to the server starting, but I run into issues because I have a config file (which is imported in this script) which has the following code:

logging.basicConfig(filename='current_log.log', level=logging.INFO,
                    filemode='a',
                    format='%(asctime)s:%(levelname)s:%(message)s')

I have tried to do something like the below, but I still run into permission errors, but I think I am still running into errors because the log_management script also imports config. Further, I could not find a function which starts the logging system similar to logging.shutdown() which is used upon the system ending, otherwise I would shut it down, move the file (if it exists) and the start it back up.

  try:
        session_management.clean_uploads_on_start(UPLOAD_FOLDER)
        log_management.check_log_on_startup(app.config['DEFAULT_LOG_NAME'])
        import config
        app.run(debug=False)
    finally:
        try:
            logging.shutdown()
            new_log_file_name = log_management.rename_log(app.config['DEFAULT_LOG_NAME'])
            log_management.move_log(new_log_file_name)
        except FileNotFoundError:
            logging.warning("Current log file not found")
        except PermissionError:
            logging.warning("Permissions lacking to rename or move log.")

# (in another script)
def check_log_on_startup(file_name):
    if os.path.exists(file_name):
        move_log(rename_log(file_name))

Any suggestions much welcomed, because I feel like I'm at a brick wall!

Answer 1

As you have already found out, trying to perform cleanups at the end of your process life cycle has the potential to fail if the process terminates uncleanly.

The issue with performing the cleanup at the start is, that you apparently call logging.basicConfig from your import before attempting to move the old log file.
This leads to the implicitly created FileHandler holding an open file object on the existing log when you attempt to rename and move it. Depending on the file system you are using, this might not be met with joy.

If you want to move the handling of potential old log files to the start of your application completely, you have to perform the renaming and moving before you call logging.basicConfig, so you'll have to remove it from your import and add it to the log_management somehow.

As an alternative, you could move the whole handling of log files to the logging file handler by subclassing the standard FileHandler class, e.g:

import logging
import os
from datetime import datetime

class CustomFileHandler(logging.FileHandler):

    def __init__(self, filename, archive_path='archive', archive_name='log_%Y%m%d', **kwargs):
        self._archive = os.path.join(archive_path, archive_name)
        self._archive_log(filename)
        super().__init__(filename, **kwargs)

    def _archive_log(self, filepath):
        if os.path.exists(filepath):
            os.rename(filepath, datetime.now().strftime(self._archive))

    def close(self):
        super().close()
        self._archive_log(self.baseFilename)

With this, you would configure your logging like so:

hdler = CustomFileHandler('current.log')
logging.basicConfig(level=logging.INFO, handlers=[hdler], 
                   format='%(asctime)s:%(levelname)s:%(message)s')

The CustomFileHandler will check for, and potentially archive, old logs during initialization. This will deal with leftovers after an unclean process termination where the shutdown cleanup cannot take place. Since the parent class initializer is called after the log archiving is attempted, there is not yet an open handle on the log that would cause a PermissionError.

The overwritten close() method will perform the archiving on a clean process shutdown.

This should remove the need for the dedicated log_management module, at least as far as the functions you show in your code are concerned. rename_log, move_log and check_log_on_startup are all encapsulated in the CustomFileHandler. There is also no need to explicitly call logging.shutdown().

---

Some notes:

The reason you cannot find a start function equivalent to logging.shutdown() is that the logging system is started/initialized when you import the logging module. Among other things, it instantiates the implicit root logger and registers logging.shutdown as exit handler via atexit.
The latter is the reason why there is no need to explicitly call logging.shutdown() with the above solution. The Python interpreter will call it during finalization when preparing for interpreter shutdown due to the exit handler registration. logging.shutdown() then iterates through the list of registered handlers and calls their close() methods, which will perform the log archiving during a clean shutdown.

Depending on the method you choose for moving (and renaming) the old log file, the above solution might need some additional safeguards against exceptions. os.rename will raise an exception if the destination path already exists, i.e. when you have already stopped and started your process previously on the same day while os.replace would silently overwrite the existing file. See more details about moving files via Python here.

Thus I would recommend to name the archived logs not only by current date but also by time.
In the above, adding the current date to the archive file name is done via datetime's strftime, hence the 'log_%Y%m%d' as default for the archive_name parameter of the custom file handler. The characters with a preceding % are valid format codes that strftime() replaces with the respective parts of the datetime object it is called on. To append the current time to the archive log file name you would simply append the respective format codes to the archive_name, e.g.: 'log_%Y%m%d_%H%M%S' which would result in a log name such as log_20200819_123721.