Skip to content

Commit bafee5d

Browse files
committed
Address review: keep optional imports nested, keep shutdown ones eager
Keep ssl and multiprocessing.queues as function-level imports. A module-level lazy import is resolved by inspect.getmembers() and pydoc, so ssl breaks them on a build without _ssl, and multiprocessing defeats the deferral the comment there asks for. Neither costs anything: a nested import and a module-level lazy import defer identically. Leave pickle, socket and struct eager in handlers.py. A record emitted from a __del__ during finalization can no longer import, so a SocketHandler pickled its first record too late and dropped it. Resolve logging.handlers in fileConfig() before it evaluates any config expression against vars(logging), so the documented handlers.X spelling works again in a fresh process, both in class= and in defaults=. Add tests for each, and pin the laziness that is left.
1 parent d73d223 commit bafee5d

3 files changed

Lines changed: 111 additions & 5 deletions

File tree

‎Lib/logging/config.py‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,6 @@
4040
lazy import struct
4141
lazy from bisect import bisect_left
4242
lazy from logging import handlers as logging_handlers
43-
lazy from multiprocessing.queues import Queue as MPQueue
4443
lazy from socketserver import StreamRequestHandler, ThreadingTCPServer
4544

4645

@@ -83,6 +82,9 @@ def fileConfig(fname, defaults=None, disable_existing_loggers=True, encoding=Non
8382
except configparser.ParsingError as e:
8483
raise RuntimeError(f'{fname} is invalid: {e}')
8584

85+
# the eval()s below resolve "handlers.X" names against vars(logging)
86+
_ = logging_handlers
87+
8688
formatters = _create_formatters(cp)
8789

8890
# critical section
@@ -511,6 +513,9 @@ def _is_queue_like_object(obj):
511513
"""Check that *obj* implements the Queue API."""
512514
if isinstance(obj, (queue.Queue, queue.SimpleQueue)):
513515
return True
516+
# defer importing multiprocessing as much as possible; a lazy import at
517+
# module level would still be resolved by getmembers() and pydoc
518+
from multiprocessing.queues import Queue as MPQueue
514519
if isinstance(obj, MPQueue):
515520
return True
516521
# Depending on the multiprocessing start context, we cannot create

‎Lib/logging/handlers.py‎

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -26,19 +26,18 @@
2626
import io # must stay eager to support finalization
2727
import logging
2828
import os
29+
import pickle
2930
import re
31+
import socket
32+
import struct
3033
import threading
3134
import time
3235
lazy import base64
3336
lazy import copy
3437
lazy import email.utils
3538
lazy import http.client
36-
lazy import pickle
3739
lazy import queue
3840
lazy import smtplib
39-
lazy import socket
40-
lazy import ssl
41-
lazy import struct
4241
lazy import urllib.parse
4342
lazy from email.message import EmailMessage
4443

@@ -1132,6 +1131,8 @@ def emit(self, record):
11321131
msg.set_content(self.format(record))
11331132
if self.username:
11341133
if self.secure is not None:
1134+
import ssl # not lazy: breaks getmembers() without _ssl
1135+
11351136
try:
11361137
keyfile = self.secure[0]
11371138
except IndexError:

‎Lib/test/test_logging.py‎

Lines changed: 100 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1865,6 +1865,45 @@ def test_defaults_do_no_interpolation(self):
18651865
finally:
18661866
os.unlink(fn)
18671867

1868+
def test_names_from_handlers_module(self):
1869+
# gh-156777: "handlers.X" in a class or defaults entry is evaluated
1870+
# against vars(logging), so logging.handlers must be imported first.
1871+
# Run it in a subprocess, since importing this module already
1872+
# imports logging.handlers.
1873+
ini = textwrap.dedent("""
1874+
[loggers]
1875+
keys=root
1876+
1877+
[handlers]
1878+
keys=hand1
1879+
1880+
[formatters]
1881+
keys=form1
1882+
1883+
[logger_root]
1884+
handlers=hand1
1885+
1886+
[handler_hand1]
1887+
class=handlers.MemoryHandler
1888+
formatter=form1
1889+
args=(10,)
1890+
1891+
[formatter_form1]
1892+
format=%(levelname)s ++ %(message)s ++ %(port)s
1893+
defaults={'port': handlers.DEFAULT_TCP_LOGGING_PORT}
1894+
""").strip()
1895+
fd, fn = tempfile.mkstemp(prefix='test_logging_', suffix='.ini')
1896+
self.addCleanup(os.unlink, fn)
1897+
os.write(fd, ini.encode('ascii'))
1898+
os.close(fd)
1899+
code = textwrap.dedent(f"""
1900+
import logging, logging.config
1901+
logging.config.fileConfig({fn!r}, encoding="utf-8")
1902+
h = logging.getLogger().handlers[0]
1903+
assert isinstance(h, logging.handlers.MemoryHandler), h
1904+
""")
1905+
assert_python_ok("-c", code)
1906+
18681907

18691908
@support.requires_working_socket()
18701909
@threading_helper.requires_working_threading()
@@ -5437,6 +5476,35 @@ def __del__(self):
54375476
with open(filename, encoding="utf-8") as fp:
54385477
self.assertEqual(fp.read().rstrip(), "ERROR:root:log in __del__")
54395478

5479+
def test_socket_handler_at_shutdown(self):
5480+
# gh-156777: SocketHandler pickles the record before sending it, and
5481+
# that must keep working when importing no longer can.
5482+
code = textwrap.dedent("""
5483+
import logging
5484+
import logging.handlers
5485+
import os
5486+
5487+
class Handler(logging.handlers.SocketHandler):
5488+
# report what emit() did instead of doing network I/O
5489+
def send(self, s):
5490+
os.write(1, b"sent %d bytes" % len(s))
5491+
5492+
def handleError(self, record):
5493+
os.write(1, b"record dropped")
5494+
5495+
h = Handler('localhost', logging.handlers.DEFAULT_TCP_LOGGING_PORT)
5496+
r = logging.LogRecord('n', logging.INFO, 'p', 1, 'msg', None, None)
5497+
5498+
class A:
5499+
# the module globals are already cleared when __del__ runs
5500+
def __del__(self, h=h, r=r):
5501+
h.emit(r)
5502+
5503+
a = A()
5504+
""")
5505+
rc, out, err = assert_python_ok("-c", code)
5506+
self.assertStartsWith(out.decode(), "sent ")
5507+
54405508
def test_recursion_error(self):
54415509
# Issue 36272
54425510
code = textwrap.dedent("""
@@ -7536,6 +7604,38 @@ def test_without_pywin32(self):
75367604
h.emit(r)
75377605

75387606

7607+
class LazyImportTest(unittest.TestCase):
7608+
7609+
"""Tests for the module level lazy imports of the logging package."""
7610+
7611+
def test_lazy_imports_config(self):
7612+
import_helper.ensure_lazy_imports(
7613+
"logging.config",
7614+
{"configparser", "json", "logging.handlers", "multiprocessing",
7615+
"select", "socket", "socketserver", "struct"},
7616+
additional_code="logging.config.dictConfig({'version': 1})\n",
7617+
)
7618+
7619+
def test_lazy_imports_handlers(self):
7620+
import_helper.ensure_lazy_imports(
7621+
"logging.handlers",
7622+
{"base64", "copy", "email", "http", "queue", "smtplib", "ssl",
7623+
"urllib"},
7624+
)
7625+
7626+
def test_getmembers_without_ssl(self):
7627+
# gh-156777: getmembers() and pydoc resolve lazy imports, so a module
7628+
# level "lazy import ssl" would break them on a build without _ssl.
7629+
code = textwrap.dedent("""
7630+
import sys
7631+
sys.modules['_ssl'] = None
7632+
import inspect
7633+
import logging.handlers
7634+
inspect.getmembers(logging.handlers)
7635+
""")
7636+
assert_python_ok("-c", code)
7637+
7638+
75397639
class MiscTestCase(unittest.TestCase):
75407640
def test__all__(self):
75417641
not_exported = {

0 commit comments

Comments
 (0)