dropped extra parameter from sent json

[jtmoon79]

tl;dr the extra parameter in logger.info(mesg, extra) is dropped from the sent json request. Why?

problem

Given the following code

#!/usr/bin/env python3.4

import os
import logging
import logstash

# logging init
logger = logging.getLogger(os.path.basename(__file__))
logger.setLevel(logging.INFO)
# logging logstash
logger.addHandler(logstash.TCPLogstashHandler('localhost', 5000, version=1))

mesg = 'hello'
extra = {'test1': 1}
logger.info(mesg, extra)

Capturing the data sent over the wire using tcpdump or wireshark proves 'test1': 1 is not present.

{
  "level": "INFO",
  "stack_info": null,
  "message": "hello",
  "type": "logstash",
  "path": "/tmp/logstash-examples/exampleIssue.py",
  "tags": [],
  "host": "myhost",
  "logger_name": "exampleIssue.py",
  "@timestamp": "2017-02-18T03:26:13.432Z",
  "@version": "1"
}

Stepping through the code shows the extra parameter is skipped for attaching to the record (a dict) within LogstashFormatterBase.get_extra_fields. extra becomes referenced by object attribute args within (.../Lib/logging/__init__.py)

def __init__(self, name, level, pathname, lineno,
             msg, args, exc_info, func=None, sinfo=None, **kwargs):

    # ...

    self.args = args

And then args skipped for adding within LogstashFormatterBase.get_extra_fields because 'args' is in skip_list

class LogstashFormatterBase(logging.Formatter):

    # ...

    def get_extra_fields(self, record):
        # The list contains all the attributes listed in
        # http://docs.python.org/library/logging.html#logrecord-attributes
        skip_list = (
            'args', 'asctime', 'created', 'exc_info', 'exc_text', 'filename',
            'funcName', 'id', 'levelname', 'levelno', 'lineno', 'module',
            'msecs', 'msecs', 'message', 'msg', 'name', 'pathname', 'process',
            'processName', 'relativeCreated', 'thread', 'threadName', 'extra',
            'auth_token', 'password')

        # ...

        fields = {}

        for key, value in record.__dict__.items():
            if key not in skip_list:
                if isinstance(value, easy_types):
                    fields[key] = value
                else:
                    fields[key] = repr(value)

From the call stack

get_extra_fields (.../Lib/site-packages/python_logstash-0.4.6-py3.4.egg!/logstash/formatter.py)
format (.../Lib/site-packages/python_logstash-0.4.6-py3.4.egg!/logstash/formatter.py)
makePickle (.../Lib/site-packages/python_logstash-0.4.6-py3.4.egg!/logstash/handler_tcp.py)
emit (.../Lib/logging/handlers.py)
handle (.../Lib/logging/__init__.py)
callHandlers (.../Lib/logging/__init__.py)
handle  (.../Lib/logging/__init__.py)
_log  (.../Lib/logging/__init__.py)
info  (.../Lib/logging/__init__.py)

solution

As a module user, the current behavior is unexpected, confusing, and prevents me from passing along required extra information. I reviewed logging.html#logrecord-attributes. It was not clear why args attribute (extra parameter) should be effectively dropped. I suggest changing the current behavior to not drop extra parameter information. If the current behavior must be kept and this problem is to be worked around then moving skip_list to be class instance variable would allow the user to remove 'args' from skip_list as needed.

Using python-logstash 0.4.7 (a8be251ad9fc102af668c38a5397515b0804da75) on cython 3.4.1.

[jtmoon79]

This may relate to feature request #37.

[matthieudesprez]

try logger.info(mesg, extra=extra)

extra is a keyword argument