How to access asctime of a python LogRecord?

Question

I have a logger and a class DuplicateFilter that filters messages that already were logged once. I would like to include the time when the logging happened into my filter but when I try to access the property asctime I get: AttributeError: 'LogRecord' object has no attribute 'asctime'

Here a small example how I set up my logger:

import logging
import logging.handlers as log_handlers
def setup_logger(filename):
    class DuplicateFilter(object):
        def __init__(self):
            self.msgs = set()

        def filter(self, record):
            if logger.level == 10:
                return True
            rv = True
            try:
                print(record.asctime)
                msg = record.threadName + " " + record.msg
                if msg in self.msgs:
                    rv = False
            except Exception as e:
                print(traceback.format_exc())
                return rv
            self.msgs.add(msg)
            return rv

    log_formatter = logging.Formatter("%(asctime)s [%(levelname)-5.5s] [%(threadName)-30.30s]   %(message)s")
    file_handler = log_handlers.TimedRotatingFileHandler(filename, encoding="UTF-8", when='W6', backupCount=12)
    file_handler.setFormatter(log_formatter)

    console_handler = logging.StreamHandler()
    console_handler.setFormatter(log_formatter)

    logger = logging.getLogger(filename)
    logger.propagate = False

    logger.addHandler(console_handler)
    logger.addHandler(file_handler)

    logger.setLevel(logging.INFO)

    dup_filter = DuplicateFilter()
    logger.addFilter(dup_filter)
    return logger


log = setup_logger("test.log")
for i in range(3):
    log.info("wow")

Now my records look like this: 2018-07-18 14:34:49,642 [INFO ] [MainThread ] wow They clearly have an asctime and I explicitly set the asctime property in the constructor of my Formatter. The only question similar to mine I found says

To have message and asctime set, you must first call self.format(record) inside the emit method

but doesn't the logging.Formatter do that when you specify the log string the way I did with %(asctime)s?

EDIT: running.t was right, I just didn't understand what the documentation meant. I solved it by adding my formater to my filter and calling the format function at the beginning:

 def __init__(self, formatter):
     self.msgs = {}
     self.formatter = formatter

 def filter(self, record):
     self.formatter.format(record)

Answer 1

In filter objects section of pyton logging module documentation I found following note:

Note that filters attached to handlers are consulted before an event is emitted by the handler, whereas filters attached to loggers are consulted whenever an event is logged (using debug(), info(), etc.), before sending an event to handlers. This means that events which have been generated by descendant loggers will not be filtered by a logger’s filter setting, unless the filter has also been applied to those descendant loggers.

Your filter is added to logger, while formatters are added to handlers. So in my opinion your filter method is applied before any of formatter you specified.

BTW, shouldn't your DuplicateFilter inherit from logging.Filter?