[issue20275] asyncio: remove debug code from BaseEventLoop

Roundup Robot added the comment: New changeset 8bb2c3ae9402 by Victor Stinner in branch 'default': Close #20275: Optimize BaseEventLoop._run_once() http://hg.python.org/cpython/rev/8bb2c3ae9402 -- nosy: +python-dev resolution: -> fixed stage: -> committed/rejected status: open -> close

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: > I don't understand the purpose of these timing information, (...) > By the way, it's not documentation how to enable asyncio logs I added a new page in the asyncio documentation to start documenting common traps with asynchronous programming and to document d

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: > I like logger_is_enabled_for.patch. I prefer debug_flag.patch because it is faster than logger_is_enabled_for.patch (see msg208214). I would like to write the most efficient code for BaseEventLoop._run_once() because this function is the real core of asyncio

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: > I really want to log the time every time if level == DEBUG and only if > 1 > sec for other levels, so maybe all you need to do is remove the comment? :-) > (Or maybe logger.isEnabledFor(logging.INFO) is faster than logger.log() when > nothing gets logged?

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: I opened an issue to propose asyncio.DEBUG: http://code.google.com/p/tulip/issues/detail?id=104 (woops, copy/paste failure :-)) -- ___ Python tracker _

[issue20275] asyncio: remove debug code from BaseEventLoop

Guido van Rossum added the comment: I really want to log the time every time if level == DEBUG and only if > 1 sec for other levels, so maybe all you need to do is remove the comment? :-) (Or maybe logger.isEnabledFor(logging.INFO) is faster than logger.log() when nothing gets logged? --

[issue20275] asyncio: remove debug code from BaseEventLoop

Changes by Antoine Pitrou : -- nosy: -pitrou ___ Python tracker ___ ___ Python-bugs-list mailing list Unsubscribe: https://mail.pyth

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: I opened an issue to propose asyncio.DEBUG: BaseEventLoop._run_once() -- ___ Python tracker ___ ___

[issue20275] asyncio: remove debug code from BaseEventLoop

Changes by Yury Selivanov : Added file: http://bugs.python.org/file33488/greater_than_1sec_logging.patch ___ Python tracker ___ ___ Python-bug

[issue20275] asyncio: remove debug code from BaseEventLoop

Changes by Yury Selivanov : Removed file: http://bugs.python.org/file33487/greater_than_1sec_logging.patch ___ Python tracker ___ ___ Python-b

[issue20275] asyncio: remove debug code from BaseEventLoop

Changes by Yury Selivanov : Added file: http://bugs.python.org/file33487/greater_than_1sec_logging.patch ___ Python tracker ___ ___ Python-bug

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: Victor, Guido, Please take a look at the attached one. I believe it's slightly better, than the "logger_is_enabled_for.patch", since it doesn't log stuff that was faster than 1 second, and is simpler too. -- ___ Pyt

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: And, I think that "asyncio._DEBUG" or even "asyncio.DEBUG" would be a great idea. -- ___ Python tracker ___ ___

[issue20275] asyncio: remove debug code from BaseEventLoop

Guido van Rossum added the comment: I like logger_is_enabled_for.patch. If you want to add other debug features please propose something on the Tulip tracker: http://code.google.com/p/tulip/issues/list . -- ___ Python tracker

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: Victor, Re your patch: since it's not really time syscalls, and Guido said he's using this debug code, how about we just have something like: t0 = self.time() event_list = self._selector.select(timeout) t1 = self.time() if t1 -

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: > Regarding the microbench, please count and report how many times it actually > calls select(). I'm on MacOS X, so it's KqueueSelector. It's 'select' method (and self._kqueue.control respectively) is called twice more times. So for 100K tasks, select gets ca

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: Here are two patches: - logger_is_enabled_for.patch: use logger.isEnabledFor(INFO) to avoid the call - add a _debug flag to BaseEventLoop Benchmark: - original: 3.90 - logger: 3.04 - _debug: 2.81 I like the _debug flag because it's faster, but I'm not sure th

[issue20275] asyncio: remove debug code from BaseEventLoop

Changes by STINNER Victor : -- keywords: +patch Added file: http://bugs.python.org/file33485/debug_flag.patch ___ Python tracker ___ _

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: > Wow, that's impressive that such minor syscalls can take so much times! Apparently, it's not syscalls, it's logging. Actually, with commented out "logging.log" code I can't see a difference wether there are calls to monotonic or not. So we can keep the code

[issue20275] asyncio: remove debug code from BaseEventLoop

Guido van Rossum added the comment: I have definitely used this log message. It typically tells me that something is responding too slow. Regarding the microbench, please count and report how many times it actually calls select(). -- ___ Python tr

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: > With debug code the execution time is around 2.8-3.1s, with debug comment > commented out it's around 2.3-2.4s. Wow, that's impressive that such minor syscalls can take so much times! I modified your script to repeat the test 5 times and take the minimum tim

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: The micro-benchmark i used is here: https://gist.github.com/1st1/8446175 -- ___ Python tracker ___ _

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: I wrote a small micro-benchmark, that creates 100K tasks and executes them. With debug code the execution time is around 2.8-3.1s, with debug comment commented out it's around 2.3-2.4s. Again, it's a micro-benchmark, and in a real application the impact is goi

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: > So you admit you just want to optimize prematurely? I don't understand the purpose of these timing information, I don't use them. I would be more interested to know which functions take longer than XXX ms and so hangs the event loop. By the way, it's not do

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: > What part of the debug timing is more expensive than the select call itself? Well, there is nothing really expensive there, but: - time.monotonic() is still a syscall - logging.log executes a fair amount of code too -- __

[issue20275] asyncio: remove debug code from BaseEventLoop

Guido van Rossum added the comment: So you admit you just want to optimize prematurely? -- ___ Python tracker ___ ___ Python-bugs-list

[issue20275] asyncio: remove debug code from BaseEventLoop

Guido van Rossum added the comment: Can you check for the level of the logger? That would work for me. -- ___ Python tracker ___ ___ P

[issue20275] asyncio: remove debug code from BaseEventLoop

STINNER Victor added the comment: I'm also in favor of removing this code, or a debug flag to enable it. -- nosy: +haypo ___ Python tracker ___ __

[issue20275] asyncio: remove debug code from BaseEventLoop

Guido van Rossum added the comment: What part of the debug timing is more expensive than the select call itself? -- ___ Python tracker ___ ___

[issue20275] asyncio: remove debug code from BaseEventLoop

Yury Selivanov added the comment: And I'd be happy to help with the patch. -- ___ Python tracker ___ ___ Python-bugs-list mailing list

[issue20275] asyncio: remove debug code from BaseEventLoop

New submission from Yury Selivanov: Can we remove debug timing around "self._selector.select(timeout)" (or at least make it configurable) from BaseEventLoop? Right now the code is: # TODO: Instrumentation only in debug mode? t0 = self.time() event_list = self._selector.s