Missing stack frames?

[Nikolaus Rath]

Nikolaus Rath <Nikolaus at rath.org> writes:
> Chris Angelico <rosuav at gmail.com> writes:
>> On Wed, Jun 4, 2014 at 12:30 PM, Nikolaus Rath <Nikolaus at rath.org> wrote:
>>> I've instrumented one of my unit tests with a conditional
>>> 'pdb.set_trace' in some circumstances (specifically, when a function is
>>> called by a thread other than MainThread).
>>
>> I think the likelihood of this being an issue with interactive
>> debugging and threads is sufficiently high that you should avoid
>> putting the two together, at least until you can verify that the same
>> problem occurs without that combination.
>
> Here's stacktrace as obtained by traceback.print_stack():
>
> tests/t1_backends.py:563: test_extra_data[mock_s3c-zlib] PASSED
> tests/t1_backends.py:563: test_extra_data[mock_s3c-bzip2] PASSED
>
> ======================== 87 tests deselected by '-kextra' =========================
> =============== 5 passed, 1 skipped, 87 deselected in 0.65 seconds ================
>   File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 853, in close
>     self.fh.close()
>   File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/s3c.py", line 691, in close
>     traceback.print_stack(file=sys.stdout)
> something is wrong
>   File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 853, in close
>     self.fh.close()
>   File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/s3c.py", line 691, in close
>     traceback.print_stack(file=sys.stdout)
> something is wrong
>   File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 1050, in close
>     self.fh.close()
>   File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/s3c.py", line 691, in close
>     traceback.print_stack(file=sys.stdout)
>
> Still no context before the ominous close() call. I'm very confused.

It get's even funnier if I just repeat this exercise (without changing
code). Here are some more "tracebacks" that I got:

  File "/usr/bin/py.test-3", line 5, in <module>
    sys.exit(load_entry_point('pytest==2.5.2', 'console_scripts', 'py.test')())
 [...] 
  File "/usr/lib/python3/dist-packages/py/_code/code.py", line 524, in repr_traceback_entry
    source = self._getentrysource(entry)
  File "/usr/lib/python3/dist-packages/py/_code/code.py", line 450, in _getentrysource
    source = entry.getsource(self.astcache)
  File "/usr/lib/python3/dist-packages/py/_code/code.py", line 199, in getsource
    astnode=astnode)
  File "/usr/lib/python3/dist-packages/py/_code/source.py", line 367, in getstatementrange_ast
    astnode = compile(content, "source", "exec", 1024)  # 1024 for AST
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 1050, in close
    self.fh.close_real()
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/s3c.py", line 702, in close_real
    traceback.print_stack(file=sys.stdout)

or also

  File "/usr/bin/py.test-3", line 5, in <module>
    sys.exit(load_entry_point('pytest==2.5.2', 'console_scripts', 'py.test')())
[...]
  File "/usr/lib/python3.4/logging/__init__.py", line 1474, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 842, in handle
    rv = self.filter(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 699, in filter
    for f in self.filters:
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 853, in close
    self.fh.close()
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 1050, in close
    self.fh.close_real()
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/s3c.py", line 702, in close_real
    traceback.print_stack(file=sys.stdout)

and this one looks actually the way I would expect:

[...]
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 335, in fetch
    return self.perform_read(do_read, key)
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 58, in wrapped
    return method(*a, **kw)
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 309, in perform_read
    return fn(fh)
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 859, in __exit__
    self.close()
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 853, in close
    self.fh.close()
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/common.py", line 1050, in close
    self.fh.close_real()
  File "/home/nikratio/in-progress/s3ql/src/s3ql/backends/s3c.py", line 702, in close_real
    traceback.print_stack(file=sys.stdout)


I am not using any C extension modules, but I guess I nevertheless have
to assume that something seriously messed up either the stack or the
traceback printing routines?


Best,
Nikolaus

-- 
GPG encrypted emails preferred. Key id: 0xD113FCAC3C4E599F
Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«