Tag: Logging

We had a problem at work where the regular blocking call to request post was getting in the way at physical locations that didn’t have ideal latency times connecting to the Slack server, like from within China. What takes a second in sunny California was suddenly 8 to 12 seconds from behind the Great Firewall.

The solution is to integrate Slack into Python logging and use the logging QueueHandler to make it asynchronous.

Here’s my implementation of an extension to the QueueHandler and QueueListener classes:

from logging import Handler
import requests
import json
#QueueHandler and QueueListener is part of standard Python logging module
#from Python 3.2 onwards; but if you're using Python 2.x, you can just 
#copy the QueueHandler and QueueListener code and save it into your own 
#queueHandler.py.
try:
    #check if they're part of standard Python logging module
    from logging.handlers import QueueHandler
    from logging.handlers import QueueListener
except ImportError:
    #if not, use your own copy
    from queueHandler import QueueHandler
    from queueHandler import QueueListener


class sqHandler(QueueHandler):
    def __init__(self, queue=None):
        QueueHandler.__init__(self,queue)

    def prepare(self, record):
        """
        Override the method to allow the formatter to work.
        """
        record.msg = self.format(record)
        record.args = None
        record.exc_info = None
        return record

class sqListener(QueueListener,Handler):
    def __init__(self, queue=None, logging_url="", channel="", username="",
                 icon_emoji = ""):
        QueueListener.__init__(self,queue)
        Handler.__init__(self)
        """
        logging_url, channel, username, icon_emoji can all be overridden
        by the extra dictionary parameter of a logging record
        For example: 
            logging.info('Test messate',extra={'channel':'@someone',
                                               'username':'testbot',
                                               'icon_emoji':':penguin:'})
        """
        self.logging_url = logging_url
        self.payload = {
            "channel": channel,
            "username": username,
            "icon_emoji": icon_emoji
            }

    def handle(self, record):
        """
        Override the QueueListener.handle method with the Handler.handle 
        method
        """
        Handler.handle(self, record)

    def emit(self, record):
        #make a copy of the default settings
        new_logging_url = self.logging_url
        new_payload = self.payload.copy()

        #override default settings if necessary
        if hasattr(record,'logging_url'):
            new_logging_url = record.logging_url

        for key in self.payload.keys():
            if hasattr(record,key):
                new_payload[key] = record.__dict__[key]

        #format the message and add to payload
        msg = self.format(record)
        new_payload["text"] = '%s' % msg

        #post the request
        requests.post(new_logging_url, data=json.dumps(new_payload))

And here’s a usage example:

import logging
import Queue as queue
import atexit
import sys
import SlackQueue

    
#Set up the root logger
logging.basicConfig(stream=sys.stdout,
                    level=logging.DEBUG, 
                    format='%(asctime)s - %(levelname)s - %(message)s')
root = logging.getLogger()

#Instantiate a queue for the handler/listener
slack_queue = queue.Queue(-1)

#Instantiate a queue handler using the queue above
SlackHandler = SlackQueue.sqHandler(slack_queue)
SlackHandler.setLevel("DEBUG")

#Set a formatter
simple = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
SlackHandler.setFormatter(simple)

#Add the queue handler to the root logger
root.addHandler(SlackHandler)

#Instantiate the queue listener with the same queue above, and also set
#the settings for communicating with Slack.
#You will need to get your own Incoming Webhook URL from Slack's Custom
#Integration setup.
SlackListener = SlackQueue.sqListener(
        slack_queue,
        logging_url="https://hooks.slack.com/services/<your_webhook_url>",
        channel="#your_channel",
        username="Penguin",
        icon_emoji = ":penguin:"
    )

#Start the listener
SlackListener.start()

#Register the listener stop method to run upon exit in order to allow the 
#queue to be emptied before exiting.
#If you miss this step, the queue might not be emptied before the program
#exits and you won't receive all the messages on Slack.
atexit.register(SlackListener.stop)


#Begin logging
logging.info("Test info message")

#You can temporarily change the Slack settings via the "extra" parameter.
#The settings in extra will only apply to this one log message.
logging.debug("Another test message",extra= {
                                                "channel":"@someone",
                                                "icon_emoji":":coffee:",
                                                "username":"Latte"
                                            })

#You can put the <!channel> tag in the message to send an announcement.
msg="Some sort of warning!"
logging.warning("<!channel>: %s"%msg)

logging.error("Gasp!")

You can use the extra parameter in logging to alter the Slack settings for a particular message. It can be useful if you decide that a particular logging message should ping a certain person directly, or post to a different channel from the default channel.

You can find all the code on GitHub.

If you’re using Python 2.x and need the source of queueHandler.py, check out Vinay Sajip’s blog post, specifically his whole script example.

Leave a comment below if you have any comments or feedback on how to improve the implementation.

References:
Logging for Slackers – Alan Gardner
Improved QueueHandler, QueueListener: dealing with handlers that block – Vinay Sajip