Add an optional hook upon record creation

[ClementMaliet]

Hello,

I have a rather log-heavy application which regularly outputs long multi-line messages. Up until version 0.4.0, I used a (admittedly hackish) custom format function to modify the record message in-place to replace it with an appropriately coloured and dot-padded version.

My actual formatter code look something like that..

class Formatter:
    """A log formatter function."""

    def __init__(self):
        self.format_string = "[{time:YYYY-MM-DD HH:mm:ss.SSSS zz}]" \
                             "[<b><y>{module}:{line}</y></b>] - " \
                             "[<b>{level}</b>]: " \
                             "<level>{message}</level>\n{exception}"

    @staticmethod
    def _indent(message, length):
        lines = message.splitlines()
        indented = ['<n><w>' + '.' * (length - 1) + ':</w></n> <level>' + l + '</level>' for l in lines]
        indented[0] = lines[0]
        return '\n'.join(indented)

    def format(self, record):
        if not record['extra'].get('formatted', False):
            if '\n' in record['message']:
                length = len("[{time:YYYY-MM-DD HH:mm:ss.SSSS zz}]"
                             "[{module}:{line}] - "
                             "[{level}]:".format(**record))
                record['message'] = self._indent(record['message'], length)
                record['extra']['formatted'] = True
        return self.format_string

However since the 0.4.1 release, whenever using colours, the message which get printed is a colour-parsed message computed long before the any hook function kicks in, be it patch or format.

I do know that modifying the record dictionary is explicitly discouraged in the documentation because of potential consistency issues such as mine. However, a hook entry point activated just after the record creation (or having the patch call there to avoid addition the API) would do the trick with no consistency issue as nothing would have ever happened with the record yet.

Now, there might be implementation details I did not considered as I am rather unfamiliar with the full loguru codebase but I think one of loguru's strength is its flexibility and I believe this would enable useful customization to the way logs are emitted by applications.

[Delgan]

Hi @ClementMaliet.

So, I've been thinking about your problem. I don't believe adding a new hook or changing the existing one would be of much help. The handling of messages and color is rather complex.
It has been established that record["message"] should contain the message stripped of any color tag and ansi codes (this is required for sending logs over the network). This choice led to a new implementation of logs formatting whereby the record["message"] is not directly used if opt(colors=True).

I do agree this led to an undesirable and surprising behavior: one can modify the record["message"] in format or patch() but only see the old message in output logs, as if the modification had no effect. I don't think this can be fixed. As you said, I will rely on the documentation discouraging such modification to explain that.
It may look like logs formatting is simply implemented with str_format.format_map(record) while it's actually custom_format_map(str_format, record, internal_args).

Anyway. I think another solution is possible.
Basically, you still have to use a custom format function, but you have to make sure that the color tags appear in the format and not in the message. You should also make sure that the "dynamic" parts of your message are contained in the extra dict to avoid parsing errors. Also, it implies you no longer need to use opt(colors=True).

def custom_format(record):
    format_string = "[{time:YYYY-MM-DD HH:mm:ss.SSSS zz}]" \
                    "[<b><y>{module}:{line}</y></b>] - " \
                    "[<b>{level}</b>]: " \
                    "<level>%s</level>\n{exception}"
    
    message_token = "{message}"

    if not record["extra"].get("formatted", False):
        if "\n" in record["message"]:
            length = len("[{time:YYYY-MM-DD HH:mm:ss.SSSS zz}]"
                         "[{module}:{line}] - "
                         "[{level}]:".format(**record))
            lines = record["message"].splitlines()
            message_token = "\n".join("<n><w>" + "." * (length + 1 if i > 0 else 0) + ":</w></n> <level>{extra[lines][%d]}</level>" % i for i in range(len(lines)))
            record["extra"]["lines"] = lines
            record["extra"]["formatted"] = True

    return format_string % message_token

This is a little bit hackish but this is an acceptable workaround in my opinion.

It seems a little bit complex, though, compared to simply starting the multi-lines message on a new line. 😄

[ClementMaliet]

Hi @Delgan,

This is indeed a reasonable workaround, the idea was hackish from the start and it does seem understandable not to change the API to support such a niche use case, all the more so if it may introduce confusion as to what information record['message'] is expected to carry.

Though I do agreed that it might indeed be useful to put some emphasis in the documentation on the fact that record['message'] is not necessarily what will be printed as it came out as a bit of a surprise to me when I noticed it.

Thank you for the workaround which I will use to update loguru and keep my complicated formatting.

[Delgan]

I was quite worried about this very surprising behavior. As a result, I have slightly modified the way messages are handled. Basically, if record["message"] has been modified, then the pre-colored message will not be used (however, the updated message is logged as is, there is no color tag parsing). It seems more appropriate. 👍