How to unsort key:value pairs with structlog in plain console mode?

Question

I use structlog with Django and noticed that key:value pairs output is alphabetical in console mode, which means that when I bind a new key beginning with _ like log.bind('_id'=id) then it is added at the very first.

I'm asking this question because after a new key:value pair is inserted in the middle or at the beginning of the line the benefit of a nicely structured and colored log is lost when reading the console.

The documentation mentions a processor boolean parameter sort_keys but it's not supported by the key_value formatter. How can I unsort key:value pairs based in plain console?

This is my config:

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "json_formatter": {
            "()": structlog.stdlib.ProcessorFormatter,
            "processor": structlog.processors.JSONRenderer(sort_keys=False),
        },
        "plain_console": {
            "()": structlog.stdlib.ProcessorFormatter,
            "processor": structlog.dev.ConsoleRenderer(pad_event=43,
                                                       colors=True,
                                                       force_colors=True
                                                       ),
        },
        "key_value": {
            "()": structlog.stdlib.ProcessorFormatter,
            "processor": structlog.processors.KeyValueRenderer(
                key_order=['timestamp', 'level', 'logger', 'event'],
                sort_keys=False
            ),
        },
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "plain_console",
        },
        "json_file": {
            "class": "logging.handlers.WatchedFileHandler",
            "filename": "json.log",
            "formatter": "json_formatter",
        },
        "flat_line_file": {
            "class": "logging.handlers.WatchedFileHandler",
            "filename": "flat_line.log",
            "formatter": "key_value",
        },
    },
    "loggers": {
        '': {
            "handlers": ["console", "flat_line_file", "json_file"],
            "level": "WARNING",
            'propagate': False,
        },
        'app1': {
            "handlers": ["console", "flat_line_file", "json_file"],
            "level": "INFO",
            'propagate': False,
        },
        'app2': {
            "handlers": ["console", "flat_line_file", "json_file"],
            "level": "INFO",
            'propagate': False,
        },
        'app3': {
            "handlers": ["console", "flat_line_file", "json_file"],
            "level": "INFO",
            'propagate': False,
        }
    }
}

structlog.configure(
    processors=[
        structlog.stdlib.filter_by_level,
        structlog.processors.TimeStamper(fmt="%Y-%m-%d %H:%M:%S.%f"),  # (fmt="iso"),
        structlog.stdlib.add_logger_name,
        structlog.stdlib.add_log_level,
        structlog.stdlib.PositionalArgumentsFormatter(),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.processors.UnicodeDecoder(),
        structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
    ],
    context_class=structlog.threadlocal.wrap_dict(dict),
    logger_factory=structlog.stdlib.LoggerFactory(),
    wrapper_class=structlog.stdlib.BoundLogger,
    cache_logger_on_first_use=True,
)

You're gonna have to be a bit more specific. I see three formatters in your config, which one do you want to affect? Also: which Python version are you running? — hynek, May 05 '20 at 05:48
Sorry for the lack of specification, I would like to `sort_key=False` the `plain_console` formatter since it supports `colors=True` so it's the one I use the most. The reason I'm asking this question is because I found hard to read log flow when order of the events is changed after insertion of a new event somewhere in the middle or at the beginning. — Florent, May 05 '20 at 06:35

score 0 · Answer 1 · answered May 06 '20 at 03:42

Currently structlog.dev.ConsoleRenderer does not have an option to disable key sorting.

The reason is that it's for humans and it's harder to orient yourself in a log when the key/value pairs are changing their position all the time.

In worst case, you have to hunt a key anew for every record with no real indication where it could be. With alphabetic order you at least know where to search for it.

I understand that it would be nicer to have certain new keys at the end, but ultimately it would mean that every key could potentially dance around all the time.

How to unsort key:value pairs with structlog in plain console mode?

1 Answers1