Incorrect Logging Level for JSON Format Errors in POST Requests

[KrzysztofPajak]

Description:

When sending a POST request with an incorrectly formatted JSON body (e.g., containing only the character '}'), the error details are logged with a Level = Debug. This logging level seems inappropriate for this type of error, and it should be logged with Level = Error instead.

Steps to Reproduce:

1. Send a POST request to the API endpoint with a malformed JSON body. For example: } Observe the logs generated by the application.

Expected Behavior:

The application should log the details of the error with a logging level of Error.

Actual Behavior:

The error details are logged with a logging level of Debug.

Environment:

ASP.NET Core Version: 8.0 Operating System: Windows 11

Additional Information:

Logging critical errors such as malformed JSON requests at a Debug level can obscure important issues that should be promptly addressed. Adjusting the logging level to Error will ensure these issues are more visible to developers and system administrators.

[martincostello]

This would allow a malicious client to spam the server's error logs by sending invalid JSON payloads.

The server isn't necessarily in control of the client and thus would not be able to take any action to make the client send a valid JSON payload.

With that I mind, I would consider the current default behaviour to be correct.

[KrzysztofPajak]

@martincostello I agree that this could potentially flood the error logs, much like other requests can. My points of views:

Visibility of Critical Issues Logging malformed JSON requests as errors makes it easier to identify and address critical issues that may be affecting the application's functionality or security. Debug logs are often less scrutinized, which can result in missing important information about recurring issues.

Improving Security Logging these incidents as errors can help in detecting potential malicious activities. If someone is deliberately sending malformed JSON payloads, it could be part of an attack or probing attempt. Having this logged as an error can alert the security team to investigate further.

Ease of Monitoring Monitoring and alerting systems are often configured to watch for error logs rather than debug logs. By logging these incidents as errors, the system can automatically alert administrators or developers, allowing for quicker response times to potential issues.

Debug Level Overload The debug log level is often filled with numerous informational and diagnostic messages. Important error information can get lost in this noise. Logging these incidents as errors ensures they are not overlooked among less critical debug information.

User Impact Misunderstanding the root cause of an issue due to insufficient logging can lead to prolonged downtime or poor user experiences. Logging as errors helps in quicker diagnosis and resolution of issues, improving overall user satisfaction.

[martincostello]

missing important information about recurring issues

This should be the responsibility of the client - it's sending malformed data and not succeeding, that's the client's fault, not the server's.

Logging these incidents as errors can help in detecting potential malicious activities. If someone is deliberately sending malformed JSON payloads, it could be part of an attack or probing attempt. Having this logged as an error can alert the security team to investigate further.

The volume of logging that could come from this could create a Denial of Service on the server (e.g. fill up the disk if file logging is used) and make such a scenario worse. It could also increase the cost to you if you store logs remotely and you pay based on volume ingested.

There's better ways to deal with this, such as alerting on metrics on HTTP status codes (if suddenly 90% of responses are causing an HTTP 4xx, then fire an alert for investigation). With the current behaviour, the spammy content would potentially be easily brushed off - elevating the message to error would create additional work on the server's part, making things worse than they already were.

Monitoring and alerting systems are often configured to watch for error logs rather than debug logs. By logging these incidents as errors, the system can automatically alert administrators or developers, allowing for quicker response times to potential issues.

Again, this is going to create noise. My personal website gets various spammy requests from crawlers I can't control or stop. I wouldn't want my logs full of this noise by it being logged as an error - it being in debug means I never see it, because it's not important. They also aren't errors, they're 404s caused by spam - my server is behaving correctly - there's no error, even if the behaviour from the client is undesirable. If you have real problems you can only see with debug logs, that suggests you're missing dedicated checks to observe whatever these problems are and remediate them.

[KrzysztofPajak]

Indeed, for services that are in production and accessible externally, logging such incidents might not be practical. However, for internal services where communication between services is crucial, this information can be highly significant.

Currently, I need to set ThrowOnBadRequest to true and additionally catch this exception as an error, then manually change it to a 400 (BadRequest). This is my workaround, but I believe there should be an option that addresses this problem more effectively.

By having a configurable option to log these incidents as errors, it allows for flexibility in different scenarios. Internal services can benefit from the increased visibility, while external-facing services can opt to keep it at the debug level to avoid log noise and potential DoS scenarios.

This approach provides a balanced solution that caters to both use cases, ensuring critical issues are not overlooked in internal communications while maintaining performance and log efficiency for external services.

[martincostello]

Yeah, I think an opt-in would be the only way to address this. I don't think changing the existing level would be workable due to the adverse affects a malicious client could create.