Logging from Python in Splunk

[timpgray]

What are the conventions for logging from a custom search command in Python? I didn’t see my log outputs showing up anywhere obvious, so I configured it(using a configuration file) to log to its own file, which I got working, but what I saw along the way raised an interesting question.

As far as I can tell, when you configure logging thru a config file, you must specify the root logger along with your own loggers. I did this with the root’s handler ultimately logging to sys.stdout. When I did this, I did indeed get logging from my command into the expected file. But while the logging out looked correct and as if the command was working properly, the actual out put of the resultant search command(if I ran the command from the search bar) seemed to contain items from my logging output interspersed with some of the expected results.

I am thinking that one thing that could explain this would be that Splunk may use sys.stdout to output search results, but I think this is unlikely.

I was able to work around this by specifying a NullHandler for the root logger and this resolved my issue.

Does anybody care to chime in on the ‘correct’ configuration for logging from a search command and/or explain what was happening when my log output showed up in the search results?

[LukeMurphey]

I usually configure my own logger instance and log directly to that. Then I assigned a sourcetype to the log file so that I can find the log entries easily. My Python code looks something like this:

import logging
import logging.handlers

def setup_logger(level):
    logger = logging.getLogger('my_search_command')
    logger.propagate = False # Prevent the log messages from being duplicated in the python.log file
    logger.setLevel(level)

    file_handler = logging.handlers.RotatingFileHandler(os.environ['SPLUNK_HOME'] + '/var/log/splunk/my_search_command.log', maxBytes=25000000, backupCount=5)
    formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
    file_handler.setFormatter(formatter)

    logger.addHandler(file_handler)

    return logger

# Setup the handler
logger = setup_logger(logging.INFO)

logger.info("Some log message...")

You can also just call logging directly and your logs will appear in python.log:

logging.warning("Something bad happened: %s", "out of memory")

I recommend formatting your log messages with name/value pairs. That way Splunk will parse them automatically. For example:

logging.info("User successfully logged in, user='%s'", user_name)