request(middleware): Use log levels when logging responses

[adinhodovic]

Would be nice if error levels were used when logging responses. Similar to Django's request handler:

https://github.com/django/django/blob/main/django/utils/log.py#L233-L249

Would simplify integration with structlog's stdlibs filter_by_level that filters based on method name and add_log_level that adds the log level. I currently add my processor for adding status_code -> level. But having issues with a custom filter to exclude log levels based on level instead of method_name since I think the python logging framework drops my log either way based on the method_name when setting logging level to warning for example.

Opinionated request, understandable if it does not go through.

[jrobichaud]

You mean you only want to log errors?

If you change INFO for ERROR in your logger configuration it should normally work.

https://github.com/jrobichaud/django-structlog/blob/master/config/settings/local.py#L141

I might not understand what your are trying to achieve.

[adinhodovic]

Hmm, no I'd like the request middleware to use the log level functions that align with each status codes' severity to be used.

https://github.com/jrobichaud/django-structlog/blob/master/django_structlog/middlewares/request.py#L34C5-L38

            logger.info(
                "request_finished",
                code=response.status_code,
                request=self.format_request(request),
            )

Preferred:

if response.status_code >= 500:
    level = "error"
elif response.status_code >= 400:
    level = "warning"
else:
    level = "info"

getattr(logger, level)(
    "request_finished",
    *args,
    extra={
        "code": response.status_code,
        "request": self.format_request(request),
    },
)

This would ensure that the method used would be logger.warning for 4xx, and logger.error for 5xx. Django does the same thing for their request logs: https://github.com/django/django/blob/main/django/utils/log.py#L233-L249.

If you take a look at structlogs stdlib they use method name to add log levels or filter:

https://github.com/hynek/structlog/blob/main/src/structlog/_log_levels.py#L51-L72

This allows me to adjust the log level and actually drop logs that are INFO. If I adjust the log level atm it will drop all log request logs since their all using the info method_name.

TLDR; my request is to only log 4xx and 5xx responses :D and adjusting method_name per status code simplifies this.

[jrobichaud]

I get it now. You want to change the log level based on the response status.

I'll have to look into it.

[jrobichaud]

I agree

if response.status_code >= 500:
    level = "error"
elif response.status_code >= 400:
    level = "warning"
else:
    level = "info"

is opinionated but I suppose for a library named django-structlog, django and structlog's opinions have considerable weight.

I am considering using django's behaviour by default and allow people to personalize the level for 4XX code. 5XX should always be error.

[jrobichaud]

@adinhodovic, please see #309

[adinhodovic]

@adinhodovic, please see #309

Yes exact! Tried it locally, worked well. Thanks for the quick response and implementation!

[jrobichaud]

@adinhodovic, I am not ready to release 6.0.0 yet.

Will it be ok with you if I make a pre release version?

[adinhodovic]

@adinhodovic, I am not ready to release 6.0.0 yet.

Will it be ok with you if I make a pre release version?

Yes, works fine with me! Thank you.

[jrobichaud]

You can install this version explicitely:

pip install django-structlog==6.0.0.dev1

[adinhodovic]

You can install this version explicitely:

pip install django-structlog==6.0.0.dev1

Did, thanks!

[sshishov]

Hello @jrobichaud and @adinhodovic , due to these changes I would like to ask, how we can suppress the structlog-sentry integration which creates the issues on Sentry for logger.error statements. We were using these statements to indicate some invalid state which we should look into, but it is not the real exception of the application.

Also when exception happens, it is propagated to Sentry as unhandled and then 500 code returned to the client. With these changes it means it will create the request_failed log statement with level ERROR and it will cause the creation of "duplicate" issue on sentry, because one was created by unhandled excepiton itself.

The question is, what is the best way to "suppress" this new behavior? Should I listen to the event of request failed and DO something there with context or similar?

Best regards, Sergei

[jrobichaud]

sentry-structlog seems to have a ignore_loggers A list of logger names to ignore any events from. could this resolve your issue?

[sshishov]

@jrobichaud Let me try to check and confirm. If it will resolve, I will post a snippet here if someone needed it also.