Temporarily capturing Python logging output to a string buffer

You can capture Python logging output temporarily to a string buffer. This is useful if you want to use logging module to record the status of long running operations and later show the resulting log to the end user, who does not have access to file system logs.

Below is an Grok framework view code example for Plone CMS.

View code:

import logging
from StringIO import StringIO

from five import grok

from xxx.objects.interfaces import IXXXResearcher
from Products.CMFCore.interfaces import ISiteRoot
from Products.statusmessages.interfaces import IStatusMessage

from xxx.objects.sync import sync_with_xxx

grok.templatedir("templates")

logger = logging.getLogger("XXX sync")
        

class SyncAll(grok.View):
    """
    Update all researcher data on the site from XXX (admin action)
    """

    grok.context(ISiteRoot)

    def sync(self):
        """ 
        Search all objects of certain type on the site and
        sync them with a remote site.
        """
       
        brains =  self.context.portal_catalog(object_provides=IXXXResearcher.__identifier__)
        for brain in brains:
            object = brain.getObject()
            sync_with_xxx(object, force=True)
            
    def startCapture(self, newLogLevel = None):
        """ Start capturing log output to a string buffer.
        
        http://docs.python.org/release/2.6/library/logging.html
        
        @param newLogLevel: Optionally change the global logging level, e.g. logging.DEBUG
        """
        self.buffer = StringIO()
        
        print >> self.buffer, "Log output"
        
        rootLogger = logging.getLogger()
         
        if newLogLevel:
            self.oldLogLevel = rootLogger.getEffectiveLevel()
            rootLogger.setLevel(newLogLevel)
        else:
            self.oldLogLevel = None
            
        self.logHandler = logging.StreamHandler(self.buffer)
        formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
        self.logHandler.setFormatter(formatter)
        rootLogger.addHandler(self.logHandler)    
            
    def stopCapture(self):
        """ Stop capturing log output.
        
        @return: Collected log output as string        
        """
                                
        # Remove our handler
        rootLogger = logging.getLogger()        

        # Restore logging level (if any)
        if self.oldLogLevel:
            rootLogger.setLevel(self.oldLogLevel)

        
        rootLogger.removeHandler(self.logHandler)
        
        self.logHandler.flush()
        self.buffer.flush()
        
        return self.buffer.getvalue()
        
    def update(self):        
        """ Process the form.
        
        Process the form, log the output and show the output to the user.
        """
        
        self.logs = None

        if "sync-now" in self.request.form:
            # Form button was pressed
            
            # Open Plone status messages interface for this request
            messages = IStatusMessage(self.request)
             
            try:        
                self.startCapture(logging.DEBUG)
                
                logger.info("Starting full site synchronization")
                
                # Do the long running,
                # lots of logging stuff
                self.sync()    

                logger.info("Succesfully done")
                
                # It worked! Trolololo.
                messages.addStatusMessage("Sync done")
                
            except Exception, e:
                # Show friendly error message
                logger.exception(e)                
                messages.addStatusMessage(u"It did not work out:" + unicode(e)) 
   
            finally:
                # Put log output for the page template access
                self.logs = self.stopCapture()

Related Zope page template:

<html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en"
 lang="en"
 metal:use-macro="here/main_template/macros/master"
 i18n:domain="xxx.objects">

 <body>
 <div metal:fill-slot="main">
 <tal:main-macro metal:define-macro="main">

 <h1>
 XXX site update
 </h1>    

 <p>
 Update all researches from XXX
 </p>

 <div tal:condition="view/logs">
   <p>Sync results:</p>
   <pre tal:content="view/logs" />                 
 </div>

 <form action="@@syncall" method="POST">
   <button type="submit" name="sync-now">
     Sync now
   </button>
 </form>         

 </tal:main-macro>
 </div>
 </body>
</html>

$\"\"$ Subscribe to RSS feed Follow me on Twitter Follow me on Facebook Follow me Google+