Ok, I've managed to reproduce the "Dummy" thread weirdness without
aiohttp... see attached code. When running this using python 3.4 and
upstream asyncio (as of April 7) on an ubuntu 12.04 machine, I get the
following output:
MainThread(140470366000896): Main Enter
Thread-1(140470315005696): Thread Enter, loop=140470323281760
Thread-1(140470315005696): Caught RuntimeError: Event loop stopped before
Future completed.
Thread-1(140470315005696): Thread Exit
MainThread(140470366000896): Main Exit
Dummy-2(140470366000896): Finally: loop=140470323281760
The finally block that I would have assumed to be executing in Thread-1 is,
at least according to logger, executing in a thread called "Dummy-2", but
with thread id identical to "MainThread".
I'm obviously abusing asyncio here, and this might not be an issue specific
to asyncio (or even an issue at all), but I see similar behaviour when
using aiohttp without hitting any RuntimeErrors, and if someone can explain
what's actually going on here, I'd be very curious to find out!
My guess, not knowing anything about the cpython thread execution model: At
the time when the finally block actually runs, the MainThread is already
gone, and a new "Dummy" thread is created (that recycles MainThread's id)
to execute the "finally" block?
Den tisdagen den 8:e april 2014 kl. 00:56:00 UTC+10 skrev Guido van Rossum:
>
> Code in one frame does not switch threads. However if you have loops on
> different threads and schedule events between those that might happen (the
> latest upstream Tulip has a guard agains this). According to threading.py,
> Dummy threads are used to represent threads not started by that module (but
> e.g. from C code).
>
>
> On Mon, Apr 7, 2014 at 5:17 AM, Lars Andersson <[email protected]<javascript:>
> > wrote:
>
>> Thanks Guido.
>>
>> All that mess manipulating the loop is the hoops I've had to jump through
>> to get the server to shut down without causing ResourceWarnings about open
>> sockets etc. I'll ask the aiohttp developers about a better way for the
>> http server to shut itself down...
>>
>> Still, is it possible that some code in a "finally" block running in
>> Thread-X gets run in a different thread ("In my case, thread "Dummy-X"),
>> after Thread-X has been terminated. I.e, why am I seeing messages from code
>> that should be executing in the http server thread being printed by a
>> thread named "Dummy-X"? (according to logging %(threadName)s )
>>
>>
>> Den måndagen den 7:e april 2014 kl. 17:28:41 UTC+10 skrev Guido van
>> Rossum:
>>>
>>> I can't really help you because I don't know aiohttp, but I note that
>>> you have way too much code manipulating a main loop. I see three separate
>>> loop.run_*() calls and a loop.stop() call that smells funny (because it's
>>> called before the loop is even started). A better idiom would be to put all
>>> this logic (whatever it is) in a couroutine and just run that single
>>> coroutine, so you'd get something like this:
>>>
>>> def http_server_thread():
>>> loop.run_until_complete(my_main_coroutine())
>>> loop.close()
>>>
>>> @coroutine
>>> my_main_coroutine():
>>> ...all the rest of your logic, using yield from to run coroutines...
>>>
>>>
>>> On Sun, Apr 6, 2014 at 7:48 PM, Lars Andersson <[email protected]> wrote:
>>>
>>>>
>>>> Hi,
>>>>
>>>> I'm having some problems to properly shut down an aiohttp server
>>>> running in a separate thread...
>>>>
>>>> The following code is run as a separate python thread to start and stop
>>>> an aiohttp server:
>>>>
>>>> def http_server_thread()
>>>> f = loop.create_server(aiohttp.server.ServerHttpProtocol, ...)
>>>> srv = loop.run_until_complete(f)
>>>> loop.run_forever()
>>>> srv.close()
>>>>
>>>> log.debug("waiting for server to exit...")
>>>> loop.run_until_complete(srv.wait_closed())
>>>> loop.stop()
>>>> loop.run_forever()
>>>>
>>>> loop.close()
>>>> log.error("server thread EXIT")
>>>>
>>>> The server is configured to serve a predefined number of requests, then
>>>> shut it self down by calling self._loop.stop() from within it's request
>>>> handler coroutine (this is used for testing purposes)
>>>>
>>>> Accessing the http server running 'Thread-2' from MainThread generates
>>>> the following events:
>>>>
>>>> MainThread: send GET request to http server running in Thread-2
>>>> Thread-2: REQ01: method = GET; path = /test; transport=139969646978160
>>>> (sock=14)
>>>> Thread-2: Max number or requests served, stopping (by calling
>>>> self._loop.stop())
>>>> Thread-2: New HttpServer Instance: config = {'maxRequests': 2}
>>>> Thread-2: waiting for server to exit...
>>>> Thread-2: closing loop 139969647425744
>>>> Thread-2: server thread EXIT
>>>> Dummy-9: Uncompleted request.
>>>>
>>>> The "Uncompleted request" message is printed by the aiohttp server
>>>> code, and must have been scheduled to run by the server running in
>>>> "Thread-2", but the final message is being printed from another thread,
>>>> "Dummy-9".
>>>>
>>>> What is going on here? Is this something I should be worried about?
>>>>
>>>> Is it valid for a server to shut itself down by calling loop.stop() in
>>>> a request handler?
>>>>
>>>> In general, what's the recommended way to make sure everything in an
>>>> event loop has been completed before closing it?
>>>>
>>>> Sorry if my explanation of the problem wasn't very clear. I can try to
>>>> make a simpler reproduction code snippet if needed.
>>>>
>>>>
>>>
>>>
>>> --
>>> --Guido van Rossum (python.org/~guido)
>>>
>>
>
>
> --
> --Guido van Rossum (python.org/~guido)
>
import asyncio
import threading
import logging
logger = logging.getLogger()
thread_info_handler = logging.StreamHandler()
thread_info_handler.setFormatter(logging.Formatter('%(threadName)s(%(thread)d): %(message)s'))
logger.addHandler(thread_info_handler)
logger.setLevel(logging.INFO)
def thread_func():
@asyncio.coroutine
def close(loop):
loop.stop()
yield from asyncio.sleep(1.0, loop=loop)
@asyncio.coroutine
def callback(loop):
try:
yield from close(loop)
except Exception as e:
logger.info("Exception: %s", str(e))
finally:
logger.info("Finally: loop=%s", id(loop))
loop = asyncio.new_event_loop()
asyncio.set_event_loop(None)
logger.info("Thread Enter, loop=%s", id(loop))
try:
loop.run_until_complete(callback(loop))
except RuntimeError as e:
logger.error("Caught RuntimeError: %s", str(e))
logger.info("Thread Exit")
def main():
logger.info("Main Enter")
asyncio.set_event_loop(None)
thread = threading.Thread(target=thread_func)
thread.start()
thread.join()
logger.info("Main Exit")
main()
