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.

Sign up for GitHub

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

logging's QueueListener drops log messages #72117

Closed
encukou opened this issue Sep 1, 2016 · 3 comments
Closed

logging's QueueListener drops log messages #72117

encukou opened this issue Sep 1, 2016 · 3 comments
Labels
stdlib Python modules in the Lib dir

Comments

@encukou
Copy link
Member

encukou commented Sep 1, 2016

BPO 27930
Nosy @vsajip, @encukou
Files
  • test.py: Test script
    		•

    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 2016-09-08.00:25:23.814>
created_at = <Date 2016-09-01.15:15:59.610>
labels = ['library']
title = "logging's QueueListener drops log messages"
updated_at = <Date 2016-09-08.00:25:23.766>
user = 'https://github.com/encukou'

    bugs.python.org fields:

    activity = <Date 2016-09-08.00:25:23.766>
actor = 'python-dev'
assignee = 'none'
closed = True
closed_date = <Date 2016-09-08.00:25:23.814>
closer = 'python-dev'
components = ['Library (Lib)']
creation = <Date 2016-09-01.15:15:59.610>
creator = 'petr.viktorin'
dependencies = []
files = ['44323']
hgrepos = []
issue_num = 27930
keywords = []
message_count = 3.0
messages = ['274139', '274306', '274931']
nosy_count = 3.0
nosy_names = ['vinay.sajip', 'petr.viktorin', 'python-dev']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue27930'
versions = ['Python 3.5', 'Python 3.6']
    @encukou
    Copy link
    Member Author

    encukou commented Sep 1, 2016

    There are two "barrier" like abstractions on Lib/logging/handlers.py in the _monitor method.

    First _monitor has two loops, what is already kind of a hint something is not right.

    Second, it has two ways to exit the loop, that also exit the thread:

    1. The _stop threading.Event is "set"
    2. The _sentinel object is added to the queue

    The problem is, the documentation says that the correct way to not loose records, the stop method must be called, but, the stop method just sets the _stop object and then adds the _sentinel object to the queue.

    The loop stops when noticing that _stop is set, and then enters a second version of the loop, trying again to see the _sentinel object, but this time with non blocking read.

    The test case shows the problem, but it also hints about the race conditions by the fact that running the test case under "taskset 1" works, so, to reproduce the issue, run the test under a multiprocessor environment.

    The proper solution would be to have a proper locking mechanism, otherwise, the _stop object should not be used, and rely only in seeing the _sentinel field; this is what the class DeterministicQueueListener does in the test case.

    (Reported by Paulo Andrade at https://bugzilla.redhat.com/show_bug.cgi?id=1370484 )

    @encukou encukou added the stdlib Python modules in the Lib dir label Sep 1, 2016
    @vsajip
    Copy link
    Member

    vsajip commented Sep 3, 2016

    Removed 3.3 and 3.4 as they are not in scope for non-security issues.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Sep 8, 2016

    New changeset 121b5b41c9e8 by Vinay Sajip in branch 'default':
    Fixes bpo-27930: improved QueueListener behaviour.
    https://hg.python.org/cpython/rev/121b5b41c9e8

    New changeset b2ea0ede3753 by Vinay Sajip in branch '3.5':
    Fixes bpo-27930: improved QueueListener behaviour.
    https://hg.python.org/cpython/rev/b2ea0ede3753

    New changeset 89b185372b2c by Vinay Sajip in branch 'default':
    Closes bpo-27930: Merged fix from 3.5.
    https://hg.python.org/cpython/rev/89b185372b2c

    @python-dev python-dev mannequin closed this as completed Sep 8, 2016
    @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
    stdlib Python modules in the Lib dir
    Projects
    None yet
    Milestone
    No milestone
    Development

    No branches or pull requests
    2 participants
    @vsajip @encukou