Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error in error reporting. #8293

Closed
musically-ut opened this issue Apr 9, 2015 · 10 comments
Closed

Error in error reporting. #8293

musically-ut opened this issue Apr 9, 2015 · 10 comments
Milestone

Comments

@musically-ut
Copy link
Contributor

The program to reproduce the error is the following:

# file: ~/tmp/ipython-except.py
def foo(u):
    raise ValueError

# This shows the correct traceback:
# sum(sum(foo(u) for u in [0]) for _ in [0])
sum(sum(foo(u) for _ in [0]) for u in [0])

The following error is produced:

16:28:05 [5]: %run -i ~/tmp/ipython_except.py
---------------------------------------------------------------------------
IndexError                                Traceback (most recent call last)
<ipython-input-5-21c031f5aefb> in <module>()
----> 1 get_ipython().magic(u'run -i ~/tmp/ipython_except.py')

/Users/musically_ut/prog/rare/ipython/IPython/core/interactiveshell.py in magic(self, arg_s)
   2306         magic_name, _, magic_arg_s = arg_s.partition(' ')
   2307         magic_name = magic_name.lstrip(prefilter.ESC_MAGIC)
-> 2308         return self.run_line_magic(magic_name, magic_arg_s)
   2309
   2310     #-------------------------------------------------------------------------

/Users/musically_ut/prog/rare/ipython/IPython/core/interactiveshell.py in run_line_magic(self, magic_name, line)
   2227                 kwargs['local_ns'] = sys._getframe(stack_depth).f_locals
   2228             with self.builtin_trap:
-> 2229                 result = fn(*args,**kwargs)
   2230             return result
   2231

/Users/musically_ut/prog/rare/ipython/IPython/core/magics/execution.py in run(self, parameter_s, runner, file_finder)

/Users/musically_ut/prog/rare/ipython/IPython/core/magic.py in <lambda>(f, *a, **k)
    191     # but it's overkill for just that one bit of state.
    192     def magic_deco(arg):
--> 193         call = lambda f, *a, **k: f(*a, **k)
    194
    195         if callable(arg):

/Users/musically_ut/prog/rare/ipython/IPython/core/magics/execution.py in run(self, parameter_s, runner, file_finder)
    736                         else:
    737                             # regular execution
--> 738                             run()
    739
    740                 if 'i' in opts:

/Users/musically_ut/prog/rare/ipython/IPython/core/magics/execution.py in run()
    722                             def run():
    723                                 runner(filename, prog_ns, prog_ns,
--> 724                                        exit_ignore=exit_ignore)
    725
    726                         if 't' in opts:

/Users/musically_ut/prog/rare/ipython/IPython/core/interactiveshell.py in safe_execfile(self, fname, *where, **kw)
   2655                     raise
   2656                 # tb offset is 2 because we wrap execfile
-> 2657                 self.showtraceback(tb_offset=2)
   2658
   2659     def safe_execfile_ipy(self, fname, shell_futures=False):

/Users/musically_ut/prog/rare/ipython/IPython/core/interactiveshell.py in showtraceback(self, exc_tuple, filename, tb_offset, exception_only)
   1850                     except Exception:
   1851                         stb = self.InteractiveTB.structured_traceback(etype,
-> 1852                                             value, tb, tb_offset=tb_offset)
   1853
   1854                     self._showtraceback(etype, value, stb)

/Users/musically_ut/prog/rare/ipython/IPython/core/ultratb.pyc in structured_traceback(self, etype, value, tb, tb_offset, number_of_lines_of_context)
   1238         self.tb = tb
   1239         return FormattedTB.structured_traceback(
-> 1240             self, etype, value, tb, tb_offset, number_of_lines_of_context)
   1241
   1242

/Users/musically_ut/prog/rare/ipython/IPython/core/ultratb.pyc in structured_traceback(self, etype, value, tb, tb_offset, number_of_lines_of_context)
   1146             # Verbose modes need a full traceback
   1147             return VerboseTB.structured_traceback(
-> 1148                 self, etype, value, tb, tb_offset, number_of_lines_of_context
   1149             )
   1150         else:

/Users/musically_ut/prog/rare/ipython/IPython/core/ultratb.pyc in structured_traceback(self, etype, evalue, etb, tb_offset, number_of_lines_of_context)
    998
    999         formatted_exception = self.format_exception_as_a_whole(etype, evalue, etb, number_of_lines_of_context,
-> 1000                                                                tb_offset)
   1001
   1002         colors = self.Colors  # just a shorthand + quicker name lookup

