Python Logger facing intermittent issues. Not rolling file as expected

Question

I have a system which used Python 3.7.9. I have 3 processes, let's term them process A, B and C.

A is the main process, which launches a number of B processes using subprocess module. Each B process then pull some messages and launch a single C process to process those messages. Once C process is complete, it terminates and loop continue from process B again.

For processes A and B, we are using logging.basicConfig to define a file based logger which changes as per date of the machine. The logfile name declared is main_{app_id}{queue_name}{cur_time}.log where curr_time is in format of "%y%m%d-%H%M%S" when process B got started.

For process C, we are using a socket logger which defines a socket handler to send all logs to a socket server running on the machine. This socket server is using a time rotated file handler to write received logs from all process C instances in a single file i.e. run_logs.log.

Below is the code for socket server

import logging
import os
import pickle
import socketserver
import struct
import sys
from logging import handlers

LOGGER = None


class SocketAgentFormatter:
    def formatter(self):
        return '%(asctime)s %(filename)s:%(lineno)d %(levelname)s\t%(message)s'


class LogRecordStreamHandler(socketserver.StreamRequestHandler):

    def handle(self):
        while True:
            chunk = self.connection.recv(4)
            if len(chunk) < 4:
                break
            slen = struct.unpack('>L', chunk)[0]
            chunk = self.connection.recv(slen)
            while len(chunk) < slen:
                chunk = chunk + self.connection.recv(slen - len(chunk))
            obj = self.un_pickle(chunk)
            record = logging.makeLogRecord(obj)
            self.handle_log_record(record)

    def un_pickle(self, data):
        return pickle.loads(data)

    def handle_log_record(self, record):
        LOGGER.handle(record)


class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):

    def __init__(self, host, port, handler):
        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)
        self.abort = 0
        self.timeout = 1

    def serve_until_stopped(self):
        import select
        abort = 0
        while not abort:
            rd, wr, ex = select.select([self.socket.fileno()],
                                       [], [],
                                       self.timeout)
            if rd:
                self.handle_request()
            abort = self.abort


def main(port):
    tcpserver = LogRecordSocketReceiver('localhost', port, LogRecordStreamHandler)
    print('Starting Logger TCP server...')
    tcpserver.serve_until_stopped()


if __name__ == '__main__':
    logger_name = sys.argv[1]
    log_file_dir = sys.argv[2]
    log_file_name = sys.argv[3]
    port = int(sys.argv[4])
    try:
        backup_count = int(sys.argv[5])
    except:
        backup_count = 7

    print("Logger Name: {logger_name}".format(logger_name=logger_name))
    print("Log File Directory: {log_file_dir}".format(log_file_dir=log_file_dir))
    print("Log File Name: {log_file_name}".format(log_file_name=log_file_name))
    print("Port: {port}".format(port=port))
    print("Backup Count: {backup_count}".format(backup_count=backup_count))

    LOGGER = logging.getLogger(logger_name)
    if not os.path.exists(log_file_dir):
        os.makedirs(log_file_dir)
    handler = logging.handlers.TimedRotatingFileHandler(os.path.join(log_file_dir, log_file_name), when='midnight',
                                                        backupCount=backup_count, utc=True)
    handler.setFormatter(logging.Formatter(SocketAgentFormatter().formatter()))
    LOGGER.addHandler(handler)
    LOGGER.setLevel(logging.DEBUG)

    main(port)

We are able to see logs in run_logs.log for C processes.

Issue is that some days the rotation of log files happen correctly i.e. We get the latest file plus the previous days log files with data intact in each of them. However, we found that on many days rotation is not working properly and latest file has the correct data but previous days files lose all data and become empty. Also, it should only modify the current file at the rotation, but we can see the date modified on previous day files are also updated.

Also, on any day if we check the latest file data is present in it, so we can't say that logs are not being written.

Apart from this, our main_{app_id}{queue_name}{cur_time}.log files also get updated and become empty files.

We tried below activities to examine/mitigate the issue:

We tried changing rotation time from midnight to like 5mins, 10 mins, 30 mins and 1 hour and let it ran for some days. Everything went smooth no such issues. However, switching back to midnight we got the issue again.

Tried building a custom handler using time rotation handler which flushes the logs before rotation happens, but same issue is happening with it as well for the midnight rotation.

My VM is using ubuntu 18 LTS.

Any help will be much appreciated!!