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

False timeout log message on proactor close #78504

Closed
johnboy2 mannequin opened this issue Aug 2, 2018 · 8 comments
Closed

False timeout log message on proactor close #78504

johnboy2 mannequin opened this issue Aug 2, 2018 · 8 comments
Labels
topic-asyncio type-bug An unexpected behavior, bug, or error

Comments

@johnboy2
Copy link
Mannequin

johnboy2 mannequin commented Aug 2, 2018

BPO 34323
Nosy @vstinner, @asvetlov, @1st1, @matrixise, @johnboy2, @johnboy2
PRs
  • bpo-34323: IocpProactor: prevent modification if closed #11494
  • bpo-34323: IocpProactor: prevent modification if closed #11494
  • bpo-34323: IocpProactor: prevent modification if closed #11494
  • bpo-34323: Enhance IocpProactor.close() log #11555
  • bpo-34323: Enhance IocpProactor.close() log #11555
  • bpo-34323: Enhance IocpProactor.close() log #11555
  • [3.7] bpo-34323: Enhance IocpProactor.close() log #11565
  • [3.7] bpo-34323: Enhance IocpProactor.close() log #11565
    		•
    Files
  • repro.py
    		•

    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 2019-01-15.12:06:28.088>
created_at = <Date 2018-08-02.22:50:13.656>
labels = ['type-bug', 'expert-asyncio']
title = 'False timeout log message on proactor close'
updated_at = <Date 2019-01-15.12:06:28.087>
user = 'https://github.com/johnboy2'

    bugs.python.org fields:

    activity = <Date 2019-01-15.12:06:28.087>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2019-01-15.12:06:28.088>
closer = 'vstinner'
components = ['asyncio']
creation = <Date 2018-08-02.22:50:13.656>
creator = 'johnboy2'
dependencies = []
files = ['47730']
hgrepos = []
issue_num = 34323
keywords = ['patch', 'patch', 'patch']
message_count = 8.0
messages = ['322994', '322995', '323035', '323428', '333673', '333681', '333688', '333689']
nosy_count = 6.0
nosy_names = ['vstinner', 'asvetlov', 'yselivanov', 'matrixise', 'johnboy2', 'John Nelson2']
pr_nums = ['11494', '11494', '11494', '11555', '11555', '11555', '11565', '11565']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue34323'
versions = ['Python 3.5']
    @johnboy2
    Copy link
    Mannequin Author

    johnboy2 mannequin commented Aug 2, 2018

    Repro:

    1. Run the attached script ('repro.py')

    Expected output:

    2018-07-31 16:39:57,069 - asyncio - DEBUG - Using proactor: IocpProactor
    2018-07-31 16:39:57,084 - root - INFO - Starting
    2018-07-31 16:39:58,100 - root - INFO - Sleep done
    2018-07-31 16:39:58,100 - root - INFO - Loop closed

    Actual output:

    2018-07-31 16:37:58,583 - asyncio - DEBUG - Using proactor: IocpProactor
    2018-07-31 16:37:58,599 - root - INFO - Starting
    2018-07-31 16:37:59,614 - root - INFO - Sleep done
    2018-07-31 16:37:59,614 - asyncio - DEBUG - taking long time to close proactor
    2018-07-31 16:37:59,614 - root - INFO - Loop closed

    @johnboy2 johnboy2 mannequin added topic-asyncio type-bug An unexpected behavior, bug, or error labels Aug 2, 2018
    @johnboy2
    Copy link
    Mannequin Author

    johnboy2 mannequin commented Aug 2, 2018

    I *suspect* the issue is down to a discrepancy between:

    • IocpProactor.close(), and
    • IocpProactor._poll()

    When the former calls the latter, it seems to be expecting a truth value response from _poll() to indicate that no timeout occurred. However, the latter only ever returns None.

    Of note is that ms != 0 whenever a timeout occurs, potentially giving a simple test point.

    @matrixise
    Copy link
    Member

    Hi johnboy2,

    thank you for your issue, but could you send us more information about your platform?

    thank you

    @johnboy2
    Copy link
    Mannequin Author

    johnboy2 mannequin commented Aug 12, 2018 

    Python 3.5.4 (v3.5.4:3f56838, Aug  8 2017, 02:17:05) [MSC v.1900 64 bit (AMD64)] on win32
Type "help", "copyright", "credits" or "license" for more information.
>>> import platform, sys
>>> platform.win32_ver()
('2012ServerR2', '6.3.9600', 'SP0', 'Multiprocessor Free')
>>> sys.version_info
sys.version_info(major=3, minor=5, micro=4, releaselevel='final', serial=0)

    @vstinner
    Copy link
    Member

    New changeset b1e4573 by Victor Stinner in branch 'master':
    bpo-34323: Enhance IocpProactor.close() log (GH-11555)
    b1e4573

    @vstinner
    Copy link
    Member

    Oops, I used the wrong bpo number for my second change in master:

    New changeset b91140f by Victor Stinner in branch 'master':
    bpo-11555: Enhance IocpProactor.close() log again (GH-11563)
    b91140f

    @vstinner
    Copy link
    Member

    New changeset d5a6adf by Victor Stinner in branch '3.7':
    [3.7] bpo-34323: Enhance IocpProactor.close() log (GH-11565)
    d5a6adf

    @vstinner
    Copy link
    Member

    Ok, the bug is now fixed. Thanks for your bug report John Nelson!

    @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
    topic-asyncio type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Milestone
    No milestone
    Development

    No branches or pull requests
    2 participants
    @matrixise @vstinner