JSON log formatting

[neilpanchal]

Hello,

It would be great to allow users to format logs in json format instead of the hardcoded logfmt format in the library. For those looking to make this work, this is how we did it:

# strip_log_formatter.py
import datetime
import json

from pythonjsonlogger import jsonlogger

class StripeJsonLogFormatter(jsonlogger.JsonFormatter):  # pragma: no cover
    def add_fields(self, log_record, record, message_dict):
        """
        This method allows us to inject custom data into resulting log messages
        """
        for field in self._required_fields:
            log_record[field] = record.__dict__.get(field)
        log_record.update(message_dict)

        # Add timestamp and application name if not present
        if 'timestamp' not in log_record:
            now = datetime.datetime.utcnow()
            log_record['timestamp'] = now.isoformat()
        if 'application' not in log_record:
            log_record['application'] = 'myapp'

        if 'level' not in log_record:
            log_record['level'] = record.levelname

        jsonlogger.merge_record_extra(record, log_record, reserved=self._skip_fields)

Reference this class from stripe_log_formatter.py in log ini configuration file as follows:

[loggers]
keys=stripe

[handlers]
keys=stripe_file

[formatters]
keys=stripe_json

[logger_stripe]
level=INFO
handlers=stripe_file
qualname=stripe
propagate=0

[handler_stripe_file]
class=logging.handlers.WatchedFileHandler
formatter=stripe_json
args=('/var/log/myapp/stripe.json',)

[formatter_stripe_json]
class=app.stripe_log_formatter.StripeJsonLogFormatter

And then at import time, monkey patch stripe library:

# Monkey patch Stripe logfmt formatter
# Watch for this code if it ever changes, things will break:
# https://github.com/stripe/stripe-python/blob/v2.67.0/stripe/util.py#L82

old_log_fmt = stripe.util.logfmt

def new_logfmt(props):
    return OrderedDict(sorted(props.items(), key=lambda x: x[0]))

stripe.util.logfmt = new_logfmt

Any chance we can get an ability to configure our own log formatter?

[richardm-stripe]

Hello @neilpanchal. What do you think of an approach like https://github.com/stripe/stripe-python/pull/913 ?

If we made that change, then you would have access to the underlying params used to construct the log message when defining your own formatter, so there should be no need to monkey-patch/modify "logfmt" in util.

For example:

class MyFormatter(logging.Formatter):
    def format(self, record):
        # record.args won't be populated today, but would be if #913 were merged
        return json.dumps(record.args)

logging.basicConfig()
formatter = MyFormatter('')
handler = logging.StreamHandler()
handler.setFormatter(formatter)

logger = logging.getLogger('stripe')
logger.setLevel(logging.DEBUG)
logger.addHandler(handler)

[richardm-stripe]

Anybody else feel free to chime in, too! We're happy to merge https://github.com/stripe/stripe-python/pull/913 and we think this solves the use case here, but we want to validate it against a user just to be sure!

@liveFreeOrCode (great handle, btw) I noticed you gave the issue a thumb. Would you be willing to take a glance at https://github.com/stripe/stripe-python/pull/913 to see if it would solve your problem?

[neilpanchal]

@richardm-stripe This would work well, thanks for taking the time to address. We've since removed logging stripe records, so I am not able to test things but from what I can see, LGMT and seems reasonable.

[richardm-stripe]

Released in v5.1.0