Debugging issues

[jkramar]

I'm having trouble using a debugger with sacred. For simplicity, I'm running 01_hello_world.py but with an error thrown in in main().

If I try python 01_hello_world.py -D, which is supposed to start a pdb client, then the following happens:

WARNING - hello_world_01 - No observers have been added to this run
INFO - hello_world_01 - Running command 'main'
INFO - hello_world_01 - Started
ERROR - hello_world_01 - Failed after 0:00:00!
Traceback (most recent call last):
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.py", line 242, in run_commandline
    return self.run(cmd_name, config_updates, named_configs, {}, args)
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.py", line 187, in run
    run()
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/run.py", line 190, in __call__
    self.result = self.main_function(*args)
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/config/captured_function.py", line 47, in captured_function
    result = wrapped(*args, **kwargs)
  File "hello_world_01.py", line 31, in main
    print('Hello world!' + 1)
TypeError: coercing to Unicode: need string or buffer, int found

(And at this point python takes input and outputs nothing until I kill it.)

If I instead ipdb 01_hello_world.py -d, I get the following error (after I continue):

> /home/mirrormodel/janos/hello_world_01.py(20)<module>()
     18 If you want to learn more about the command-line interface try
     19 ``help`` or ``-h``.
---> 20 """
     21 from __future__ import division, print_function, unicode_literals
     22 from sacred import Experiment

ipdb> c
INFO - hello_world_01 - Running command 'main'
INFO - hello_world_01 - Started
ERROR - hello_world_01 - Failed after 0:00:00!
Traceback (most recent call last):
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/ipdb/__main__.py", line 168, in main
    pdb._runscript(mainpyfile)
  File "/usr/local/anaconda2/lib/python2.7/pdb.py", line 1233, in _runscript
    self.run(statement)
  File "/usr/local/anaconda2/lib/python2.7/bdb.py", line 400, in run
    exec cmd in globals, locals
  File "<string>", line 1, in <module>
  File "hello_world_01.py", line 20, in <module>
    """
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.py", line 130, in automain
    self.run_commandline()
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.py", line 242, in run_commandline
    return self.run(cmd_name, config_updates, named_configs, {}, args)
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.py", line 187, in run
    run()
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/run.py", line 190, in __call__
    self.result = self.main_function(*args)
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/config/captured_function.py", line 47, in captured_function
    result = wrapped(*args, **kwargs)
  File "hello_world_01.py", line 31, in main
    print('Hello world!' + 1)
TypeError: coercing to Unicode: need string or buffer, int found
Uncaught exception. Entering post mortem debugging
Running 'cont' or 'step' will restart the program
> /home/mirrormodel/janos/hello_world_01.py(31)main()
     27
     28 # This function should be executed so we are decorating it with @ex.automain
     29 @ex.automain
     30 def main():
---> 31     print('Hello world!' + 1)

Traceback (most recent call last):
  File "/home/mirrormodel/.local/bin/ipdb", line 11, in <module>
    sys.exit(main())
  File "/home/mirrormodel/.local/lib/python2.7/site-packages/ipdb/__main__.py", line 184, in main
    pdb.interaction(None, t)
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/core/debugger.py", line 289, in interaction
    OldPdb.interaction(self, frame, traceback)
  File "/usr/local/anaconda2/lib/python2.7/pdb.py", line 210, in interaction
    self.cmdloop()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/terminal/debugger.py", line 65, in cmdloop
    line = self.pt_cli.run(reset_current_buffer=True).text
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/interface.py", line 399, in run
    self._redraw()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/interface.py", line 346, in _redraw
    self.renderer.render(self, self.layout, is_done=self.is_done)
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/renderer.py", line 398, in render
    size = output.get_size()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/terminal/vt100_output.py", line 359, in get_size
    rows, columns = _get_size(stdout.fileno())
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/terminal/vt100_output.py", line 317, in _get_size
    fcntl.ioctl(fileno, termios.TIOCGWINSZ, buf, True)
IOError: [Errno 25] Inappropriate ioctl for device

If you suspect this is an IPython bug, please report it at:
    https://github.com/ipython/ipython/issues
or send an email to the mailing list at ipython-dev@scipy.org

You can print a more detailed traceback right now with "%tb", or use "%debug"
to interactively debug it.

Extra-detailed tracebacks for bug-reporting purposes can be enabled via:
    %config Application.verbose_crash=True

Similarly, if I ipython -i 01_hello_world.py -- -d:

