This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: Race between setTarget and flush in logging.handlers.MemoryHandler
Type: behavior Stage: resolved
Components: Library (Lib) Versions: Python 3.10, Python 3.9, Python 3.8
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: iritkatriel, miss-islington, vinay.sajip
Priority: normal Keywords: patch

Created on 2020-08-07 15:10 by iritkatriel, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 21765 merged iritkatriel, 2020-08-07 15:16
PR 21897 merged miss-islington, 2020-08-16 15:12
PR 21898 merged miss-islington, 2020-08-16 15:12
Messages (4)
msg375001 - (view) Author: Irit Katriel (iritkatriel) * (Python committer) Date: 2020-08-07 15:10
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")

------------------------------------------------
msg375510 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2020-08-16 15:10
New changeset 2353d77fad7ed9d11d8a4d66b5dd1306cdb94125 by Irit Katriel in branch 'master':
bpo-41503: Fix race between setTarget and flush in logging.handlers.MemoryHandler (GH-21765)
https://github.com/python/cpython/commit/2353d77fad7ed9d11d8a4d66b5dd1306cdb94125
msg375512 - (view) Author: miss-islington (miss-islington) Date: 2020-08-16 15:34
New changeset 2c050e52f1ccf5db03819e4ed70690521d67e9fa 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)
https://github.com/python/cpython/commit/2c050e52f1ccf5db03819e4ed70690521d67e9fa
msg375516 - (view) Author: miss-islington (miss-islington) Date: 2020-08-16 16:27
New changeset 08f0a2109297e8a64e8636d47dce737e5b7ccf2c 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)
https://github.com/python/cpython/commit/08f0a2109297e8a64e8636d47dce737e5b7ccf2c
History
Date User Action Args
2022-04-11 14:59:34adminsetgithub: 85675
2020-08-16 16:31:46vinay.sajipsetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2020-08-16 16:27:08miss-islingtonsetmessages: + msg375516
2020-08-16 15:34:42miss-islingtonsetmessages: + msg375512
2020-08-16 15:12:47miss-islingtonsetpull_requests: + pull_request21017
2020-08-16 15:12:39miss-islingtonsetnosy: + miss-islington
pull_requests: + pull_request21016
2020-08-16 15:10:22vinay.sajipsetmessages: + msg375510
2020-08-16 13:01:20iritkatrielsetversions: + Python 3.8, Python 3.9
2020-08-11 14:29:26iritkatrielsetnosy: + vinay.sajip
2020-08-07 15:16:12iritkatrielsetkeywords: + patch
stage: patch review
pull_requests: + pull_request20909
2020-08-07 15:10:00iritkatrielcreate