CODEWITHSUNDEEP
pythondebuggingprofilingpython-asyncio
user3525723
user3525723

Reputation: 373

Discover what is blocking the event loop

I have thousands of asyncio tasks running.

Something is taking about 10 seconds to complete (some CPU intensive work).

This is making the program not work, as some tasks need to answer a message lets say in 5 seconds, on their network connection.

My current idea is to somehow intercept the event loop. There must be some area in the asyncio module where it executes all current active tasks in an event loop, between each epoll()/select(). If I could insert a "elapsed = time.time()" before and "elapsed = time.time() - elapsed" after each task "resumed", I think it would be enough to find out the tasks that are taking too much time.

I think the related code may be here, at line 79: https://github.com/python/cpython/blob/master/Lib/asyncio/events.py

def _run(self):
    try:
        self._context.run(self._callback, *self._args)
    except (SystemExit, KeyboardInterrupt):
        raise
    except BaseException as exc:
        cb = format_helpers._format_callback_source(
            self._callback, self._args)
        msg = f'Exception in callback {cb}'
        context = {
            'message': msg,
            'exception': exc,
            'handle': self,
        }
        if self._source_traceback:
            context['source_traceback'] = self._source_traceback
        self._loop.call_exception_handler(context)
    self = None  # Needed to break cycles when an exception occurs.

But I don't know what to do here to print any useful info; I need a way to identify what line of my code this "self._context.run(...)" will execute.

I have passed the last 5 sleepless months trying to fix my code and had no success yet.

I have tried to use CProfiler, line_profile, but none of them helped. They tell me the time it takes to execute a function and the time spent on each line. What I need to find out is how much time the code is taken between each loop iteration.

All those profiling/debugging tools I tried gave me no clue what should be fixed. And after rewriting the same program about 15 times in different ways I still can't have it working.

I'm just a non-professional programmer and still a newbie in Python, but if I cant solve this problem the next step will be learning learning Rust, which itself will be a huge pain in the ass and probably 3 years after I started, I will have this thing working, which supposed to take no more than 2 months.

Upvotes: 7

Views: 3368

Answers (2)

Emanuel
Emanuel

Reputation: 722

By the way, there is a built-in cool feature inside asyncio (you can see the code source: here) which tells you if there is a "blocking" function.

You just need to enable the debugging mode (good for load tests).

How to enable the debug mode - you can find here all the options how.

Upvotes: 4

user3525723
user3525723

Reputation: 373

Just edited file /usr/lib/python3.7/asyncio/events.py and added:

import time
import signal
import traceback

START_TIME = 0

def handler(signum, frame):
    print('##########', time.time() - START_TIME)
    traceback.print_stack()

signal.signal(signal.SIGALRM, handler)

And on line 79:

    def _run(self):
        global START_TIME
        try:
            signal.alarm(3)
            START_TIME = time.time()
            self._context.run(self._callback, *self._args)
            signal.alarm(0)
        except Exception as exc:
            cb = format_helpers._format_callback_source(
                self._callback, self._args)
            msg = f'Exception in callback {cb}'
            context = {
                'message': msg,
                'exception': exc,
                'handle': self,
            }
            if self._source_traceback:
                context['source_traceback'] = self._source_traceback
            self._loop.call_exception_handler(context)
        self = None  # Needed to break cycles when an exception occurs.

Now every time some asynchronous code block the event loop for 3 seconds it will show a message.

Found out my problem was with a simple "BeautifulSoup(page, 'html.parser')" where page was a 1mb html file with a big table.

Upvotes: 4

Related Questions