logging Formatter behavior when using msecs and braces : '{'

[fxcallewaert]

BPO	44884
Nosy	@vsajip

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = None
created_at = <Date 2021-08-11.05:43:18.060>
labels = ['type-bug', 'library', '3.11']
title = "logging Formatter behavior when using msecs and braces : '{'"
updated_at = <Date 2021-11-30.13:00:54.821>
user = 'https://bugs.python.org/fxcallewaert'

bugs.python.org fields:

activity = <Date 2021-11-30.13:00:54.821>
actor = 'serhiy.storchaka'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['Library (Lib)']
creation = <Date 2021-08-11.05:43:18.060>
creator = 'fxcallewaert'
dependencies = []
files = []
hgrepos = []
issue_num = 44884
keywords = []
message_count = 1.0
messages = ['399371']
nosy_count = 2.0
nosy_names = ['vinay.sajip', 'fxcallewaert']
pr_nums = []
priority = 'normal'
resolution = None
stage = None
status = 'open'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue44884'
versions = ['Python 3.11']

[fxcallewaert]

>>> import logging
>>> logging.getLogger().handlers[0].setFormatter(logging.Formatter(fmt='{asctime} {message}', style='{'))
>>> logging.error("hello") 
2021-08-11 01:04:54,972 hello 

Wait. I come from a place where we use '.' as a decimal separator ...

>>> logging.getLogger().handlers[0].setFormatter(logging.Formatter(fmt='{asctime}.{msecs:03.0f} {message}', style='{', datefmt="%Y-%m-%d %H:%M:%S")) 
>>> logging.error("hello") 
2021-08-11 01:06:27.471 hello

All very reasonable. I know my date time formatting and my brace formatting so I'm good or am I ...

>>> import time, math
>>> for i in range(2500): a= (lambda : (time.sleep(0.0004), (logging.error("Whaaat!") )if math.modf(time.time())[0]>0.9995 else 0))()
... 
2021-08-11 01:26:40.1000 Whaaat!

You'll hopefully agree that formatting a msecs as 1000 is plain wrong.
Can I get around this ? the best / simplest, I've found is

>>> logging.Formatter.default_msec_format = "%s.%03d"
>>> logging.getLogger().handlers[0].setFormatter(logging.Formatter(fmt='{asctime} {message}', style='{'))
>>> for i in range(2500): a= (lambda : (time.sleep(0.0004), (logging.error("Now that's ok") )if math.modf(time.time())[0]>0.9995 else 0))()
... 
2021-08-11 01:33:46.999 Now that's ok

Having to rely / teach /learn about "Old string formatting" in 2021 is not ideal.
Can you suggest something better ?

or would it be palatable to make a "careful" modification in logging/init.py (see below) ?

replace

self.msecs = (ct - int(ct)) * 1000

by

self.msecs = math.floor((ct - int(ct)) * 1000) #requires importing math

or

self.msecs = int((ct - int(ct)) * 1000) + 0.0