bpo-34323: Enhance IocpProactor.close() log (GH-11555)

IocpProactor.close() now uses time to decide when to log: wait 1
second before the first log, then log every second. Log also the
number of seconds since close() was called.
This commit is contained in:
Victor Stinner 2019-01-15 11:48:00 +01:00 committed by GitHub
parent 06f8b57212
commit b1e45739d8
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 18 additions and 3 deletions

View File

@ -7,6 +7,7 @@ import math
import msvcrt import msvcrt
import socket import socket
import struct import struct
import time
import weakref import weakref
from . import events from . import events
@ -802,10 +803,21 @@ class IocpProactor:
context['source_traceback'] = fut._source_traceback context['source_traceback'] = fut._source_traceback
self._loop.call_exception_handler(context) self._loop.call_exception_handler(context)
# wait until all cancelled overlapped future complete # Wait until all cancelled overlapped complete: don't exit with running
# overlapped to prevent a crash. Display progress every second if the
# loop is still running.
msg_update = 1.0
start_time = time.monotonic()
next_msg = start_time + msg_update
while self._cache: while self._cache:
if not self._poll(1): if next_msg <= time.monotonic():
logger.debug('taking long time to close proactor') logger.debug('IocpProactor.close(): '
'loop is running after closing for %.1f seconds',
time.monotonic() - start_time)
next_msg = time.monotonic() + msg_update
# handle a few events, or timeout
self._poll(msg_update)
self._results = [] self._results = []

View File

@ -0,0 +1,3 @@
:mod:`asyncio`: Enhance ``IocpProactor.close()`` log: wait 1 second before
the first log, then log every second. Log also the number of seconds since
``close()`` was called.