From 66bbddfd08ef9d052eb8e43ee550feea62616c5b Mon Sep 17 00:00:00 2001 From: Luna Date: Thu, 4 Oct 2018 20:28:32 +0100 Subject: [PATCH 01/21] bpo-34844 --- Lib/logging/__init__.py | 46 ++++++++++++++++++++++++++++++++++----- Lib/test/test_logging.py | 47 +++++++++++++++++++++++++--------------- 2 files changed, 70 insertions(+), 23 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 7aeff45f26668a..32f62349482092 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -23,10 +23,13 @@ To use, simply 'import logging' and log away! """ -import sys, os, time, io, traceback, warnings, weakref, collections.abc +import sys, os, time, io, re, traceback, warnings, weakref, collections.abc from string import Template +from contextlib import contextmanager + + __all__ = ['BASIC_FORMAT', 'BufferingFormatter', 'CRITICAL', 'DEBUG', 'ERROR', 'FATAL', 'FileHandler', 'Filter', 'Formatter', 'Handler', 'INFO', 'LogRecord', 'Logger', 'LoggerAdapter', 'NOTSET', 'NullHandler', @@ -413,10 +416,10 @@ def makeLogRecord(dict): rv.__dict__.update(dict) return rv + #--------------------------------------------------------------------------- # Formatter classes and functions #--------------------------------------------------------------------------- - class PercentStyle(object): default_format = '%(message)s' @@ -426,11 +429,32 @@ class PercentStyle(object): def __init__(self, fmt): self._fmt = fmt or self.default_format + @contextmanager + def _verifyFields(self): + """ + Verify if fields passed into XXXStyle. + """ + try: + yield + except KeyError as e: + raise ValueError("Invalid formatting field %s" % e) + def usesTime(self): return self._fmt.find(self.asctime_search) >= 0 + def validate(self): + self._validateFormat(r'(\%\([^%()]+\)[\s\d-]*[\w]+)') + + def _validateFormat(self, expression): + matches = re.search(expression, self._fmt) + if matches is None: + raise ValueError('Invalid format %(fmt)s for %(style)s style' + % {"fmt": self._fmt, "style": self.default_format[0]}) + def format(self, record): - return self._fmt % record.__dict__ + with self._verifyFields(): + return self._fmt % record.__dict__ + class StrFormatStyle(PercentStyle): default_format = '{message}' @@ -438,7 +462,11 @@ class StrFormatStyle(PercentStyle): asctime_search = '{asctime' def format(self, record): - return self._fmt.format(**record.__dict__) + with self._verifyFields(): + return self._fmt.format(**record.__dict__) + + def validate(self): + self._validateFormat(r'(\{[^{}]+\})') class StringTemplateStyle(PercentStyle): @@ -455,7 +483,13 @@ def usesTime(self): return fmt.find('$asctime') >= 0 or fmt.find(self.asctime_format) >= 0 def format(self, record): - return self._tpl.substitute(**record.__dict__) + with self._verifyFields(): + return self._tpl.substitute(**record.__dict__) + + def validate(self): + with self._verifyFields(): + self._validateFormat(r'(\$\{[^${}]+\})') + BASIC_FORMAT = "%(levelname)s:%(name)s:%(message)s" @@ -530,6 +564,8 @@ def __init__(self, fmt=None, datefmt=None, style='%'): raise ValueError('Style must be one of: %s' % ','.join( _STYLES.keys())) self._style = _STYLES[style][0](fmt) + self._style.validate() + self._fmt = self._style._fmt self.datefmt = datefmt diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index d352e5fa3f3de6..e7d9603e410c51 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3163,7 +3163,13 @@ def verify_reverse(stuff): ], pat=r"^[\w.]+ -> (\w+): (\d+)$") def test_out_of_order(self): - self.apply_config(self.out_of_order) + self.assertRaises(ValueError, self.apply_config, self.out_of_order) + + def test_out_of_order_with_dollar_style(self): + config = self.out_of_order.copy() + config['formatters']['mySimpleFormatter']['format'] = "${asctime} (${name}) ${levelname}: ${message}" + + self.apply_config(config) handler = logging.getLogger('mymodule').handlers[0] self.assertIsInstance(handler.target, logging.Handler) self.assertIsInstance(handler.formatter._style, @@ -3491,14 +3497,17 @@ def test_percent(self): f = logging.Formatter('${%(message)s}') self.assertEqual(f.format(r), '${Message with 2 placeholders}') f = logging.Formatter('%(random)s') - self.assertRaises(KeyError, f.format, r) + self.assertRaises(ValueError, f.format, r) self.assertFalse(f.usesTime()) f = logging.Formatter('%(asctime)s') self.assertTrue(f.usesTime()) f = logging.Formatter('%(asctime)-15s') self.assertTrue(f.usesTime()) - f = logging.Formatter('asctime') - self.assertFalse(f.usesTime()) + f = logging.Formatter('%(asctime) - 15s') + self.assertTrue(f.usesTime()) + # Testing ValueError raised from mismatching format + self.assertRaises(ValueError, logging.Formatter, '{asctime}') + self.assertRaises(ValueError, logging.Formatter, '${message}') def test_braces(self): # Test {}-formatting @@ -3506,7 +3515,8 @@ def test_braces(self): f = logging.Formatter('$%{message}%$', style='{') self.assertEqual(f.format(r), '$%Message with 2 placeholders%$') f = logging.Formatter('{random}', style='{') - self.assertRaises(KeyError, f.format, r) + self.assertRaises(ValueError, f.format, r) + f = logging.Formatter("{message}", style='{') self.assertFalse(f.usesTime()) f = logging.Formatter('{asctime}', style='{') self.assertTrue(f.usesTime()) @@ -3514,27 +3524,28 @@ def test_braces(self): self.assertTrue(f.usesTime()) f = logging.Formatter('{asctime:15}', style='{') self.assertTrue(f.usesTime()) - f = logging.Formatter('asctime', style='{') - self.assertFalse(f.usesTime()) + # Testing ValueError raised from mismatching format + self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='{') def test_dollars(self): # Test $-formatting r = self.get_record() - f = logging.Formatter('$message', style='$') + f = logging.Formatter('${message}', style='$') self.assertEqual(f.format(r), 'Message with 2 placeholders') f = logging.Formatter('$$%${message}%$$', style='$') self.assertEqual(f.format(r), '$%Message with 2 placeholders%$') f = logging.Formatter('${random}', style='$') - self.assertRaises(KeyError, f.format, r) + self.assertRaises(ValueError, f.format, r) self.assertFalse(f.usesTime()) f = logging.Formatter('${asctime}', style='$') self.assertTrue(f.usesTime()) - f = logging.Formatter('${asctime', style='$') + f = logging.Formatter('${message}', style='$') self.assertFalse(f.usesTime()) - f = logging.Formatter('$asctime', style='$') + f = logging.Formatter('${asctime}--', style='$') self.assertTrue(f.usesTime()) - f = logging.Formatter('asctime', style='$') - self.assertFalse(f.usesTime()) + # Testing ValueError raised from mismatching format + self.assertRaises(ValueError, logging.Formatter, '{asctime}', style='$') + self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='$') def test_invalid_style(self): self.assertRaises(ValueError, logging.Formatter, None, None, 'x') @@ -4000,10 +4011,10 @@ def test_stream(self): self.assertEqual(handler.stream, stream) def test_format(self): - logging.basicConfig(format='foo') + logging.basicConfig(format='%(asctime)s - %(message)s') formatter = logging.root.handlers[0].formatter - self.assertEqual(formatter._style._fmt, 'foo') + self.assertEqual(formatter._style._fmt, '%(asctime)s - %(message)s') def test_datefmt(self): logging.basicConfig(datefmt='bar') @@ -4032,11 +4043,11 @@ def test_incompatible(self): handlers = [logging.StreamHandler()] stream = sys.stderr assertRaises(ValueError, logging.basicConfig, filename='test.log', - stream=stream) + stream=stream) assertRaises(ValueError, logging.basicConfig, filename='test.log', - handlers=handlers) + handlers=handlers) assertRaises(ValueError, logging.basicConfig, stream=stream, - handlers=handlers) + handlers=handlers) # Issue 23207: test for invalid kwargs assertRaises(ValueError, logging.basicConfig, loglevel=logging.INFO) # Should pop both filename and filemode even if filename is None From 0eaaf25557a87a19595c50a43b79395dad3a1b2c Mon Sep 17 00:00:00 2001 From: Luna Date: Thu, 4 Oct 2018 20:45:18 +0100 Subject: [PATCH 02/21] added news entry --- .../next/Library/2018-10-04-20-44-45.bpo-34844.Hnuxav.rst | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 Misc/NEWS.d/next/Library/2018-10-04-20-44-45.bpo-34844.Hnuxav.rst diff --git a/Misc/NEWS.d/next/Library/2018-10-04-20-44-45.bpo-34844.Hnuxav.rst b/Misc/NEWS.d/next/Library/2018-10-04-20-44-45.bpo-34844.Hnuxav.rst new file mode 100644 index 00000000000000..464dcb1e4ceb9d --- /dev/null +++ b/Misc/NEWS.d/next/Library/2018-10-04-20-44-45.bpo-34844.Hnuxav.rst @@ -0,0 +1,6 @@ +logging.Formatter enhancement - Ensure styles and fmt matches in +logging.Formatter - Added validate method in each format style class: +StrFormatStyle, PercentStyle, StringTemplateStyle. - This method is called +in the constructor of logging.Formatter class - Also re-raise the KeyError +in the format method of each style class, so it would a bit clear that it's +an error with the invalid format fields. From f4f6a60804b66c0b9ffc0547efb0072c4d30e41e Mon Sep 17 00:00:00 2001 From: Luna Date: Fri, 5 Oct 2018 21:27:53 +0100 Subject: [PATCH 03/21] suggested changed before regex fix --- Lib/logging/__init__.py | 44 ++++++++++++++--------------------------- 1 file changed, 15 insertions(+), 29 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 32f62349482092..4a4e820ae89cce 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -425,54 +425,45 @@ class PercentStyle(object): default_format = '%(message)s' asctime_format = '%(asctime)s' asctime_search = '%(asctime)' + validation_pattern = r'(\%\([^%()]+\)[\s\d-]*[\w]+)' def __init__(self, fmt): self._fmt = fmt or self.default_format - @contextmanager - def _verifyFields(self): - """ - Verify if fields passed into XXXStyle. - """ - try: - yield - except KeyError as e: - raise ValueError("Invalid formatting field %s" % e) def usesTime(self): return self._fmt.find(self.asctime_search) >= 0 def validate(self): - self._validateFormat(r'(\%\([^%()]+\)[\s\d-]*[\w]+)') - - def _validateFormat(self, expression): - matches = re.search(expression, self._fmt) - if matches is None: + if not re.search(self.validation_pattern, self._fmt): raise ValueError('Invalid format %(fmt)s for %(style)s style' % {"fmt": self._fmt, "style": self.default_format[0]}) + def _format(self, record): + return self._fmt % record.__dict__ + def format(self, record): - with self._verifyFields(): - return self._fmt % record.__dict__ + try: + return self._format(record) + except KeyError as e: + raise ValueError("Invalid formatting field %s" % e) class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' + validation_pattern = r'(\{[^{}]+\})' - def format(self, record): - with self._verifyFields(): - return self._fmt.format(**record.__dict__) - - def validate(self): - self._validateFormat(r'(\{[^{}]+\})') + def _format(self, record): + return self._fmt.format(**record.__dict__) class StringTemplateStyle(PercentStyle): default_format = '${message}' asctime_format = '${asctime}' asctime_search = '${asctime}' + validation_pattern = r'(\$\{[^${}]+\})' def __init__(self, fmt): self._fmt = fmt or self.default_format @@ -482,13 +473,8 @@ def usesTime(self): fmt = self._fmt return fmt.find('$asctime') >= 0 or fmt.find(self.asctime_format) >= 0 - def format(self, record): - with self._verifyFields(): - return self._tpl.substitute(**record.__dict__) - - def validate(self): - with self._verifyFields(): - self._validateFormat(r'(\$\{[^${}]+\})') + def _format(self, record): + return self._tpl.substitute(**record.__dict__) BASIC_FORMAT = "%(levelname)s:%(name)s:%(message)s" From d51e1867976f51b100903747daee75615a37ad02 Mon Sep 17 00:00:00 2001 From: Luna Date: Sat, 6 Oct 2018 18:49:21 +0100 Subject: [PATCH 04/21] regex changes --- Lib/logging/__init__.py | 7 +++---- Lib/test/test_logging.py | 34 +++++++++++++++++++++++++++------- 2 files changed, 30 insertions(+), 11 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 4a4e820ae89cce..a7934b688f661f 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -425,12 +425,11 @@ class PercentStyle(object): default_format = '%(message)s' asctime_format = '%(asctime)s' asctime_search = '%(asctime)' - validation_pattern = r'(\%\([^%()]+\)[\s\d-]*[\w]+)' + validation_pattern = r'(\%\([^%()]+\)[#|0|\-|\s|+]?[\d]*[d|i|o|u|x|X|e|E|f|E|g|G|C|r|s|a|%]{1})' def __init__(self, fmt): self._fmt = fmt or self.default_format - def usesTime(self): return self._fmt.find(self.asctime_search) >= 0 @@ -453,7 +452,7 @@ class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' - validation_pattern = r'(\{[^{}]+\})' + validation_pattern = r'(\{[^{}-]+\})' def _format(self, record): return self._fmt.format(**record.__dict__) @@ -463,7 +462,7 @@ class StringTemplateStyle(PercentStyle): default_format = '${message}' asctime_format = '${asctime}' asctime_search = '${asctime}' - validation_pattern = r'(\$\{[^${}]+\})' + validation_pattern = r'(\$\{?[\w]+\}?)' def __init__(self, fmt): self._fmt = fmt or self.default_format diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index e7d9603e410c51..1544ed556d26ff 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3503,11 +3503,8 @@ def test_percent(self): self.assertTrue(f.usesTime()) f = logging.Formatter('%(asctime)-15s') self.assertTrue(f.usesTime()) - f = logging.Formatter('%(asctime) - 15s') + f = logging.Formatter('%(asctime)#15s') self.assertTrue(f.usesTime()) - # Testing ValueError raised from mismatching format - self.assertRaises(ValueError, logging.Formatter, '{asctime}') - self.assertRaises(ValueError, logging.Formatter, '${message}') def test_braces(self): # Test {}-formatting @@ -3524,8 +3521,6 @@ def test_braces(self): self.assertTrue(f.usesTime()) f = logging.Formatter('{asctime:15}', style='{') self.assertTrue(f.usesTime()) - # Testing ValueError raised from mismatching format - self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='{') def test_dollars(self): # Test $-formatting @@ -3543,7 +3538,32 @@ def test_dollars(self): self.assertFalse(f.usesTime()) f = logging.Formatter('${asctime}--', style='$') self.assertTrue(f.usesTime()) - # Testing ValueError raised from mismatching format + + def test_format_validate(self): + f = logging.Formatter("%(asctime)-15s - %(message) 5s - %(process)03d - %(module)") + self.assertEqual(f._fmt, "%(asctime)-15s - %(message) 5s - %(process)03d - %(module)") + f = logging.Formatter("$%{message}%$ - {asctime!a:15} - {customfield['key']} - {process:.2f} - {custom.f:.4f}", + style="{") + self.assertEqual(f._fmt, + "$%{message}%$ - {asctime!a:15} - {customfield['key']} - {process:.2f} - {custom.f:.4f}") + f = logging.Formatter("${asctime} - $message", style="$") + self.assertEqual(f._fmt, "${asctime} - $message") + + # Testing when ValueError being raised from incorrect format + # Percentage Style + self.assertRaises(ValueError, logging.Formatter, "%(asctime) - 15s") + self.assertRaises(ValueError, logging.Formatter, "%(asctime)Z") + self.assertRaises(ValueError, logging.Formatter, "%(asctime)b") + self.assertRaises(ValueError, logging.Formatter, "%(asctime)*") + self.assertRaises(ValueError, logging.Formatter, "%(asctime)_") + self.assertRaises(ValueError, logging.Formatter, '{asctime}') + self.assertRaises(ValueError, logging.Formatter, '${message}') + + # StrFormat Style + self.assertRaises(ValueError, logging.Formatter, "{name-thing}", style="{") + self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='{') + + # Dollar style self.assertRaises(ValueError, logging.Formatter, '{asctime}', style='$') self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='$') From cc2cfbda4b47c85b5a9a254dcde13cdbb9a8af88 Mon Sep 17 00:00:00 2001 From: Luna Date: Sat, 6 Oct 2018 22:11:49 +0100 Subject: [PATCH 05/21] commit --- Lib/logging/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index a7934b688f661f..d3b845816aadcd 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -452,7 +452,7 @@ class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' - validation_pattern = r'(\{[^{}-]+\})' + validation_pattern = r'(\{[^{!}-]+(![r|s|a]+)?(:[\d]*)?\})' def _format(self, record): return self._fmt.format(**record.__dict__) From 7c24e469a95d943936ccf6975606c8d53a3c6a83 Mon Sep 17 00:00:00 2001 From: Luna Date: Sat, 6 Oct 2018 22:46:34 +0100 Subject: [PATCH 06/21] rewrote regex --- Lib/logging/__init__.py | 3 ++- Lib/test/test_logging.py | 4 ++++ 2 files changed, 6 insertions(+), 1 deletion(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index d3b845816aadcd..8d42bbd35ae644 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -452,7 +452,8 @@ class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' - validation_pattern = r'(\{[^{!}-]+(![r|s|a]+)?(:[\d]*)?\})' + validation_pattern = r'(\{[^{!:}-]+(![r|s|a]{1})?(:[.]*[<|>|=]?[+|-|\s]?[\d]' \ + r'*[b|c|d|e|E|f|F|g|G|n|o|s|x|X|%]{0,1})?\})' def _format(self, record): return self._fmt.format(**record.__dict__) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 1544ed556d26ff..1197f0b02970cd 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3562,6 +3562,10 @@ def test_format_validate(self): # StrFormat Style self.assertRaises(ValueError, logging.Formatter, "{name-thing}", style="{") self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='{') + self.assertRaises(ValueError, logging.Formatter, '{asctime!Z:15}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{asctime!aa:15}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{process:.2ff}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{process:.2Z}', style='{') # Dollar style self.assertRaises(ValueError, logging.Formatter, '{asctime}', style='$') From abd868d0cf89d69814355c9ca51ac55a761cec27 Mon Sep 17 00:00:00 2001 From: Luna Date: Sun, 7 Oct 2018 20:10:14 +0100 Subject: [PATCH 07/21] changes as requested --- Lib/logging/__init__.py | 14 ++++++-------- Lib/test/test_logging.py | 37 ++++++++++++++++++++++++++++++------- 2 files changed, 36 insertions(+), 15 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 8d42bbd35ae644..ceb91cf948e82c 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -27,8 +27,6 @@ from string import Template -from contextlib import contextmanager - __all__ = ['BASIC_FORMAT', 'BufferingFormatter', 'CRITICAL', 'DEBUG', 'ERROR', 'FATAL', 'FileHandler', 'Filter', 'Formatter', 'Handler', 'INFO', @@ -425,7 +423,7 @@ class PercentStyle(object): default_format = '%(message)s' asctime_format = '%(asctime)s' asctime_search = '%(asctime)' - validation_pattern = r'(\%\([^%()]+\)[#|0|\-|\s|+]?[\d]*[d|i|o|u|x|X|e|E|f|E|g|G|C|r|s|a|%]{1})' + validation_pattern = re.compile(r'%\(\w+\)[#0+ -]*(\*|\d+)?(\.(\*|\d+))?[diouxefgcrsa%]', re.I) def __init__(self, fmt): self._fmt = fmt or self.default_format @@ -434,7 +432,7 @@ def usesTime(self): return self._fmt.find(self.asctime_search) >= 0 def validate(self): - if not re.search(self.validation_pattern, self._fmt): + if not self.validation_pattern.search(self._fmt): raise ValueError('Invalid format %(fmt)s for %(style)s style' % {"fmt": self._fmt, "style": self.default_format[0]}) @@ -445,15 +443,15 @@ def format(self, record): try: return self._format(record) except KeyError as e: - raise ValueError("Invalid formatting field %s" % e) + raise ValueError('Formatting field not found in record: %s' % e) class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' - validation_pattern = r'(\{[^{!:}-]+(![r|s|a]{1})?(:[.]*[<|>|=]?[+|-|\s]?[\d]' \ - r'*[b|c|d|e|E|f|F|g|G|n|o|s|x|X|%]{0,1})?\})' + validation_pattern = re.compile(r'\{[^{!:}-]+(![rsa])?(:(.)?[<>=]?[+ -]?[#0]?[\d]*,?[\.\d]*)?[bcdefgnosx%]?\}', + re.I) def _format(self, record): return self._fmt.format(**record.__dict__) @@ -463,7 +461,7 @@ class StringTemplateStyle(PercentStyle): default_format = '${message}' asctime_format = '${asctime}' asctime_search = '${asctime}' - validation_pattern = r'(\$\{?[\w]+\}?)' + validation_pattern = re.compile(r'\$(([\w]+)|(\{[\w]+(:?\})))', re.I) def __init__(self, fmt): self._fmt = fmt or self.default_format diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 1197f0b02970cd..ccbe55e78bf72c 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3540,24 +3540,44 @@ def test_dollars(self): self.assertTrue(f.usesTime()) def test_format_validate(self): - f = logging.Formatter("%(asctime)-15s - %(message) 5s - %(process)03d - %(module)") - self.assertEqual(f._fmt, "%(asctime)-15s - %(message) 5s - %(process)03d - %(module)") - f = logging.Formatter("$%{message}%$ - {asctime!a:15} - {customfield['key']} - {process:.2f} - {custom.f:.4f}", - style="{") - self.assertEqual(f._fmt, - "$%{message}%$ - {asctime!a:15} - {customfield['key']} - {process:.2f} - {custom.f:.4f}") + # Check correct formatting + # Percentage style + f = logging.Formatter("%(levelname)-15s - %(message) 5s - %(process)03d - %(module) - %(asctime)*.3s") + self.assertEqual(f._fmt, "%(levelname)-15s - %(message) 5s - %(process)03d - %(module) - %(asctime)*.3s") + f = logging.Formatter("%(asctime)*s - %(asctime)*.3s - %(process)-34.33o") + self.assertEqual(f._fmt, "%(asctime)*s - %(asctime)*.3s - %(process)-34.33o") + f = logging.Formatter("%(process)#+027.23X") + self.assertEqual(f._fmt, "%(process)#+027.23X") + f = logging.Formatter("%(foo)#.*g") + self.assertEqual(f._fmt, "%(foo)#.*g") + + # StrFormat Style + f = logging.Formatter("$%{message}%$ - {asctime!a:15} - {customfield['key']}", style="{") + self.assertEqual(f._fmt, "$%{message}%$ - {asctime!a:15} - {customfield['key']}") + f = logging.Formatter("{process:.2f} - {custom.f:.4f}", style="{") + self.assertEqual(f._fmt, "{process:.2f} - {custom.f:.4f}") + f = logging.Formatter("{customfield!s:#<30}", style="{") + self.assertEqual(f._fmt, "{customfield!s:#<30}") + f = logging.Formatter("{message!r}", style="{") + self.assertEqual(f._fmt, "{message!r}") + f = logging.Formatter("{process!s:<#30,12f}- {custom:=+#30,.1d} - {module:^30}", style="{") + self.assertEqual(f._fmt, "{process!s:<#30,12f}- {custom:=+#30,.1d} - {module:^30}") + + # Dollar style f = logging.Formatter("${asctime} - $message", style="$") self.assertEqual(f._fmt, "${asctime} - $message") # Testing when ValueError being raised from incorrect format # Percentage Style - self.assertRaises(ValueError, logging.Formatter, "%(asctime) - 15s") self.assertRaises(ValueError, logging.Formatter, "%(asctime)Z") self.assertRaises(ValueError, logging.Formatter, "%(asctime)b") self.assertRaises(ValueError, logging.Formatter, "%(asctime)*") + self.assertRaises(ValueError, logging.Formatter, "%(asctime)*3s") self.assertRaises(ValueError, logging.Formatter, "%(asctime)_") self.assertRaises(ValueError, logging.Formatter, '{asctime}') self.assertRaises(ValueError, logging.Formatter, '${message}') + self.assertRaises(ValueError, logging.Formatter, '%(foo)#12.3*f') # with both * and decimal number as precision + self.assertRaises(ValueError, logging.Formatter, '%(foo)0*.8*f') # StrFormat Style self.assertRaises(ValueError, logging.Formatter, "{name-thing}", style="{") @@ -3566,10 +3586,13 @@ def test_format_validate(self): self.assertRaises(ValueError, logging.Formatter, '{asctime!aa:15}', style='{') self.assertRaises(ValueError, logging.Formatter, '{process:.2ff}', style='{') self.assertRaises(ValueError, logging.Formatter, '{process:.2Z}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{process!s:<##30,12g}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{process!s:<#30#,12g}', style='{') # Dollar style self.assertRaises(ValueError, logging.Formatter, '{asctime}', style='$') self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='$') + self.assertRaises(ValueError, logging.Formatter, '${asctime', style='$') def test_invalid_style(self): self.assertRaises(ValueError, logging.Formatter, None, None, 'x') From c1359bb69c517fbda011b3f01d1aee3b2bece867 Mon Sep 17 00:00:00 2001 From: Luna Date: Sun, 7 Oct 2018 20:16:17 +0100 Subject: [PATCH 08/21] changes as requested --- Lib/logging/__init__.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index ceb91cf948e82c..3bdc6fb2bd3af4 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -433,8 +433,8 @@ def usesTime(self): def validate(self): if not self.validation_pattern.search(self._fmt): - raise ValueError('Invalid format %(fmt)s for %(style)s style' - % {"fmt": self._fmt, "style": self.default_format[0]}) + raise ValueError('Invalid format %s for %s style' + % (self._fmt, self.default_format[0])) def _format(self, record): return self._fmt % record.__dict__ From 921ba331d8dddffb373105f752c39a42a5629a1a Mon Sep 17 00:00:00 2001 From: Luna Date: Mon, 8 Oct 2018 21:42:09 +0100 Subject: [PATCH 09/21] added doc and docstring, added some of the original tests back for $ style --- Doc/library/logging.rst | 3 +++ Lib/logging/__init__.py | 1 + Lib/test/test_logging.py | 4 ++++ 3 files changed, 8 insertions(+) diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst index c63ea212e41f5a..32444bf49458a1 100644 --- a/Doc/library/logging.rst +++ b/Doc/library/logging.rst @@ -544,6 +544,9 @@ The useful mapping keys in a :class:`LogRecord` are given in the section on .. versionchanged:: 3.2 The *style* parameter was added. + .. versionchanged:: 3.8 + Incorrect or mismatch style and ftm will raise a ``ValueError``. For + example: ``logging.Formatter('%(asctime)s - %(message)s', style='{')``. .. method:: format(record) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 3bdc6fb2bd3af4..047d2e9e970d1d 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -432,6 +432,7 @@ def usesTime(self): return self._fmt.find(self.asctime_search) >= 0 def validate(self): + """Validate the input format, ensure it matches the correct style""" if not self.validation_pattern.search(self._fmt): raise ValueError('Invalid format %s for %s style' % (self._fmt, self.default_format[0])) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index ccbe55e78bf72c..cab32503627014 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3527,6 +3527,8 @@ def test_dollars(self): r = self.get_record() f = logging.Formatter('${message}', style='$') self.assertEqual(f.format(r), 'Message with 2 placeholders') + f = logging.Formatter('$message', style='$') + self.assertEqual(f.format(r), 'Message with 2 placeholders') f = logging.Formatter('$$%${message}%$$', style='$') self.assertEqual(f.format(r), '$%Message with 2 placeholders%$') f = logging.Formatter('${random}', style='$') @@ -3534,6 +3536,8 @@ def test_dollars(self): self.assertFalse(f.usesTime()) f = logging.Formatter('${asctime}', style='$') self.assertTrue(f.usesTime()) + f = logging.Formatter('$asctime', style='$') + self.assertTrue(f.usesTime()) f = logging.Formatter('${message}', style='$') self.assertFalse(f.usesTime()) f = logging.Formatter('${asctime}--', style='$') From 8484f296872c1e87ad41e562f09af44e70de484b Mon Sep 17 00:00:00 2001 From: Luna Date: Wed, 10 Oct 2018 00:43:59 +0100 Subject: [PATCH 10/21] changed validate method for StrFormatStyle --- Doc/library/logging.rst | 2 +- Lib/logging/__init__.py | 34 +++++++++++++++++++++++++++++----- 2 files changed, 30 insertions(+), 6 deletions(-) diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst index 32444bf49458a1..76f946cc9c0ebb 100644 --- a/Doc/library/logging.rst +++ b/Doc/library/logging.rst @@ -545,7 +545,7 @@ The useful mapping keys in a :class:`LogRecord` are given in the section on The *style* parameter was added. .. versionchanged:: 3.8 - Incorrect or mismatch style and ftm will raise a ``ValueError``. For + Incorrect or mismatch style and fmt will raise a ``ValueError``. For example: ``logging.Formatter('%(asctime)s - %(message)s', style='{')``. .. method:: format(record) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 047d2e9e970d1d..c34f3c5acd5245 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -26,6 +26,7 @@ import sys, os, time, io, re, traceback, warnings, weakref, collections.abc from string import Template +from string import Formatter as StrFormatter __all__ = ['BASIC_FORMAT', 'BufferingFormatter', 'CRITICAL', 'DEBUG', 'ERROR', @@ -434,8 +435,13 @@ def usesTime(self): def validate(self): """Validate the input format, ensure it matches the correct style""" if not self.validation_pattern.search(self._fmt): - raise ValueError('Invalid format %s for %s style' - % (self._fmt, self.default_format[0])) + self._invalid_raise() + + def _invalid_raise(self, additional_message=None): + msg = 'Invalid format %s for %s style' % (self._fmt, self.default_format[0]) + if additional_message: + msg = "%s, %s" % (msg, additional_message) + raise ValueError(msg) def _format(self, record): return self._fmt % record.__dict__ @@ -451,18 +457,36 @@ class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' - validation_pattern = re.compile(r'\{[^{!:}-]+(![rsa])?(:(.)?[<>=]?[+ -]?[#0]?[\d]*,?[\.\d]*)?[bcdefgnosx%]?\}', - re.I) + # This is only for validating the format_spec + validation_pattern = re.compile(r"^((.)?[<>=]?[+ -]?[#0]?[\d]*,?[\.\d]*)?[bcdefgnosx%]?$", re.I) def _format(self, record): return self._fmt.format(**record.__dict__) + def validate(self): + """Validate the input format, ensure it is the correct string formatting style""" + try: + fields = [] + for _, field_name, spec, conversion in StrFormatter().parse(self._fmt): + + if field_name and "-" not in field_name: + if conversion and conversion not in "rsa": + raise ValueError("invalid conversion %s for field %s" % (conversion, field_name)) + if spec and not self.validation_pattern.search(spec): + raise ValueError("invalid spec %s for %s" % (spec[-1], field_name)) + + fields.append(field_name) + if not fields: + raise ValueError("No fields found for format %s" % self._fmt) + except ValueError as e: + self._invalid_raise(e) + class StringTemplateStyle(PercentStyle): default_format = '${message}' asctime_format = '${asctime}' asctime_search = '${asctime}' - validation_pattern = re.compile(r'\$(([\w]+)|(\{[\w]+(:?\})))', re.I) + validation_pattern = re.compile(r'\$(\w+|\{\w+\})', re.I) def __init__(self, fmt): self._fmt = fmt or self.default_format From 4c35216c40ba42d9f52486f1bba1b60b6b27dabe Mon Sep 17 00:00:00 2001 From: Luna Date: Wed, 10 Oct 2018 22:03:50 +0100 Subject: [PATCH 11/21] changed on StrFormatStyle class --- Lib/logging/__init__.py | 33 +++++++++++++++------- Lib/test/test_logging.py | 60 +++++++++++++++++++++++++++++++++++----- 2 files changed, 76 insertions(+), 17 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index c34f3c5acd5245..374a2d988a7732 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -419,6 +419,10 @@ def makeLogRecord(dict): #--------------------------------------------------------------------------- # Formatter classes and functions #--------------------------------------------------------------------------- +_str_formatter = StrFormatter() +del StrFormatter + + class PercentStyle(object): default_format = '%(message)s' @@ -438,7 +442,7 @@ def validate(self): self._invalid_raise() def _invalid_raise(self, additional_message=None): - msg = 'Invalid format %s for %s style' % (self._fmt, self.default_format[0]) + msg = "Invalid format '%s' for '%s' style" % (self._fmt, self.default_format[0]) if additional_message: msg = "%s, %s" % (msg, additional_message) raise ValueError(msg) @@ -458,29 +462,38 @@ class StrFormatStyle(PercentStyle): asctime_format = '{asctime}' asctime_search = '{asctime' # This is only for validating the format_spec - validation_pattern = re.compile(r"^((.)?[<>=]?[+ -]?[#0]?[\d]*,?[\.\d]*)?[bcdefgnosx%]?$", re.I) + validation_pattern = re.compile(r"^(.?[<>=^]?[+ -]?#?0?[\d]*,?(\.[\d]*)?)?[bcdefgnosx%]?$", re.I) + spec_fmt_pattern = re.compile(r"(?<=(? Date: Fri, 12 Oct 2018 19:59:59 +0100 Subject: [PATCH 12/21] commit --- Lib/logging/__init__.py | 72 ++++++++++++++++++------------------ Lib/test/test_logging.py | 80 ++++++++++++++++++++++++++++++++++------ 2 files changed, 104 insertions(+), 48 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 374a2d988a7732..58afcd29c90a0a 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -439,13 +439,7 @@ def usesTime(self): def validate(self): """Validate the input format, ensure it matches the correct style""" if not self.validation_pattern.search(self._fmt): - self._invalid_raise() - - def _invalid_raise(self, additional_message=None): - msg = "Invalid format '%s' for '%s' style" % (self._fmt, self.default_format[0]) - if additional_message: - msg = "%s, %s" % (msg, additional_message) - raise ValueError(msg) + raise ValueError("Invalid format '%s' for '%s' style" % (self._fmt, self.default_format[0])) def _format(self, record): return self._fmt % record.__dict__ @@ -461,45 +455,36 @@ class StrFormatStyle(PercentStyle): default_format = '{message}' asctime_format = '{asctime}' asctime_search = '{asctime' - # This is only for validating the format_spec - validation_pattern = re.compile(r"^(.?[<>=^]?[+ -]?#?0?[\d]*,?(\.[\d]*)?)?[bcdefgnosx%]?$", re.I) - spec_fmt_pattern = re.compile(r"(?<=(?=^])?[+ -]?#?0?(\d+|{\w+})?[,_]?(\.(\d+|{\w+}))?[bcdefgnosx%]?$', re.I) + field_spec = re.compile(r'^(\d+|\w+)(\.\w+|\[[^]]+\])*$') def _format(self, record): return self._fmt.format(**record.__dict__) - def _validate(self, fmt): - try: - fields = [] - for _, field_name, spec, conversion in _str_formatter.parse(fmt): - - if field_name: - if "-" in field_name: - raise ValueError("Invalid field name '%s', cannot have '-' in field name") - if conversion and conversion not in "rsa": - raise ValueError("invalid conversion '%s' for '%s' field" % (conversion, field_name)) - if spec: - if self.spec_fmt_pattern.search(spec): - return self._validate(spec) - elif not self.validation_pattern.search(spec): - raise ValueError("invalid spec %s for '%s' field" % (spec[-1], field_name)) - - fields.append(field_name) - if not fields: - raise ValueError("no fields found") - except ValueError as e: - self._invalid_raise(e) - def validate(self): """Validate the input format, ensure it is the correct string formatting style""" - self._validate(self._fmt) + fields = set() + try: + for _, fieldname, spec, conversion in _str_formatter.parse(self._fmt): + if fieldname: + if not self.field_spec.match(fieldname): + raise ValueError('invalid field name/expression: %r' % fieldname) + fields.add(fieldname) + if conversion and conversion not in 'rsa': + raise ValueError('invalid conversion: %r' % conversion) + if spec and not self.fmt_spec.match(spec): + raise ValueError('bad specifier: %r' % spec) + except ValueError as e: + raise ValueError('invalid format: %s' % e) + if not fields: + raise ValueError('invalid format: no fields') class StringTemplateStyle(PercentStyle): default_format = '${message}' asctime_format = '${asctime}' asctime_search = '${asctime}' - validation_pattern = re.compile(r'\$(\w+|\{\w+\})', re.I) def __init__(self, fmt): self._fmt = fmt or self.default_format @@ -509,6 +494,20 @@ def usesTime(self): fmt = self._fmt return fmt.find('$asctime') >= 0 or fmt.find(self.asctime_format) >= 0 + def validate(self): + pattern = Template.pattern + fields = set() + for m in pattern.finditer(self._fmt): + d = m.groupdict() + if d['named']: + fields.add(d['named']) + elif d['braced']: + fields.add(d['braced']) + elif m.group(0) == '$': + raise ValueError('invalid format: bare \'$\' not allowed') + if not fields: + raise ValueError('invalid format: no fields') + def _format(self, record): return self._tpl.substitute(**record.__dict__) @@ -566,7 +565,7 @@ class Formatter(object): converter = time.localtime - def __init__(self, fmt=None, datefmt=None, style='%'): + def __init__(self, fmt=None, datefmt=None, style='%', validate=True): """ Initialize the formatter with specified format strings. @@ -586,7 +585,8 @@ def __init__(self, fmt=None, datefmt=None, style='%'): raise ValueError('Style must be one of: %s' % ','.join( _STYLES.keys())) self._style = _STYLES[style][0](fmt) - self._style.validate() + if validate: + self._style.validate() self._fmt = self._style._fmt self.datefmt = datefmt diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 73b0364f914c24..e697d2b6ceb31d 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3570,16 +3570,34 @@ def test_format_validate(self): self.assertEqual(f._fmt, "{customfield!s:#<30}") f = logging.Formatter("{message!r}", style="{") self.assertEqual(f._fmt, "{message!r}") + f = logging.Formatter("{message!s}", style="{") + self.assertEqual(f._fmt, "{message!s}") + f = logging.Formatter("{message!a}", style="{") + self.assertEqual(f._fmt, "{message!a}") + f = logging.Formatter("{process!r:4.2}", style="{") + self.assertEqual(f._fmt, "{process!r:4.2}") f = logging.Formatter("{process!s:<#30,.12f}- {custom:=+#30,.1d} - {module:^30}", style="{") self.assertEqual(f._fmt, "{process!s:<#30,.12f}- {custom:=+#30,.1d} - {module:^30}") - f = logging.Formatter("{process!s:{w},{p}}", style="{") - self.assertEqual(f._fmt, "{process!s:{w},{p}}") - # f = logging.Formatter("{process!s:{{w}},{{p})}", style="{") - # self.assertEqual(f._fmt, "{process!s:{{w}},{{p}}}") + f = logging.Formatter("{process!s:{w},.{p}}", style="{") + self.assertEqual(f._fmt, "{process!s:{w},.{p}}") + f = logging.Formatter("{foo:12.{p}}", style="{") + self.assertEqual(f._fmt, "{foo:12.{p}}") + f = logging.Formatter("{foo:{w}.6}", style="{") + self.assertEqual(f._fmt, "{foo:{w}.6}") + f = logging.Formatter("{foo[0].bar[1].baz}", style="{") + self.assertEqual(f._fmt, "{foo[0].bar[1].baz}") + f = logging.Formatter("{foo[k1].bar[k2].baz}", style="{") + self.assertEqual(f._fmt, "{foo[k1].bar[k2].baz}") + f = logging.Formatter("{12[k1].bar[k2].baz}", style="{") + self.assertEqual(f._fmt, "{12[k1].bar[k2].baz}") # Dollar style f = logging.Formatter("${asctime} - $message", style="$") self.assertEqual(f._fmt, "${asctime} - $message") + f = logging.Formatter("$bar $$", style="$") + self.assertEqual(f._fmt, "$bar $$") + f = logging.Formatter("$bar $$$$", style="$") + self.assertEqual(f._fmt, "$bar $$$$") # this would print two $($$) # Testing when ValueError being raised from incorrect format # Percentage Style @@ -3597,30 +3615,30 @@ def test_format_validate(self): # Testing failure for '-' in field name self.assert_error_message( ValueError, - "Invalid format '{name-thing}' for '{' style, Invalid field 'name-thing', cannot have '-' in field name", + "invalid field name/expression: 'name-thing'", logging.Formatter, "{name-thing}", style="{" ) # Testing failure for style mismatch self.assert_error_message( ValueError, - "Invalid format '{name-thing}' for '{' style, no fields found", + "invalid format: no fields", logging.Formatter, '%(asctime)s', style='{' ) # Testing failure for invalid conversion self.assert_error_message( ValueError, - "Invalid format '{asctime!Z:15}' for '{' style, invalid conversion 'Z' for 'asctime' field" + "invalid conversion: 'Z'" ) self.assertRaises(ValueError, logging.Formatter, '{asctime!s:#30,15f}', style='{') self.assert_error_message( ValueError, - "Invalid format '{asctime!aa:15}' for '{' style, expected ':' after conversion specifier", + "invalid format: expected ':' after conversion specifier", logging.Formatter, '{asctime!aa:15}', style='{' ) # Testing failure for invalid spec self.assert_error_message( ValueError, - "Invalid format '{asctime!Z:15}' for '{' style, invalid spect '.2ff' for 'process' field", + "bad specifier: '.2ff'", logging.Formatter, '{process:.2ff}', style='{' ) self.assertRaises(ValueError, logging.Formatter, '{process:.2Z}', style='{') @@ -3630,18 +3648,55 @@ def test_format_validate(self): # Testing failure for mismatch braces self.assert_error_message( ValueError, - "Invalid format '{process' for '{' style, unmatched '{' in format spec", + "invalid format: unmatched '{' in format spec", logging.Formatter, '{process', style='{' ) self.assert_error_message( ValueError, - "Invalid format 'process}' for '{' style, unmatched '{' in format spec", + "invalid format: unmatched '{' in format spec", logging.Formatter, 'process}', style='{' ) + self.assertRaises(ValueError, logging.Formatter, '{{foo!r:4.2}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{{foo!r:4.2}}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo/bar}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo:{{w}}.{{p}}}}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo!X:{{w}}.{{p}}}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo!a:random}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo!a:ran{dom}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo!a:ran{d}om}', style='{') + self.assertRaises(ValueError, logging.Formatter, '{foo.!a:d}', style='{') # Dollar style - self.assertRaises(ValueError, logging.Formatter, '{asctime}', style='$') + # Testing failure for mismatch bare $ + self.assert_error_message( + ValueError, + "invalid format: bare \'$\' not allowed", + logging.Formatter, '$bar $$$', style='$' + ) + self.assert_error_message( + ValueError, + "invalid format: bare \'$\' not allowed", + logging.Formatter, 'bar $', style='$' + ) + self.assert_error_message( + ValueError, + "invalid format: bare \'$\' not allowed", + logging.Formatter, 'foo $.', style='$' + ) + # Testing failure for mismatch style + self.assert_error_message( + ValueError, + "invalid format: no fields", + logging.Formatter, '{asctime}', style='$' + ) self.assertRaises(ValueError, logging.Formatter, '%(asctime)s', style='$') + + # Testing failure for incorrect fields + self.assert_error_message( + ValueError, + "invalid format: no fields", + logging.Formatter, 'foo', style='$' + ) self.assertRaises(ValueError, logging.Formatter, '${asctime', style='$') def test_invalid_style(self): @@ -3705,6 +3760,7 @@ def test_formatting(self): 'deliberate mistake')) self.assertTrue(r.stack_info.startswith('Stack (most recent ' 'call last):\n')) + print(r.stack_info) self.assertTrue(r.stack_info.endswith('logging.exception(\'failed\', ' 'stack_info=True)')) From aab0c4622eb2be3866bd4409a563c58f13d58071 Mon Sep 17 00:00:00 2001 From: Luna Date: Sat, 13 Oct 2018 10:46:06 +0100 Subject: [PATCH 13/21] removed redundant debugging print --- Lib/test/test_logging.py | 1 - 1 file changed, 1 deletion(-) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index e697d2b6ceb31d..c19b799859ca15 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3760,7 +3760,6 @@ def test_formatting(self): 'deliberate mistake')) self.assertTrue(r.stack_info.startswith('Stack (most recent ' 'call last):\n')) - print(r.stack_info) self.assertTrue(r.stack_info.endswith('logging.exception(\'failed\', ' 'stack_info=True)')) From 59879e92bb00e5a5d6b599489a733383e7a0fcb0 Mon Sep 17 00:00:00 2001 From: Luna Date: Sat, 13 Oct 2018 21:34:17 +0100 Subject: [PATCH 14/21] added options to logging.config.dictConfig to allow passing in validate parameter --- Lib/logging/config.py | 19 +++++- Lib/test/test_logging.py | 137 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 155 insertions(+), 1 deletion(-) diff --git a/Lib/logging/config.py b/Lib/logging/config.py index fa1a398aee2a2b..319808f2392390 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -33,6 +33,7 @@ import sys import threading import traceback +from inspect import signature from socketserver import ThreadingTCPServer, StreamRequestHandler @@ -666,13 +667,29 @@ def configure_formatter(self, config): dfmt = config.get('datefmt', None) style = config.get('style', '%') cname = config.get('class', None) + validate = config.get('validate', True) if not cname: c = logging.Formatter + result = c(fmt, dfmt, style, validate) else: c = _resolve(cname) - result = c(fmt, dfmt, style) + if self._has_validate_param(config, c): + result = c(fmt, dfmt, style, validate) + else: + result = c(fmt, dfmt, style) return result + def _has_validate_param(self, config, formatter_callable): + """Check if formatter callable has validate parameter""" + params = signature(formatter_callable).parameters + if not isinstance(formatter_callable, logging.Formatter) or \ + not params.get('validate') or params.get("kwargs"): + if config.get('validate'): + raise TypeError('%r has not validate in parameters' % formatter_callable) + + return False + return True + def configure_filter(self, config): """Configure a filter from a dictionary.""" if '()' in config: diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index c19b799859ca15..bfd801f6005be9 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -2125,6 +2125,10 @@ def test_warnings_no_handlers(self): def formatFunc(format, datefmt=None): return logging.Formatter(format, datefmt) +class myCustomFormatter: + def __init__(self, fmt, datefmt=None): + pass + def handlerFunc(): return logging.StreamHandler() @@ -2765,6 +2769,114 @@ class ConfigDictTest(BaseTest): } } + # Configuration with custom logging.Formatter subclass as '()' key and 'validate' set to False + custom_formatter_class_validate = { + 'version': 1, + 'formatters': { + 'form1': { + '()': __name__ + '.ExceptionFormatter', + 'format': '%(levelname)s:%(name)s:%(message)s', + 'validate': False, + }, + }, + 'handlers' : { + 'hand1' : { + 'class': 'logging.StreamHandler', + 'formatter': 'form1', + 'level': 'NOTSET', + 'stream': 'ext://sys.stdout', + }, + }, + "loggers": { + "my_test_logger_custom_formatter": { + "level": "DEBUG", + "handlers": ["hand1"], + "propagate": "true" + } + } + } + + # Configuration with custom logging.Formatter subclass as 'class' key and 'validate' set to False + custom_formatter_class_validate2 = { + 'version': 1, + 'formatters': { + 'form1': { + 'class': __name__ + '.ExceptionFormatter', + 'format': '%(levelname)s:%(name)s:%(message)s', + 'validate': False, + }, + }, + 'handlers' : { + 'hand1' : { + 'class': 'logging.StreamHandler', + 'formatter': 'form1', + 'level': 'NOTSET', + 'stream': 'ext://sys.stdout', + }, + }, + "loggers": { + "my_test_logger_custom_formatter": { + "level": "DEBUG", + "handlers": ["hand1"], + "propagate": "true" + } + } + } + + # Configuration with custom class that is not inherited from logging.Formatter + custom_formatter_class_validate3 = { + 'version': 1, + 'formatters': { + 'form1': { + 'class': __name__ + '.myCustomFormatter', + 'format': '%(levelname)s:%(name)s:%(message)s', + 'validate': False, + }, + }, + 'handlers' : { + 'hand1' : { + 'class': 'logging.StreamHandler', + 'formatter': 'form1', + 'level': 'NOTSET', + 'stream': 'ext://sys.stdout', + }, + }, + "loggers": { + "my_test_logger_custom_formatter": { + "level": "DEBUG", + "handlers": ["hand1"], + "propagate": "true" + } + } + } + + # Configuration with custom function and 'validate' set to False + custom_formatter_with_function = { + 'version': 1, + 'formatters': { + 'form1': { + '()': formatFunc, + 'format': '%(levelname)s:%(name)s:%(message)s', + 'validate': False, + }, + }, + 'handlers' : { + 'hand1' : { + 'class': 'logging.StreamHandler', + 'formatter': 'form1', + 'level': 'NOTSET', + 'stream': 'ext://sys.stdout', + }, + }, + "loggers": { + "my_test_logger_custom_formatter": { + "level": "DEBUG", + "handlers": ["hand1"], + "propagate": "true" + } + } + } + def apply_config(self, conf): logging.config.dictConfig(conf) @@ -3175,6 +3287,31 @@ def test_out_of_order_with_dollar_style(self): self.assertIsInstance(handler.formatter._style, logging.StringTemplateStyle) + def test_custom_formatter_class_with_validate(self): + self.apply_config(self.custom_formatter_class_validate) + handler = logging.getLogger("my_test_logger_custom_formatter").handlers[0] + self.assertIsInstance(handler.formatter, ExceptionFormatter) + + def test_custom_formatter_class_with_validate2(self): + self.apply_config(self.custom_formatter_class_validate2) + handler = logging.getLogger("my_test_logger_custom_formatter").handlers[0] + self.assertIsInstance(handler.formatter, ExceptionFormatter) + + def test_custom_formatter_class_with_validate2_with_wrong_fmt(self): + config = self.custom_formatter_class_validate.copy() + config['formatters']['form1']['style'] = "$" + + # Exception should not be raise as we have configured 'validate' to False + self.apply_config(config) + handler = logging.getLogger("my_test_logger_custom_formatter").handlers[0] + self.assertIsInstance(handler.formatter, ExceptionFormatter) + + def test_custom_formatter_class_with_validate3(self): + self.assertRaises(ValueError, self.apply_config, self.custom_formatter_class_validate3) + + def test_custom_formatter_function_with_validate(self): + self.assertRaises(ValueError, self.apply_config, self.custom_formatter_with_function) + def test_baseconfig(self): d = { 'atuple': (1, 2, 3), From 43c0b344237f9f83d9504fdbdf2afca02f0f6564 Mon Sep 17 00:00:00 2001 From: Luna Date: Sat, 13 Oct 2018 21:41:46 +0100 Subject: [PATCH 15/21] added in documentation for the validate key in logging.config.dictConfig --- Doc/library/logging.config.rst | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/Doc/library/logging.config.rst b/Doc/library/logging.config.rst index de805eb955dfbe..8a3b026fb13903 100644 --- a/Doc/library/logging.config.rst +++ b/Doc/library/logging.config.rst @@ -226,6 +226,11 @@ otherwise, the context is used to determine what to instantiate. (with defaults of ``None``) and these are used to construct a :class:`~logging.Formatter` instance. + .. versionchanged:: 3.8 + a ``validate`` key (with defaults of ``True``) can be added into + the ``formatters`` section of the configuring dict, this is to + validate the correct format. + * *filters* - the corresponding value will be a dict in which each key is a filter id and each value is a dict describing how to configure the corresponding Filter instance. From 908c3ec74a73b45c9721552a6d32c6cabfc7880c Mon Sep 17 00:00:00 2001 From: Luna Date: Sun, 14 Oct 2018 12:31:43 +0100 Subject: [PATCH 16/21] removing blank space --- Lib/test/test_logging.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index bfd801f6005be9..9802955e6a985b 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -3305,10 +3305,10 @@ def test_custom_formatter_class_with_validate2_with_wrong_fmt(self): self.apply_config(config) handler = logging.getLogger("my_test_logger_custom_formatter").handlers[0] self.assertIsInstance(handler.formatter, ExceptionFormatter) - + def test_custom_formatter_class_with_validate3(self): self.assertRaises(ValueError, self.apply_config, self.custom_formatter_class_validate3) - + def test_custom_formatter_function_with_validate(self): self.assertRaises(ValueError, self.apply_config, self.custom_formatter_with_function) From d73ab3adcd5a04cfa7c42c04169e296b0241ef1a Mon Sep 17 00:00:00 2001 From: Luna Date: Sun, 14 Oct 2018 12:48:34 +0100 Subject: [PATCH 17/21] rewrote logging.config.DictConfigurator.configure_formatter logic, simplified process without importing inspect module --- Doc/library/logging.config.rst | 4 ++-- Lib/logging/config.py | 32 +++++++++++++++----------------- 2 files changed, 17 insertions(+), 19 deletions(-) diff --git a/Doc/library/logging.config.rst b/Doc/library/logging.config.rst index 8a3b026fb13903..c351c25e750e43 100644 --- a/Doc/library/logging.config.rst +++ b/Doc/library/logging.config.rst @@ -227,9 +227,9 @@ otherwise, the context is used to determine what to instantiate. :class:`~logging.Formatter` instance. .. versionchanged:: 3.8 - a ``validate`` key (with defaults of ``True``) can be added into + a ``validate`` key (with default of ``True``) can be added into the ``formatters`` section of the configuring dict, this is to - validate the correct format. + validate the format. * *filters* - the corresponding value will be a dict in which each key is a filter id and each value is a dict describing how to configure diff --git a/Lib/logging/config.py b/Lib/logging/config.py index 319808f2392390..85e7526ea32d80 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -33,7 +33,6 @@ import sys import threading import traceback -from inspect import signature from socketserver import ThreadingTCPServer, StreamRequestHandler @@ -667,28 +666,27 @@ def configure_formatter(self, config): dfmt = config.get('datefmt', None) style = config.get('style', '%') cname = config.get('class', None) - validate = config.get('validate', True) + if not cname: c = logging.Formatter - result = c(fmt, dfmt, style, validate) else: c = _resolve(cname) - if self._has_validate_param(config, c): - result = c(fmt, dfmt, style, validate) - else: - result = c(fmt, dfmt, style) - return result - def _has_validate_param(self, config, formatter_callable): - """Check if formatter callable has validate parameter""" - params = signature(formatter_callable).parameters - if not isinstance(formatter_callable, logging.Formatter) or \ - not params.get('validate') or params.get("kwargs"): - if config.get('validate'): - raise TypeError('%r has not validate in parameters' % formatter_callable) + # Identifying if we need to pass in the validate parameter to the formatter + # - The default in logging.Formatter is True, so we won't need to pass in + # if "validate" key is not in the config + use_validate = False + if config.get("validate"): + use_validate = True + + # A TypeError would be raised if "validate" key is passed in with a formatter callable + # that does not accept "validate" as a parameter + if use_validate: + result = c(fmt, dfmt, style, config["validate"]) + else: + result = c(fmt, dfmt, style) - return False - return True + return result def configure_filter(self, config): """Configure a filter from a dictionary.""" From ff05742c5ba05d062c4ff14ee7790d7f969b2eee Mon Sep 17 00:00:00 2001 From: Luna Date: Sun, 14 Oct 2018 12:51:00 +0100 Subject: [PATCH 18/21] document typo change on logging.rst --- Doc/library/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst index 76f946cc9c0ebb..309e3b620ab5ed 100644 --- a/Doc/library/logging.rst +++ b/Doc/library/logging.rst @@ -545,7 +545,7 @@ The useful mapping keys in a :class:`LogRecord` are given in the section on The *style* parameter was added. .. versionchanged:: 3.8 - Incorrect or mismatch style and fmt will raise a ``ValueError``. For + Incorrect or mismatched style and fmt will raise a ``ValueError``. For example: ``logging.Formatter('%(asctime)s - %(message)s', style='{')``. .. method:: format(record) From 2664f85ea4f8336ac620136cbf814021a2fb5e72 Mon Sep 17 00:00:00 2001 From: Luna Date: Sun, 14 Oct 2018 13:06:58 +0100 Subject: [PATCH 19/21] reformatted logging.config.rst --- Doc/library/logging.config.rst | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/Doc/library/logging.config.rst b/Doc/library/logging.config.rst index c351c25e750e43..7f6c3c69739d01 100644 --- a/Doc/library/logging.config.rst +++ b/Doc/library/logging.config.rst @@ -227,9 +227,9 @@ otherwise, the context is used to determine what to instantiate. :class:`~logging.Formatter` instance. .. versionchanged:: 3.8 - a ``validate`` key (with default of ``True``) can be added into - the ``formatters`` section of the configuring dict, this is to - validate the format. + a ``validate`` key (with default of ``True``) can be added into + the ``formatters`` section of the configuring dict, this is to + validate the format. * *filters* - the corresponding value will be a dict in which each key is a filter id and each value is a dict describing how to configure From 74ca6a26a288428ec4dd5e616624f36b4d00c396 Mon Sep 17 00:00:00 2001 From: Luna Date: Mon, 15 Oct 2018 13:19:26 +0100 Subject: [PATCH 20/21] simplified the logic in logging.config.DictConfig.configure_formatter --- Doc/library/logging.rst | 5 +++-- Lib/logging/config.py | 11 ++--------- 2 files changed, 5 insertions(+), 11 deletions(-) diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst index 309e3b620ab5ed..e3937c4eb32c5c 100644 --- a/Doc/library/logging.rst +++ b/Doc/library/logging.rst @@ -545,8 +545,9 @@ The useful mapping keys in a :class:`LogRecord` are given in the section on The *style* parameter was added. .. versionchanged:: 3.8 - Incorrect or mismatched style and fmt will raise a ``ValueError``. For - example: ``logging.Formatter('%(asctime)s - %(message)s', style='{')``. + The `validate` parameter was added. Incorrect or mismatched style and fmt + will raise a ``ValueError``. + For example: ``logging.Formatter('%(asctime)s - %(message)s', style='{')``. .. method:: format(record) diff --git a/Lib/logging/config.py b/Lib/logging/config.py index 85e7526ea32d80..cfd93116eeddbd 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -672,17 +672,10 @@ def configure_formatter(self, config): else: c = _resolve(cname) - # Identifying if we need to pass in the validate parameter to the formatter - # - The default in logging.Formatter is True, so we won't need to pass in - # if "validate" key is not in the config - use_validate = False - if config.get("validate"): - use_validate = True - # A TypeError would be raised if "validate" key is passed in with a formatter callable # that does not accept "validate" as a parameter - if use_validate: - result = c(fmt, dfmt, style, config["validate"]) + if 'validate' in config: # if user hasn't mentioned it, the default will be fine + result = c(fmt, dfmt, style, config['validate']) else: result = c(fmt, dfmt, style) From de1243f4d03074a8712c89fc45508150fd677176 Mon Sep 17 00:00:00 2001 From: Luna Date: Mon, 15 Oct 2018 14:02:51 +0100 Subject: [PATCH 21/21] fixed document due to failure --- Doc/library/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst index e3937c4eb32c5c..71a46ac7f20ac9 100644 --- a/Doc/library/logging.rst +++ b/Doc/library/logging.rst @@ -545,7 +545,7 @@ The useful mapping keys in a :class:`LogRecord` are given in the section on The *style* parameter was added. .. versionchanged:: 3.8 - The `validate` parameter was added. Incorrect or mismatched style and fmt + The *validate* parameter was added. Incorrect or mismatched style and fmt will raise a ``ValueError``. For example: ``logging.Formatter('%(asctime)s - %(message)s', style='{')``.