feature: add support for log messages formatting

[HorlogeSkynet]

Checklist

• [x] All new and existing tests are passing
• [ ] (If adding features:) I have added tests to cover my changes
• [x] (If docs changes needed:) I have updated the documentation accordingly.
• [x] I have added an entry to CHANGES.rst because this is a user-facing change or an important bugfix
• [x] I have written proper commit message(s)

What changes does this Pull Request introduce?

Add ability to configure log messages format through configuration.

Why is this necessary?

%(asctime)s can be interesting to add to timestamp log messages.

[ix5]

This feature looks interesting, but I have a few thoughts:

• I'm not entirely convinced it is necessary
• At the moment, the linked Python docs page doesn't really tell you much, maybe you could add a few examples or mention the available format strings (asctime, name, message, levelname etc?)
• Security risks; though this would require access to setting the config, format strings are a source of bugs/incidents1, 2. I'm not the right person to judge this, perhaps others might chime in how to mitigate those risks?

[HorlogeSkynet]

Thanks for reviewing this.

1. It is not strictly "necessary", but timestamped logs are much more interesting (not to say "needed" in some cases). If this patch is rejected, Isso should change its default logs format to include (at least) date and time.

2. That can be done, indeed.

3. To exploit this you need to tweak the configuration. On a regular setup, being able to do so would require same privileges as modifying code. So this risk is affordable, IMHO.

Bye 👋

---

EDIT 25/12/2023 : Rebased and amended to take 2 into account. Merry Xmas :christmas_tree:

[HorlogeSkynet]

Hey ! Any chance to get this merged before next release ? :slightly_smiling_face:

[ix5]

Left some review comments inline. Please also add a few tests, our coverage should increase, not decrease with time.

I'm also partial to changing the default log format to include timestamps. That needs to be communicated, of course.

As for this:

To exploit this you need to tweak the configuration. On a regular setup, being able to do so would require same privileges as modifying code. So this risk is affordable, IMHO.

It's not necessarily about an attacker already having gained access to the config file, but rather an inexperienced admin changing the defaults (perhaps by including the user-submitted text verbatim in the logs) and thus opening themselves up to vulnerabilities. At the very least, we should have a small overview of logging format vulnerabilities that might affect Isso here.

[HorlogeSkynet]

Left some review comments inline. Please also add a few tests, our coverage should increase, not decrease with time.

The only code that is modified is the entry point, which isn't actually tested at all.

I'm also partial to changing the default log format to include timestamps. That needs to be communicated, of course.

The default log format is not changed. This patch allows changing it.

As for this:

To exploit this you need to tweak the configuration. On a regular setup, being able to do so would require same privileges as modifying code. So this risk is affordable, IMHO.

It's not necessarily about an attacker already having gained access to the config file, but rather an inexperienced admin changing the defaults (perhaps by including the user-submitted text verbatim in the logs) and thus opening themselves up to vulnerabilities. At the very least, we should have a small overview of logging format vulnerabilities that might affect Isso here.

I've added another note to the documentation to emphasize that setting this option is not harmless.

Thanks, bye :wave:

[HorlogeSkynet]

Hello @jelmer 👋

As commented, I'm skeptical this is a useful feature - especially in light of isso's goal to have reasonable defaults and minimal.

If I may, as commented, this patch does not change current behavior (to address "reasonable defaults") and is actually 2-line long (to address "minimal").

That said, if there is enough support for including this I think there should at least be some tests for it.

Having logs with proper timestamps is required by law in some countries to answer legal requests (to address "enough support") and I'd love to add a test case to ensure standard library works as expected, if Isso entrypoint were actually tested at all.

Bye 🙏

[jelmer]

I think that's an argument for improving the default log format rather than making the log format configurable.

The change isn't minimal, because we now have more code paths - including e.g. handling invalid log format expressions.

[HorlogeSkynet]

Hello @jelmer

I think that's an argument for improving the default log format rather than making the log format configurable.

You will find the branch rebased and updated in order to change the default log format (changelog has been modified accordingly).

The change isn't minimal, because we now have more code paths - including e.g. handling invalid log format expressions.

We don't necessarily have to : if an administrator replaces the (now default) log format by another somewhat broken, Python logging library will emit tracebacks (prefixed by --- Logging error ---) whereas Isso will continue to run smoothly.

Bye :wave:

[HorlogeSkynet]

Thanks for the update - but that still doesn't address my original comments about making this configurable without adding appropriate tests.

Hello @jelmer 👋

As I said, many other configuration options (as log-file) are not tested. Actually, entry point is not tested at all. I don't think it is a good thing either, but I'm not sure this issue should be addressed here, as entry point testing is a fully-separate concern. Also, I fail to see how "testing standard library" downstream would be interesting (as written before, wrong formatting strings will cause explicit exceptions in standard output).

Bye 🙏

[jelmer]

The fact that not everything is tested (although @ix5 has made massive strides improving overall test coverage) isn't a good reason for not adding tests for new features (and reducing our overall test coverage).

It would be good to test that invalid log settings don't cause isso to crash, but another thing to test would simply be that the option actually works (i.e. that the log format is actually applied when setting the options). If you look at some of the other PRs open against isso, they all come with tests.

[HorlogeSkynet]

The fact that not everything is tested (although @ix5 has made massive strides improving overall test coverage) isn't a good reason for not adding tests for new features (and reducing our overall test coverage).

I fully agree (see my previous message). If Isso entry point were actually tested, I would have extended it according to this "feature". Re-increasing code coverage (for this conditional branch) could be the subject of another patch, implementing entry point tests.

It would be good to test that invalid log settings don't cause isso to crash, but another thing to test would simply be that the option actually works (i.e. that the log format is actually applied when setting the options).

I guess such tests got their place in standard library (do they already exist ?). The option actually works, as it runs in production for me since 2023-11-08.

If you look at some of the other PRs open against isso, they all come with tests.

Indeed, they don't modify/target the entry point.

[ix5]

The utility of this change is still nebulous to me. I'd be open to changing isso's default log format (to file, that is, gunicorn already differs anyway) to expose more fields or be better readable. IMO, we haven't made any promises to users regarding the format (stability) of logs so far so a change wouldn't hurt anyone.

I hate to see the collective effort wasted on discussing this PR and really don't want to dissuade the author from contributing to this (or other) projects. He surely won't be too happy with the next paragraph and I can see why they'd feel upset.

However, with the author repeatedly refusing to accept maintainer feedback regarding tests I don't see a path forward for this PR and am going to close this. If jelmer feels differently he may reopen.

[HorlogeSkynet]

Hello @ix5 and thanks for taking a decision :pray:

The utility of this change is still nebulous to me.

This has been addressed above (TL; DR : legal issues regarding metadata ; In the end, is there a software out there writing logs lacking of a proper timestamp ?).

I hate to see the collective effort wasted on discussing this PR and really don't want to dissuade the author from contributing to this (or other) projects.

:+1:

I really wonder though how this would "dissuade" me from contributing to OSS. Projects usually approve my patches, not this one, and that's unfortunate (after 6 months, 2 rebases/reworks + 20 messages). But you are the maintainers so you decide.

I don't see a path forward for this PR

... even accepting that entry point and log-file option are already not tested, so log-format does not either require to be, or writing proper entry point tests and rebase/extend this patch.

---

If some users/administrators happen to get to the bottom of this endless discussion, I'll be maintaining the patch here, while Isso does not support this feature (as I am legally required to do so).

---

Thanks, bye :wave: