erlang-lager / lager

A logging framework for Erlang/OTP
Apache License 2.0
1.12k stars 456 forks source link

lager_default_formatter doesn't handle formatter configs that use bytes in iolists #443

Open nickelization opened 6 years ago

nickelization commented 6 years ago

This is a pretty minor nitpick, but I noticed an inconsistency between the docs and the behavior of the custom formatting code. The docs for lager_default_formatter say "any traditional iolist elements in the configuration are printed verbatim." Traditional iolist elements may include single character bytes (the byte() type in Erlang being defined as 0..255) but when I use this config:

{formatter_config,[message,$\n]}

it prints log lines like this:

hello world10this is a second message10

i.e. it formats the $\n byte as the integer 10 instead of the \n character.

Haven't looked at the code yet, so not sure if this is easily fixable, but I can try and take a look later this week if nobody else picks it up. (Hopefully changing the behavior to print bytes as characters instead of integers wouldn't break anything for any existing users, but it seems like a pretty odd quirk for someone to be deliberately relying on, and since it's not documented to behave this way I feel like we could probably consider it a bugfix and not a feature change.) Or, alternatively, we could just add a note in the docs about this. It is, of course, easy to work around by just changing the config to {formatter_config, [message, "\n"]}).

Vagabond commented 6 years ago

$\n by itself is not an iolist, it is just a number that happens to have the same value in the ASCII table as a newline, an iolist would be [$\n], no?

nickelization commented 6 years ago

Well, the docs say that the formatter "provides a generic, default formatting for log messages using a structure similar to Erlang's iolist which we call "semi-iolist"...any traditional iolist elements in the configuration are printed verbatim". $\n is not an iolist, but it is an iolist element, I would think.

nickelization commented 6 years ago

Okay I reread it a few times. Perhaps it was meant to be interpreted as "any elements that are themselves iolists are printed verbatim"? I read it as "any elements that would be allowed in iolists are also allowed here." If it's supposed to be the former, then maybe we should just reword it to make that more clear.

Vagabond commented 6 years ago

I see your point, maybe we can/should fix it? If you want to make a PR we can at least take a look at the impact and any backwards compatibility concerns.

nickelization commented 6 years ago

Sounds good 👍 I did a little more experimenting and it does allow bare binary strings (e.g. {formatter_config,[message,<<"\n">>]}) which are iolist elements but not iolists themselves I believe, so that seems consistent with my initial interpretation. I'll take a look at writing a PR later this week or next :)

Vagabond commented 6 years ago

The more I look at it the more I think you're right and nobody sane should be relying on this behaviour.

jadeallenx commented 6 years ago

Hey @nickelization did you ever have time to look into this?

nickelization commented 6 years ago

Hey sorry, I know I said I was going to look into it but I've been super busy for the last month (just started a new job) and haven't gotten around to it yet. If anyone else wants to pick this up, feel free, or else it'll have to wait until I have a little more free time in my schedule....

jadeallenx commented 6 years ago

Sorry wasn't trying to guilt you into anything - no worries if you haven't got time. Just trying to clean up our open issues. Thanks for letting me know.

juise commented 6 years ago

I guess I stumbled upon the same problem. We have use lager and lager_syslog and our custom formatter (but really, it's doesn't matter).

We have follow log message: lage:info("~ts", [<<"To: \"ЯSomething New\" <sip:192.168.55.16>">>]). where "Я" it's Russian later "Я" by example.

when lager process this message it's call: https://github.com/erlang-lager/lager/blob/master/src/lager_format.erl#L73 and after https://github.com/erlang-lager/lager/blob/master/src/lager_format.erl#L252 which gives:

[84,111,58,32,34,1071,83,111...]

This list goes through formatter, and it's doesn't matter which formatter to use. And after that message goes to the backend, in my case it's lager_syslog, which crash when seeing 1071 number in iolist.