Eats CPU and memory due to slighly misconfigured OOPSObserver

Bug #869463 reported by Gavin Panella
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Launchpad itself
Fix Released
Critical
Gavin Panella
python-oops-twisted
Fix Released
High
Gavin Panella
txlongpoll
Fix Released
Critical
Gavin Panella

Bug Description

In txlongpoll, an observer is created by getRotatableLogFileObserver()
and passed as the fallback parameter to OOPSObserver. The docstring
for OOPSObserver.__init__ says this is the right thing to do:

        :param fallback: If supplied, a LogObserver to pass
            non-failure log events to, and to inform (as non-failures)
            when an OOPS has occurred.

However, it actually expects a callable, but this does not cause an
error until later.

I'm not quite sure why it doesn't happen every time, but what can
happen is that the txlongpoll process spins tightly and comsumes more
and more memory. I've attached an example log that is recorded.

The following diff, I think, will resolve this issue in txlongpoll:

{{{
=== modified file 'twisted/plugins/txlongpoll.py'
--- twisted/plugins/txlongpoll.py 2011-09-30 10:46:17 +0000
+++ twisted/plugins/txlongpoll.py 2011-10-06 19:48:36 +0000
@@ -67,7 +67,7 @@
         repo = DateDirRepo(options["oops-dir"], options["oops-prefix"])
         config.publishers.append(defer_publisher(repo.publish))

- observer = OOPSObserver(config, logfile)
+ observer = OOPSObserver(config, logfile.emit)
     addObserver(observer.emit)
}}}

To avoid this kind of issue in the future, I propose doing something
like the following in python-oops-twisted:

{{{
=== modified file 'oops_twisted/log.py'
--- oops_twisted/log.py 2011-09-28 09:00:46 +0000
+++ oops_twisted/log.py 2011-10-06 19:57:22 +0000
@@ -41,6 +41,7 @@
             occurred.
         """
         self.config = config
+ assert fallback is None or callable(fallback)
         self.fallback = fallback

     def emit(self, eventDict):
}}}

Related branches

Revision history for this message
Gavin Panella (allenap) wrote :
Changed in python-oops-twisted:
status: New → Triaged
importance: Undecided → High
Changed in txlongpoll:
status: Triaged → In Progress
Gavin Panella (allenap)
Changed in launchpad:
status: New → In Progress
importance: Undecided → Critical
assignee: nobody → Gavin Panella (allenap)
Changed in python-oops-twisted:
assignee: nobody → Gavin Panella (allenap)
status: Triaged → In Progress
Revision history for this message
Robert Collins (lifeless) wrote : Re: [Bug 869463] Re: Eats CPU and memory due to slighly misconfigured OOPSObserver

Nice catch. I thought callable was deprecated?

Revision history for this message
John A Meinel (jameinel) wrote :

@lifeless it was deprecated for a release or two of Python in favor of "isinstance(foo, Callable)" with their Abstract Base Class syntax. And then the python devs realized that the isinstance syntax was stupid, and un-deprecated callable.

This came up on another list just recently (I think bzr).

Revision history for this message
Martin Pool (mbp) wrote :

> Instead of callable(f) you can [enjoy] hasattr(f, '__call__').

http://bugs.python.org/issue10518

Gavin Panella (allenap)
Changed in launchpad:
status: In Progress → Fix Committed
Changed in python-oops-twisted:
status: In Progress → Fix Committed
Changed in txlongpoll:
status: In Progress → Fix Released
William Grant (wgrant)
Changed in launchpad:
status: Fix Committed → Fix Released
Changed in python-oops-twisted:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.