/Users/musically_ut/prog/rare/ipython/IPython/core/ultratb.pyc in format_exception_as_a_whole(self, etype, evalue, etb, number_of_lines_of_context, tb_offset)
    949         records = self.get_records(etb, number_of_lines_of_context, tb_offset)
    950
--> 951         frames = self.format_records(records)
    952         if records is None:
    953             return ""

/Users/musically_ut/prog/rare/ipython/IPython/core/ultratb.pyc in format_records(self, records)
    745             file = py3compat.cast_unicode(file, util_path.fs_encoding)
    746             link = tpl_link % file
--> 747             args, varargs, varkw, locals = inspect.getargvalues(frame)
    748
    749             if func == '?':

/usr/local/Cellar/python/2.7.9/Frameworks/Python.framework/Versions/2.7/lib/python2.7/inspect.pyc in getargvalues(frame)
    827     'varargs' and 'varkw' are the names of the * and ** arguments or None.
    828     'locals' is the locals dictionary of the given frame."""
--> 829     args, varargs, varkw = getargs(frame.f_code)
    830     return ArgInfo(args, varargs, varkw, frame.f_locals)
    831

/usr/local/Cellar/python/2.7.9/Frameworks/Python.framework/Versions/2.7/lib/python2.7/inspect.pyc in getargs(co)
    789                                 remain[-1] = remain[-1] - 1
    790                             if not remain: break
--> 791             args[i] = stack[0]
    792
    793     varargs = None

IndexError: list index out of range

Expected output is something along the lines of the following:

16:31:07 [11]: %run -i ~/tmp/ipython_except.py
---------------------------------------------------------------------------
ValueError                                Traceback (most recent call last)
/Users/musically_ut/tmp/ipython_except.py in <module>()
      3
      4 # This shows the correct traceback:
----> 5 sum(sum(foo(u) for u in [0]) for _ in [0])
      6 # sum(sum(foo(u) for _ in [0]) for u in [0])

/Users/musically_ut/tmp/ipython_except.py in <genexpr>((_,))
      3
      4 # This shows the correct traceback:
----> 5 sum(sum(foo(u) for u in [0]) for _ in [0])
      6 # sum(sum(foo(u) for _ in [0]) for u in [0])

/Users/musically_ut/tmp/ipython_except.py in <genexpr>((u,))
      3
      4 # This shows the correct traceback:
----> 5 sum(sum(foo(u) for u in [0]) for _ in [0])
      6 # sum(sum(foo(u) for _ in [0]) for u in [0])

/Users/musically_ut/tmp/ipython_except.py in foo(u)
      1 def foo(u):
----> 2     raise ValueError
      3
      4 # This shows the correct traceback:
      5 sum(sum(foo(u) for u in [0]) for _ in [0])

ValueError:

Tested against IPython 4.0.0-dev (current master) and Python 2.7.9:

$ python -m IPython
Python 2.7.9 (default, Jan  7 2015, 11:49:12)
Type "copyright", "credits" or "license" for more information.

IPython 4.0.0-dev -- An enhanced Interactive Python.
@musically-ut
Copy link
Contributor Author

Update, this problem doesn't occur with Python-3, i.e. the correct traceback is shown for both the statements:

sum(sum(foo(u) for u in [0]) for _ in [0])
sum(sum(foo(u) for _ in [0]) for u in [0])

@Carreau
Copy link
Member

Carreau commented Apr 20, 2015

Might be a Python 2.7 bug. the frame does:

LOAD_FAST
FOR_ITER
STORE_DEREF
LOAD_GLOBAL
LOAD_CLOSURE
BUILD_TUPLE
LOAD_CONST
MAKE_CLOSURE
LOAD_CONST
BUILD_LIST
GET_ITER
CALL_FUNCTION
CALL_FUNCTION
YIELD_VALUE
POP_TOP
JUMP_ABSOLUTE
LOAD_CONST
RETURN_VALUE

For which obviously getargs will fail. ...

@musically-ut
Copy link
Contributor Author

Then should it be escalated to the Python2.7 bug tracker?
I think it would be best if you (@Carreau) write the report. :)

@Carreau
Copy link
Member

Carreau commented Apr 20, 2015

Yeah, trying to make a smaller example.
I don't use getframe a lot so have to re-read the doc, but will probably do.

@musically-ut
Copy link
Contributor Author

Thanks!
Also, please post the link to the Python bug here when you file it. 👍

@Carreau
Copy link
Member

Carreau commented Apr 20, 2015

Sure, that might not be today though.

@keryil
Copy link

keryil commented May 11, 2015

Any updates on this?

@Carreau
Copy link
Member

Carreau commented May 11, 2015

No not particularly.
I trying to up my installation to work on both 3.5 and 2.7 head of Python, but it's a rabbit hole.

@ssanderson
Copy link
Member

ssanderson commented Oct 7, 2015

@Carreau the bug in getargs is caused by the fact the nested generator expression's bytecode has an anonymous inner argument named .0:

In [5]: (0/0 for i in [1] if all(i for j in [])).gi_code.co_varnames
Out[5]: ('.0',)

In inspect.getargs, there's a big long section that's trying very hard to resolve names of functions with anonymous tuple arguments:

    # The following acrobatics are for anonymous (tuple) arguments.
    for i in range(nargs):
        if args[i][:1] in ('', '.'):
            ... # Do a bunch of stuff to handle anonymous tuple args.

This code is trying to handle functions that look like this:

In [11]: def foo((x, y), z):
   ....:     return x, y, z
   ....:

In [12]: foo((1, 2), 3)
Out[12]: (1, 2, 3)

Tuple argument unpacking was removed in Python 3, which is why this issue only manifests in Python 2.

The bytecode for a function like foo generates extra instructions to unpack the first argument:

In [13]: dis.dis(foo)
  1           0 LOAD_FAST                0 (.0)
              3 UNPACK_SEQUENCE          2
              6 STORE_FAST               2 (x)
              9 STORE_FAST               3 (y)

  2          12 LOAD_FAST                2 (x)
             15 LOAD_FAST                3 (y)
             18 LOAD_FAST                1 (z)
             21 BUILD_TUPLE              3
             24 RETURN_VALUE

The problem with all of this is that the bytecode for generator expressions uses the same machinery as tuple unpacking under the hood:

In [3]: dis.dis((x for x in [0]).gi_code)
  1           0 LOAD_FAST                0 (.0)
        >>    3 FOR_ITER                11 (to 17)
              6 STORE_FAST               1 (x)
              9 LOAD_FAST                1 (x)
             12 YIELD_VALUE
             13 POP_TOP
             14 JUMP_ABSOLUTE            3
        >>   17 LOAD_CONST               0 (None)
             20 RETURN_VALUE

getargs does the right thing for simple genexprs, but fails when the yielded values are themselves generator expressions that close over an outer name. The simplest example of such a failure is something like this:

In [8]: getargs(((x for _ in [0]) for x in [0]).gi_code)
---------------------------------------------------------------------------
IndexError                                Traceback (most recent call last)
<ipython-input-8-eaf5530bb07a> in <module>()
----> 1 getargs(((x for _ in [0]) for x in [0]).gi_code)

/usr/lib/python2.7/inspect.pyc in getargs(co)
    789                                 remain[-1] = remain[-1] - 1
    790                             if not remain: break
--> 791             args[i] = stack[0]
    792
    793     varargs = None

IndexError: list index out of range

The disassembly of the bad expression is:

In [12]: dis.dis(((x for _ in [0]) for x in [0]).gi_code)
  1           0 LOAD_FAST                0 (.0)
        >>    3 FOR_ITER                30 (to 36)
              6 STORE_DEREF              0 (x)
              9 LOAD_CLOSURE             0 (x)
             12 BUILD_TUPLE              1
             15 LOAD_CONST               0 (<code object <genexpr> at 0x7f9ac7071eb0, file "<ipython-input-12-272633ab0f4c>", line 1>)
             18 MAKE_CLOSURE             0
             21 LOAD_CONST               1 (0)
             24 BUILD_LIST               1
             27 GET_ITER
             28 CALL_FUNCTION            1
             31 YIELD_VALUE
             32 POP_TOP
             33 JUMP_ABSOLUTE            3
        >>   36 LOAD_CONST               2 (None)
             39 RETURN_VALUE

The issue here, ultimately, is the fact that the outer loop variable is passed to the inner function via a STORE_DEREF rather than as a STORE_FAST. There's been an open issue on bugs.python.org about this since 2012, which a patch supplied that fixes the issue (I just tried it locally). I'm not sure why it hasn't been merged.

ssanderson added a commit to quantopian/ipython that referenced this issue Oct 8, 2015
ssanderson added a commit to quantopian/ipython that referenced this issue Oct 8, 2015
@minrk minrk added this to the 4.1 milestone Oct 9, 2015
@taschini
Copy link

I'm not sure why it hasn't been merged.

I don't know either. At least I'm happy that my patch could help you guys.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants