itamarst / eliot

Eliot: the logging system that tells you *why* it happened
https://eliot.readthedocs.io
Apache License 2.0
1.11k stars 66 forks source link

How to make eliot work with asyncio? #280

Closed x0zzz closed 7 years ago

x0zzz commented 7 years ago

Question as in the title. I have a pretty big project with logging handled by eliot. I had to move to PY3.6+asyncio recently. Now I have every coroutine call nesting within all other "opened" calls from eliot POV. This yields a decent mindf**k; a line from eliot-tree:

comm_api:execute_request/2/2/3/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/2/3 ⇒ failed

Do I need to downgrade my logging back to Python's builtin logger or can I work around this somehow?

itamarst commented 7 years ago

Eliot was originally used with a couple of large Twisted programs, so it is indeed possible to write async code that uses Eliot. That being said, I haven't made it easy to use with coroutines and yield yet, so that's a problem (see #259). There's some talk of adding a coroutine-specific context to Python (there's a PEP about it), so this is a general issue, but I do think it's solvable with a decorator for generators at least. And quite possibly for coroutines too, given it's a similar mechanism.

Unfortunately I'm too tired to think through a workaround at the moment; I will try to think about it. And as soon as I have some free time I will try to implement a real solution.

itamarst commented 7 years ago

I wonder if there's a sketch of the proposed context system I could use now...

itamarst commented 7 years ago

Might be able to combine this pattern - https://github.com/Skyscanner/aiotask-context - with eliot's current concept of context. Something like... inside the thread-local storage have a weakref map from current asyncio task to context stack.

x0zzz commented 7 years ago

@itamarst So do you think it's doable? What would be a timeline for making eliot compatible with asyncio? Is there a quick/temporary hack/solution?

itamarst commented 7 years ago

I might have some time to play with it this weekend, we'll see. Can't think of temporary hack, so far, but if I have branch with prototype you can try it if I still haven't reached releasable version.

itamarst commented 7 years ago

There's a branch up with a sketch of a solution: https://github.com/ScatterHQ/eliot/tree/coroutines-280

It has the following semantics:

  1. A coroutine you do await on inherits the current eliot logging context.
  2. Random other coroutines don't.

I believe this is the expected behavior. Please test out this branch on your application and let me know if the resulting logs make sense to you.

Current known limitations, to be addressed before merging to master:

x0zzz commented 7 years ago

Thanks a lot!

Now each coroutine has own root node in eliot-tree, which is awesome. No more madness!

However, all API calls in my app are now timeouting, so something began to block. I'll investigate and let you know whether it's me or you.

itamarst commented 7 years ago

Thanks for testing! Let me know if you figure out the blocking.

What's your application, if I can ask?

x0zzz commented 7 years ago

All is fine, I had choppy WiFi yesterday. Thank you very much for the feature! Much appreciated!

My app is an arbitrage trader of cryptocurrencies. I switched to asyncio because I wanted to scale to more exchanges. I am glad I can keep using Eliot with async, it's extremely useful :)

itamarst commented 7 years ago

Can't close it yet, it's not been merged to master. But glad it works.