Protect from scenarios where all frames should be ignored

[djeebus]

I ran into this scenario running the tests for my app. It opens some connections to a cassandra cluster, runs some tests, and (sometimes) doesn't close the connection. Each cluster registers an atexit function which closes the connection.

When py.test runs these tests, just before quitting it prints the following traceback:

Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "cassandra/cluster.py", line 2184, in cassandra.cluster.ControlConnection.shutdown (cassandra/cluster.c:39664)
  File "/usr/lib/python3.4/logging/__init__.py", line 1267, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/lib/python3.4/logging/__init__.py", line 1404, in _log
    fn, lno, func, sinfo = self.findCaller(stack_info)
  File "/home/djeebus/code/other/structlog/src/structlog/stdlib.py", line 32, in findCaller
    f, name = _find_first_app_frame_and_name(['logging'])
  File "/home/djeebus/code/other/structlog/src/structlog/_frames.py", line 44, in _find_first_app_frame_and_name
    name = f.f_globals.get("__name__") or "?"
AttributeError: 'NoneType' object has no attribute 'f_globals'

Unfortunately I haven't been able to reproduce this in a simple test. I think it involves the fact that some of the code is written in C, but haven't been able to verify that. I have, however, fixed the bug in a pretty simple way. Hopefully this hopes someone else as well!

[hynek]

Your approach doesn’t work and your tests prove it. :)

You’ll have to set name to ? in if branch otherwise it’s still set to the name of the previous frame.

[djeebus]

@hynek wow, that's embarassing. Not sure how I managed to write a test that fails and then not fix it.

... anyway, should be happy now. Thanks for looking!

[codecov-io]

Current coverage is 100.00%

Merging #62 into master will not affect coverage as of f8f23bb

@@            master     #62   diff @@
======================================
  Files           13      13       
  Stmts          645     648     +3
  Branches        75      76     +1
  Methods          0       0       
======================================
+ Hit            645     648     +3
  Partial          0       0       
  Missed           0       0       

Review entire Coverage Diff as of f8f23bb

Powered by Codecov. Updated on successful CI builds.

[sontek]

@hynek ahem :) Currently:

Traceback (most recent call last):
  File "cassandra/cluster.py", line 2184, in cassandra.cluster.ControlConnection.shutdown (cassandra/cluster.c:39664)
  File "/usr/lib/python3.4/logging/__init__.py", line 1267, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/lib/python3.4/logging/__init__.py", line 1404, in _log
    fn, lno, func, sinfo = self.findCaller(stack_info)
  File "/home/sontek/venvs/statsvc/lib/python3.4/site-packages/structlog/stdlib.py", line 32, in findCaller
    f, name = _find_first_app_frame_and_name(['logging'])
  File "/home/sontek/venvs/statsvc/lib/python3.4/site-packages/structlog/_frames.py", line 43, in _find_first_app_frame_and_name
    name = f.f_globals.get("__name__") or "?"

any chance you'll take a look at this awesome PR that solves bad logs for me? :)

[hynek]

Ugh no idea why this got lost. :( But since you’re here: could you test if it actually helps? :)

[sontek]

With latest pypi and master:

===================================================================================================================== 132 passed, 1 skipped in 40.76 seconds ======================================================================================================================
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "cassandra/cluster.py", line 2184, in cassandra.cluster.ControlConnection.shutdown (cassandra/cluster.c:39664)
  File "/usr/lib/python3.4/logging/__init__.py", line 1267, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/lib/python3.4/logging/__init__.py", line 1404, in _log
    fn, lno, func, sinfo = self.findCaller(stack_info)
  File "/home/sontek/venvs/statsvc/lib/python3.4/site-packages/structlog/stdlib.py", line 32, in findCaller
    f, name = _find_first_app_frame_and_name(['logging'])
  File "/home/sontek/venvs/statsvc/lib/python3.4/site-packages/structlog/_frames.py", line 43, in _find_first_app_frame_and_name
    name = f.f_globals.get("__name__") or "?"

with this branch, no errors! :)

===================================================================================================================== 132 passed, 1 skipped in 44.40 seconds ======================================================================================================================
$

[hynek]

Thanks and sorry for the delay!