Python 2.7.12 |Anaconda 4.2.0 (64-bit)| (default, Jul  2 2016, 17:42:40)
Type "copyright", "credits" or "license" for more information.

IPython 5.1.0 -- An enhanced Interactive Python.
?         -> Introduction and overview of IPython's features.
%quickref -> Quick reference.
help      -> Python's own help system.
object?   -> Details about 'object', use 'object??' for extra details.
INFO - hello_world_01 - Running command 'main'
INFO - hello_world_01 - Started
ERROR - hello_world_01 - Failed after 0:00:00!

TypeErrorTraceback (most recent call last)
/home/mirrormodel/janos/hello_world_01.py in <module>()
     27
     28 # This function should be executed so we are decorating it with @ex.automain
---> 29 @ex.automain
     30 def main():
     31     print('Hello world!' + 1)

/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.pyc in automain(self, function)
    128                                    'interactive mode. Use @ex.main instead.')
    129
--> 130             self.run_commandline()
    131         return captured
    132

/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.pyc in run_commandline(self, argv)
    240
    241         try:
--> 242             return self.run(cmd_name, config_updates, named_configs, {}, args)
    243         except Exception:
    244             if not self.current_run or self.current_run.debug:

/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/experiment.pyc in run(self, command_name, config_updates, named_configs, meta_info, options)
    185         run = self._create_run(command_name, config_updates, named_configs,
    186                                meta_info, options)
--> 187         run()
    188         return run
    189

/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/run.pyc in __call__(self, *args)
    188                     self._start_heartbeat()
    189                     self._execute_pre_run_hooks()
--> 190                     self.result = self.main_function(*args)
    191                     self._execute_post_run_hooks()
    192                     if self.result is not None:

/home/mirrormodel/.local/lib/python2.7/site-packages/sacred/config/captured_function.pyc in captured_function(wrapped, instance, args, kwargs)
     45     start_time = time.time()
     46     # =================== run actual function =================================
---> 47     result = wrapped(*args, **kwargs)
     48     # =========================================================================
     49     stop_time = time.time()

/home/mirrormodel/janos/hello_world_01.py in main()
     29 @ex.automain
     30 def main():
---> 31     print('Hello world!' + 1)

TypeError: coercing to Unicode: need string or buffer, int found

Traceback (most recent call last):
  File "/usr/local/anaconda2/bin/ipython", line 6, in <module>
    sys.exit(IPython.start_ipython())
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/__init__.py", line 119, in start_ipython
    return launch_new_instance(argv=argv, **kwargs)
  File "/usr/local/anaconda2/lib/python2.7/site-packages/traitlets/config/application.py", line 653, in launch_instance
    app.start()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/terminal/ipapp.py", line 348, in start
    self.shell.mainloop()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/terminal/interactiveshell.py", line 440, in mainloop
    self.interact()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/terminal/interactiveshell.py", line 423, in interact
    code = self.prompt_for_code()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/IPython/terminal/interactiveshell.py", line 333, in prompt_for_code
    pre_run=self.pre_prompt, reset_current_buffer=True)
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/interface.py", line 399, in run
    self._redraw()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/interface.py", line 346, in _redraw
    self.renderer.render(self, self.layout, is_done=self.is_done)
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/renderer.py", line 398, in render
    size = output.get_size()
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/terminal/vt100_output.py", line 359, in get_size
    rows, columns = _get_size(stdout.fileno())
  File "/usr/local/anaconda2/lib/python2.7/site-packages/prompt_toolkit/terminal/vt100_output.py", line 317, in _get_size
    fcntl.ioctl(fileno, termios.TIOCGWINSZ, buf, True)
IOError: [Errno 25] Inappropriate ioctl for device

If you suspect this is an IPython bug, please report it at:
    https://github.com/ipython/ipython/issues
or send an email to the mailing list at ipython-dev@scipy.org

You can print a more detailed traceback right now with "%tb", or use "%debug"
to interactively debug it.

Extra-detailed tracebacks for bug-reporting purposes can be enabled via:
    %config Application.verbose_crash=True

What can I do to successfully debug my experiments?

[Qwlouse]

I'm having trouble properly reproducing this behavior. From my attempts so far it seems that it is always working fine under python 3. The freeze with python 01_hello_world -D under python 2.7 seems to be connected to stdout capturing, and I'm still trying to find out what goes wrong (debugging the debugger is tricky...).

