launchpad-reviewers team mailing list archive

[John A Meinel <john@xxxxxxxxxxxxxxxxx>]

John A Meinel has proposed merging lp:~jameinel/launchpad/suppress-generator-exit-726985 into lp:launchpad.

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)
Related bugs:
  #726985 codebrowse OOPSes with GeneratorExit when connection closed early
  https://bugs.launchpad.net/bugs/726985

For more details, see:
https://code.launchpad.net/~jameinel/launchpad/suppress-generator-exit-726985/+merge/52414

Adding another kind of exception for Loggerhead to treat as a non-OOPS.

There are only a few pages that do streamed bodies, but when one of those is stopped early, we get a GeneratorExit exception (when the generator loses its last reference.)

The test for this requires CPython's refcounting semantics (throw a GeneratorExit exception as soon as we call 'del app'). I'm pretty sure this is safe for Launchpad, but I figured I would mention it.

GeneratorExit itself never really cares any other context, so I don't think we could say that there is any reason to decide we really do want an oops here, rather than just always suppressing it. If we get 1 more of these, we should probably unify their logging, etc a bit. But for right now, 2 didn't seem to imply a trend.

Note that I was unable to actually reproduce the failure with custom "GET ../download/" and stopping early. So if we want, we can put this off until we actually see this being the #1 OOPS failure. Though according to wgrant, it was.

-- 
https://code.launchpad.net/~jameinel/launchpad/suppress-generator-exit-726985/+merge/52414
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~jameinel/launchpad/suppress-generator-exit-726985 into lp:launchpad.

=== modified file 'lib/launchpad_loggerhead/app.py'
--- lib/launchpad_loggerhead/app.py	2011-02-09 00:43:53 +0000
+++ lib/launchpad_loggerhead/app.py	2011-03-07 13:48:19 +0000
@@ -356,8 +356,16 @@
             # just because the connection was closed prematurely.
             logger = logging.getLogger('lp-loggerhead')
             logger.info('Caught socket exception from %s: %s %s'
-                         % (environ.get('REMOTE_ADDR', '<unknown>'),
-                            e.__class__, e,))
+                        % (environ.get('REMOTE_ADDR', '<unknown>'),
+                           e.__class__, e,))
+            return
+        except GeneratorExit, e:
+            # This generally means a client closed early during a streaming
+            # body. Nothing to worry about. GeneratorExit doesn't usually have
+            # any context associated with it, so not worth printing to the log.
+            logger = logging.getLogger('lp-loggerhead')
+            logger.info('Caught GeneratorExit from %s'
+                        % (environ.get('REMOTE_ADDR', '<unknown>')))
             return
         except:
             error_page_sent = wrapped.generate_oops(environ, error_utility)

=== modified file 'lib/launchpad_loggerhead/tests.py'
--- lib/launchpad_loggerhead/tests.py	2011-02-23 17:26:26 +0000
+++ lib/launchpad_loggerhead/tests.py	2011-03-07 13:48:19 +0000
@@ -203,17 +203,26 @@
             raise socket.error(errno.EPIPE, 'Connection closed')
         return fail_write
 
+    def multi_yielding_app(self, environ, start_response):
+        writer = start_response('200 OK', {})
+        yield 'content\n'
+        yield 'I want\n'
+        yield 'to give to the user\n'
+
+    def _get_default_environ(self):
+        return {'wsgi.version': (1, 0),
+                'wsgi.url_scheme': 'http',
+                'PATH_INFO': '/test/path',
+                'REQUEST_METHOD': 'GET',
+                'SERVER_NAME': 'localhost',
+                'SERVER_PORT': '8080',
+               }
+
     def wrap_and_run(self, app, failing_write=False):
         app = oops_middleware(app)
         # Just random env data, rather than setting up a whole wsgi stack just
         # to pass in values for this dict
-        environ = {'wsgi.version': (1, 0),
-                   'wsgi.url_scheme': 'http',
-                   'PATH_INFO': '/test/path',
-                   'REQUEST_METHOD': 'GET',
-                   'SERVER_NAME': 'localhost',
-                   'SERVER_PORT': '8080',
-                  }
+        environ = self._get_default_environ()
         if failing_write:
             result = list(app(environ, self.failing_start_response))
         else:
@@ -242,6 +251,23 @@
         self.assertContainsRe(self.log_stream.getvalue(),
             'Caught socket exception from <unknown>:.*Connection closed')
 
+    def test_stopping_early_no_oops(self):
+        # See bug #726985.
+        # If content is being streamed, and the pipe closes, we'll get a
+        # 'GeneratorExit', because it is closed before finishing. This doesn't
+        # need to become an OOPS.
+        self.catchLogEvents()
+        app = oops_middleware(self.multi_yielding_app)
+        environ = self._get_default_environ()
+        result = app(environ, self.noop_start_response)
+        self.assertEqual('content\n', result.next())
+        # At this point, we intentionally kill the app and the response, so
+        # that they will get GeneratorExit
+        del app, result
+        self.assertEqual([], self.oopses)
+        self.assertContainsRe(self.log_stream.getvalue(),
+            'Caught GeneratorExit from <unknown>')
+
 
 def test_suite():
     return unittest.TestLoader().loadTestsFromName(__name__)