Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Race between setTarget and flush in logging.handlers.MemoryHandler #85675

Closed
iritkatriel opened this issue Aug 7, 2020 · 4 comments
Closed

Race between setTarget and flush in logging.handlers.MemoryHandler #85675

iritkatriel opened this issue Aug 7, 2020 · 4 comments
Labels
3.8 only security fixes 3.9 only security fixes 3.10 only security fixes stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error

Comments

@iritkatriel
Copy link
Member

BPO 41503
Nosy @vsajip, @miss-islington, @iritkatriel
PRs
  • bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765) #21765
  • [3.9] bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765) #21897
  • [3.8] bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765) #21898
    		•

    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 = <Date 2020-08-16.16:31:46.696>
created_at = <Date 2020-08-07.15:10:00.487>
labels = ['3.8', 'type-bug', 'library', '3.9', '3.10']
title = 'Race between setTarget and flush in logging.handlers.MemoryHandler'
updated_at = <Date 2020-08-16.16:31:46.696>
user = 'https://github.com/iritkatriel'

    bugs.python.org fields:

    activity = <Date 2020-08-16.16:31:46.696>
actor = 'vinay.sajip'
assignee = 'none'
closed = True
closed_date = <Date 2020-08-16.16:31:46.696>
closer = 'vinay.sajip'
components = ['Library (Lib)']
creation = <Date 2020-08-07.15:10:00.487>
creator = 'iritkatriel'
dependencies = []
files = []
hgrepos = []
issue_num = 41503
keywords = ['patch']
message_count = 4.0
messages = ['375001', '375510', '375512', '375516']
nosy_count = 3.0
nosy_names = ['vinay.sajip', 'miss-islington', 'iritkatriel']
pr_nums = ['21765', '21897', '21898']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue41503'
versions = ['Python 3.8', 'Python 3.9', 'Python 3.10']
    @iritkatriel
    Copy link
    Member Author

    The logging.handlers.MemoryHandler.setTarget() method does not acquire the lock, so it can change the target while flush is processing the buffer.

    The script below causes flush to call target.handle when target is None, causing:

    File "C:\Users\User\src\cpython\lib\logging\handlers.py", line 1265, in emit
    self.flush()
    File "C:\Users\User\src\cpython\lib\logging\handlers.py", line 1348, in flush
    self.target.handle(record)
    AttributeError: 'NoneType' object has no attribute 'handle'

    ------------------------------------------------

    import io
import logging.handlers
import threading
import time

class SlowHandler:
    def __init__(self):
        self.stream = io.StringIO()
        self.streamHandler = logging.StreamHandler(self.stream)

    def handle(self, msg):
        time.sleep(1)
        self.streamHandler.handle(msg)

target = SlowHandler()
mem_hdlr = logging.handlers.MemoryHandler(10, logging.ERROR, target)
mem_logger = logging.getLogger('mem')
mem_logger.propagate = False
mem_logger.addHandler(mem_hdlr)

def toggleTarget():
    time.sleep(1)
    mem_hdlr.setTarget(None)

t = threading.Thread(target=toggleTarget, args=())
t.daemon = True
t.start()

while True:
    time.sleep(0.1)
    mem_logger.warning("warning not flushed")
    mem_logger.error("error is flushed")

    @iritkatriel iritkatriel added 3.10 only security fixes stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error labels Aug 7, 2020
    @iritkatriel iritkatriel added 3.8 only security fixes 3.9 only security fixes labels Aug 16, 2020
    @vsajip
    Copy link
    Member

    vsajip commented Aug 16, 2020

    New changeset 2353d77 by Irit Katriel in branch 'master':
    bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765)
    2353d77

    @miss-islington
    Copy link
    Contributor

    New changeset 2c050e5 by Miss Islington (bot) in branch '3.9':
    [3.9] bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765) (GH-21897)
    2c050e5

    @miss-islington
    Copy link
    Contributor

    New changeset 08f0a21 by Miss Islington (bot) in branch '3.8':
    [3.8] bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765) (GH-21898)
    08f0a21

    @vsajip vsajip closed this as completed Aug 16, 2020
    @vsajip vsajip closed this as completed Aug 16, 2020
    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Assignees
    No one assigned
    Labels
    3.8 only security fixes 3.9 only security fixes 3.10 only security fixes stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Milestone
    No milestone
    Development

    No branches or pull requests
    3 participants
    @vsajip @iritkatriel @miss-islington