However doing ipdb 01_hello_world.py -d works fine for me under both python 2 and python 3 and so does for example the classic python -m pdb 01_hello_world.py -d ipython -i 01_hello_world.py -- -d for me does run without the second error, but somehow yields scrambled symbols in the command prompt.

I'll dig further into the python 2.7 python 01_hello_world -D problem. Meanwhile you could maybe try python 3, python -m pdb 01_hello_world.py -d, or maybe updating ipdb.

[jkramar]

Hi Klaus,

Thanks for getting back!

When I look further into what happens if I do ipdb 01_hello_world.py -d , the problem occurs at utils.py:146, where tee_output() tries to os.dup2 ipython's stdout and stderr into some subprocesses, and ipython doesn't like that. However, python -m pdb 01_hello_world.py -d seems to work fine. :) Thanks for the tip!

Janos

On Tue, Jan 31, 2017 at 7:41 PM, Klaus Greff notifications@github.com wrote:

I'm having trouble properly reproducing this behavior. From my attempts so far it seems that it is always working fine under python 3. The freeze with python 01_hello_world -D under python 2.7 seems to be connected to stdout capturing, and I'm still trying to find out what goes wrong (debugging the debugger is tricky...).

However doing ipdb 01_hello_world.py -d works fine for me under both python 2 and python 3 and so does for example the classic python -m pdb 01_hello_world.py -d ipython -i 01_hello_world.py -- -d for me does run without the second error, but somehow yields scrambled symbols in the command prompt.

I'll dig further into the python 2.7 python 01_hello_world -D problem. Meanwhile you could maybe try python 3, python -m pdb 01_hello_world.py -d, or maybe updating ipdb.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/IDSIA/sacred/issues/134#issuecomment-276469458, or mute the thread https://github.com/notifications/unsubscribe-auth/AAxtDO__QrwSrQDEoZzD-XjsdxsFrO58ks5rX457gaJpZM4LvVu3 .

[Qwlouse]

I've changed the tee_output to always properly tidy up the filedescriptors. For me that fixes the ipdb problems. See if it helps and reopen this issue if needed.

PS: This was a nasty one. Thanks for finding it!

[black-puppydog]

I am having similar problems, but with pudb. What works for me is disabling the tee_output entirely when self.unobserved. Wouldn't that be a good idea in any case? Or are there reasons to capture the output when there's no chance of storing it anywhere anyway?

[corcra]

I have encountered an issue using ipdb.set_trace() with FileStorageObserver (possibly other observers, haven't tested that).

01_hello_world.py works fine as-is. If I modify it to include the observer, and include an ipdb.set_trace() statement, as follows:

from __future__ import division, print_function, unicode_literals
from sacred import Experiment
from sacred.observers import FileStorageObserver
import ipdb

# Create an Experiment instance
ex = Experiment()
ex.observers.append(FileStorageObserver.create('my_runs'))

# This function should be executed so we are decorating it with @ex.automain
@ex.automain
def main():
    print('Hello world!')
    ipdb.set_trace()

... then when I do ipython 01_hello_world.py I get this:

INFO - 01_hello_world - Running command 'main'
INFO - 01_hello_world - Started run with ID "63"
Hello world!
ERROR - 01_hello_world - Failed after 0:00:00!
Traceback (most recent calls WITHOUT Sacred internals):
  File "redacted/01_hello_world.py", line 39, in main
    ipdb.set_trace()
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/ipdb/__main__.py", line 67, in set_trace
    p = _init_pdb(context).set_trace(frame)
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/ipdb/__main__.py", line 48, in _init_pdb
    p = debugger_cls(def_colors, context=context)
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/IPython/terminal/debugger.py", line 17, in __init__
    self.pt_init()
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/IPython/terminal/debugger.py", line 43, in pt_init
    self.pt_cli = CommandLineInterface(self._pt_app, eventloop=self.shell._eventloop)
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/prompt_toolkit/interface.py", line 80, in __init__
    self.output = output or create_output()
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/prompt_toolkit/shortcuts.py", line 124, in create_output
    ansi_colors_only=ansi_colors_only, term=term)
  File "/Users/stephanie/anaconda3/lib/python3.6/site-packages/prompt_toolkit/terminal/vt100_output.py", line 424, in from_pty
    assert stdout.isatty()
AssertionError
---------------------------------------------------------------------------
AssertionError                            Traceback (most recent call last)
/Users/stephanie/anaconda3/lib/python3.6/site-packages/sacred/experiment.py in run_commandline(self, argv)
    259         try:
