soravux / scoop

SCOOP (Scalable COncurrent Operations in Python)
https://github.com/soravux/scoop
GNU Lesser General Public License v3.0
635 stars 87 forks source link

scoop swallows original exception's tracebacks #19

Open joernhees opened 9 years ago

joernhees commented 9 years ago

if i put the following code in test.py:

import scoop

def boom():
    return 0 / 0

if __name__ == '__main__':
    boom()

and then run it with python -m scoop test.py it gives me the following output:

$ python -m scoop test.py
[2015-05-08 19:14:31,741] launcher  INFO    SCOOP 0.7.1 release on darwin using Python 2.7.9 (default, Jan  7 2015, 11:50:42) [GCC 4.2.1 Compatible Apple LLVM 6.0 (clang-600.0.56)], API: 1013
[2015-05-08 19:14:31,742] launcher  INFO    Deploying 8 worker(s) over 1 host(s).
[2015-05-08 19:14:31,742] launcher  INFO    Worker distribution:
[2015-05-08 19:14:31,742] launcher  INFO       127.0.0.1:   7 + origin
Traceback (most recent call last):
  File "/usr/local/Cellar/python/2.7.9/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/local/Cellar/python/2.7.9/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 302, in <module>
    b.main()
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 92, in main
    self.run()
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 290, in run
    futures_startup()
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 271, in futures_startup
    run_name="__main__"
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/futures.py", line 64, in _startup
    result = _controller.switch(rootFuture, *args, **kargs)
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/_control.py", line 253, in runController
    raise future.exceptionValue
ZeroDivisionError: integer division or modulo by zero
[2015-05-08 19:14:32,265] launcher  (127.0.0.1:50283) INFO    Root process is done.
[2015-05-08 19:14:32,266] launcher  (127.0.0.1:50283) INFO    Finished cleaning spawned subprocesses.
$

As you can see the traceback information was swallowed, making it very hard to understand the errors.

Currently i use the following as a workaround, maybe it might make sense to embed this in scoop?

import sys
import scoop
from functools import wraps

def exception_stack_catcher(func):
    @wraps(func)
    def exception_stack_wrapper(*args, **kwds):
        try:
            return func(*args, **kwds)
        except Exception as e:
            scoop.logger.exception(e)
            raise e, None, sys.exc_info()[2]
    return exception_stack_wrapper

@exception_stack_catcher
def boom():
    return 0 / 0

if __name__ == '__main__':
    boom()

Output:

$ python -m scoop test.py
[2015-05-08 20:14:06,534] launcher  INFO    SCOOP 0.7.1 release on darwin using Python 2.7.9 (default, Jan  7 2015, 11:50:42) [GCC 4.2.1 Compatible Apple LLVM 6.0 (clang-600.0.56)], API: 1013
[2015-05-08 20:14:06,535] launcher  INFO    Deploying 8 worker(s) over 1 host(s).
[2015-05-08 20:14:06,535] launcher  INFO    Worker distribution:
[2015-05-08 20:14:06,535] launcher  INFO       127.0.0.1:   7 + origin
[2015-05-08 20:14:06,753] test (127.0.0.1:58913) ERROR   integer division or modulo by zero
Traceback (most recent call last):
  File "test.py", line 9, in exception_stack_wrapper
    return func(*args, **kwds)
  File "test.py", line 17, in boom
    return 0 / 0
ZeroDivisionError: integer division or modulo by zero
Traceback (most recent call last):
  File "/usr/local/Cellar/python/2.7.9/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/local/Cellar/python/2.7.9/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 302, in <module>
    b.main()
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 92, in main
    self.run()
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 290, in run
    futures_startup()
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/bootstrap/__main__.py", line 271, in futures_startup
    run_name="__main__"
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/futures.py", line 64, in _startup
    result = _controller.switch(rootFuture, *args, **kargs)
  File "/Users/joern/venv/lib/python2.7/site-packages/scoop/_control.py", line 253, in runController
    raise future.exceptionValue
ZeroDivisionError: integer division or modulo by zero
[2015-05-08 20:14:07,070] launcher  (127.0.0.1:51173) INFO    Root process is done.
[2015-05-08 20:14:07,071] launcher  (127.0.0.1:51173) INFO    Finished cleaning spawned subprocesses.
joernhees commented 9 years ago

actually it seems this only works on one host :-/

I already tried modifying scoop (wherever raises future.exceptionValue), but i can't find where that value is ever set. In that place it should probably save the current traceback in the exception, maybe as _tb attribute, so that when the exception is sent back to main, it can re-raise it with that traceback.

joernhees commented 9 years ago

also note that you should never use logging.exception(e), but instead just call it with a message. The exception will be auto-appended, but handing it to logging.exception instead of a message can result in an encoding error raise in the exception handling itself, which hides the actual exception: http://stackoverflow.com/a/31141546/1423333

nickvandewiele commented 8 years ago

I believe this thread is also related: https://groups.google.com/forum/#!topic/scoop-users/z75AF3n1WBU and proposes an alternative to the decorator you mentioned.

joernhees commented 8 years ago

hmm, yes, seems related, but there are a lot of times when you just don't want to put anything on stdout...

also think about nested invocations...