--> 260             return self.run(cmd_name, config_updates, named_configs, {}, args)
    261         except Exception:

/Users/stephanie/anaconda3/lib/python3.6/site-packages/sacred/experiment.py in run(self, command_name, config_updates, named_configs, meta_info, options)
    208                                meta_info, options)
--> 209         run()
    210         return run

/Users/stephanie/anaconda3/lib/python3.6/site-packages/sacred/run.py in __call__(self, *args)
    220                 self._execute_pre_run_hooks()
--> 221                 self.result = self.main_function(*args)
    222                 self._execute_post_run_hooks()

/Users/stephanie/anaconda3/lib/python3.6/site-packages/sacred/config/captured_function.py in captured_function(wrapped, instance, args, kwargs)
     45     # =================== run actual function =================================
---> 46     result = wrapped(*args, **kwargs)
     47     # =========================================================================

redacted/01_hello_world.py in main()
     38     print('Hello world!')
---> 39     ipdb.set_trace()

/Users/stephanie/anaconda3/lib/python3.6/site-packages/ipdb/__main__.py in set_trace(frame, context)
     66         frame = sys._getframe().f_back
---> 67     p = _init_pdb(context).set_trace(frame)
     68     if p and hasattr(p, 'shell'):

/Users/stephanie/anaconda3/lib/python3.6/site-packages/ipdb/__main__.py in _init_pdb(context, commands)
     47     try:
---> 48         p = debugger_cls(def_colors, context=context)
     49     except TypeError:

/Users/stephanie/anaconda3/lib/python3.6/site-packages/IPython/terminal/debugger.py in __init__(self, *args, **kwargs)
     16         self._ptcomp = None
---> 17         self.pt_init()
     18

/Users/stephanie/anaconda3/lib/python3.6/site-packages/IPython/terminal/debugger.py in pt_init(self)
     42         )
---> 43         self.pt_cli = CommandLineInterface(self._pt_app, eventloop=self.shell._eventloop)
     44

/Users/stephanie/anaconda3/lib/python3.6/site-packages/prompt_toolkit/interface.py in __init__(self, application, eventloop, input, output)
     79         # Inputs and outputs.
---> 80         self.output = output or create_output()
     81         self.input = input or StdinInput(sys.stdin)

/Users/stephanie/anaconda3/lib/python3.6/site-packages/prompt_toolkit/shortcuts.py in create_output(stdout, true_color, ansi_colors_only)
    123             stdout, true_color=true_color,
--> 124             ansi_colors_only=ansi_colors_only, term=term)
    125

/Users/stephanie/anaconda3/lib/python3.6/site-packages/prompt_toolkit/terminal/vt100_output.py in from_pty(cls, stdout, true_color, ansi_colors_only, term)
    423         """
--> 424         assert stdout.isatty()
    425         def get_size():

AssertionError:

During handling of the above exception, another exception occurred:

NameError                                 Traceback (most recent call last)
redacted/01_hello_world.py in <module>()
     34
     35 # This function should be executed so we are decorating it with @ex.automain
---> 36 @ex.automain
     37 def main():
     38     print('Hello world!')

/Users/stephanie/anaconda3/lib/python3.6/site-packages/sacred/experiment.py in automain(self, function)
    135                                    'interactive mode. Use @ex.main instead.')
    136
--> 137             self.run_commandline()
    138         return captured
    139

/Users/stephanie/anaconda3/lib/python3.6/site-packages/sacred/experiment.py in run_commandline(self, argv)
    269             else:
    270                 print_filtered_stacktrace()
--> 271                 exit(1)
    272
    273     def open_resource(self, filename, mode='r'):

NameError: name 'exit' is not defined

Other info: running this on macOS High Sierra 10.13.5, which is probably my problem, but I figured I'd report it anyway.

(also, hi Klaus!)

[Qwlouse]

Hi Stephanie! thanks for reporting! And sorry for the long latency. I haven't found a good way yet to balance my internship, my personal life, and maintaining Sacred. :sweat_smile:

I can reproduce the problem on my Debian, so it is clearly not due to macOS. The problem is the stdout-capturing. For some reason the (default) file-descriptor based capturing causes trouble with debuggers. You can get around the problem by adding the -C sys option to switch to purely-python based capturing. When debugging you should also always add the -d flag to tell sacred to stop messing with exceptions.

I am reopening this issue to keep track of the problem with -C fd and debuggers.