Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Downgrade the Warning to Information on missing Content-Length header in MultiplexingMiddleware #2146

Merged
merged 4 commits into from
Sep 14, 2024

Conversation

PaulARoy
Copy link
Contributor

@PaulARoy PaulARoy commented Sep 3, 2024

Aggregations log a lot of warnings due to missing content-headers (for aggregations without body).

Most of the time it's a completely normal behavior and it doesn't justify a warning message, we simply don't have a body. It might be interesting to keep an information log though.

Not sure tests are relevant for this minor fix as it's just logging.

@raman-m raman-m changed the title fix: downgrade the warning to information on missing content-length header Downgrade the Warning to Information on missing Content-Length header Sep 3, 2024
@raman-m
Copy link
Member

raman-m commented Sep 3, 2024

Hello Paul,
It must be an issue related to Staging and Production environments only. For Development we don't care about logging levels because we specify usually Debug (level 1) or even Trace (level 0).

How many records are logged in the log?
Which environment is set to use the Warning level?

P.S. If the Warning (level 3) is set in the Testing (Staging) environment, then Production should be set to Error (level 4), and your logs won't contain this message. However, if Production is set to Warning level, then your logs will indeed be full of these messages.

@raman-m raman-m added Aggregation Ocelot feature: Request Aggregation Logging Ocelot feature: Logging labels Sep 3, 2024
@PaulARoy
Copy link
Contributor Author

PaulARoy commented Sep 3, 2024

Hello raman,

I indeed see these logs in staging and production environment, and it's only a problem because it sends warning to my error tracking platform (Sentry).

We log one warning line per call of aggregate function that is missing a Content-Length header, but I initially thought it was an abnormality: it is not. All bodyless queries are missing the Content-Length header, which means all GET methods to an aggregate logs a Warning line, which is incorrect.

So my initial asumption to track it as a warning was wrong, this is a completely normal code path. Thus downgrading the log level to Information instead of Warning.

I still think it's relevant to log it as info.

Don't hesitate if you have any more questions.

@PaulARoy
Copy link
Contributor Author

PaulARoy commented Sep 3, 2024

Additional info: from this decision tree, I initially believed it was an unwanted state from which the process could continue (Warning), but we are not in an unwanted state (it's a normal situation), thus the Information level.

log_levels

@raman-m
Copy link
Member

raman-m commented Sep 4, 2024

Paul, this decision-making diagram is excellent! 😃 However, let's not suggest implementing a user's role in the configuration JSON. 🤣 Just kidding...

We will switch to the Information level to minimize log output. I would like to draw attention to line 266, where it may be prudent to also lower the logging level. @ggnaegi, what are your thoughts?

@PaulARoy, my plan is to merge it in the upcoming regular monthly release slated for September'24. Our team will be quite busy in September as we have two pending releases: the v23.3 Hotfixes and the Annual 2023. The latter is anticipated to be a swift release around mid-September, hopefully.
How critical is this minor fix for you? What's the priority?

@raman-m raman-m added proposal Proposal for a new functionality in Ocelot Oct'24 October 2024 release labels Sep 4, 2024
@raman-m raman-m added this to the September'24 milestone Sep 4, 2024
@PaulARoy
Copy link
Contributor Author

PaulARoy commented Sep 5, 2024

Thanks raman

Regarding line 266 I'd thought about it and I'd keep the Warning level: this is an abnormal situation where somewhere someone has started reading the body. This shouldn't be happening and will cause the downstream to miss on the body (so continue on an abnormal state => Warning).

Honestly this is a bit critical for me as it logs a warning on each GET aggregate call (most of them). It saturates the logs and the bug tracking tool and I had to disable the tool entirely for now. While it doesn't break anything, it makes it a bit less production-ready.

Considering how little it is I'd appreciate if you could take this in the next release, but it is not completely blocking.

@raman-m raman-m modified the milestones: September'24, v23.3 Hotfixes Sep 5, 2024
@raman-m
Copy link
Member

raman-m commented Sep 5, 2024

Understood regarding line 266. Let's keep it as Warning.

Honestly this is a bit critical for me as it logs a warning on each GET aggregate call (most of them).

No problem to prioritize! The PR has been included in the ongoing v23.3 Hotfixes release.

Copy link
Member

@raman-m raman-m left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Currently, the GET verb is permitted for the Aggregation feature. However, it appears that we will soon introduce additional verbs, see PR #1389, thus relaxing the strict GET requirement. Let's ensure we don't overlook this update.

@@ -276,7 +276,7 @@ protected virtual async Task<Stream> CloneRequestBodyAsync(HttpRequest request,
}
else
{
Logger.LogWarning("Aggregation does not support body copy without Content-Length header!");
Logger.LogInformation("Aggregation does not support body copy without Content-Length header, skipping body copy.");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I recommend implementing a minor decision-making process based on the HTTP verb

  • If the verb is GET, then it should be logged at the Information level, as should HEAD, OPTIONS, and other verbs that do not have a body.
  • However, if the verb is PUT, POST, etc., then we should log at the Warning level.

This approach should suffice to determine the appropriate logging level.

Copy link
Contributor Author

@PaulARoy PaulARoy Sep 6, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi raman,

Hard disagree for me on this, as the presence or absence of body is not specified in the HTTP spec.

It's an entirely normal and supported scenario to have a PUT or POST query without body and it stills holds a meaning (https://lists.w3.org/Archives/Public/ietf-http-wg/2010JulSep/0276.html)

Also I know we probably won't agree on this, but GET, OPTIONS and HEAD are not prohibited from having a body (it's just undefined by the spec) :D

So I wouldn't log it as a warning and I wouldn't make a verb-specific logic here.

Copy link
Member

@raman-m raman-m Sep 6, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair enough! Not an issue.

TODO

  • Add decision maker for logging level

Copy link
Member

@raman-m raman-m left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Paul, I appreciate your small contribution! 💟

@raman-m raman-m changed the title Downgrade the Warning to Information on missing Content-Length header Downgrade the Warning to Information on missing Content-Length header in MultiplexingMiddleware Sep 14, 2024
@raman-m raman-m merged commit c502e4f into ThreeMammals:develop Sep 14, 2024
1 check passed
@raman-m raman-m removed the Oct'24 October 2024 release label Oct 2, 2024
raman-m added a commit that referenced this pull request Oct 3, 2024
…Blue Olympic Balumbes release

* #2084 Apply default config file paths in `GetMergedOcelotJson` when providing the `folder` argument of `AddOcelot` (#2120)

* Adding unit test first

* Fixing default global config file not being found in folder

* Adding PR trait to test

* Backing out whitespace changes

* Code review by @raman-m

* Create Configuration feature folder and move test classes

* Adjust namespace and review what we have

* Acceptance tests for #2084 user scenario

---------

Co-authored-by: Raman Maksimchuk <[email protected]>

* Bump Steeltoe.Discovery.Eureka from 3.2.5 to 3.2.8 in /src/Ocelot.Provider.Eureka (#2122)

* Bump Steeltoe.Discovery.Eureka in /src/Ocelot.Provider.Eureka

Bumps [Steeltoe.Discovery.Eureka](https://github.com/SteeltoeOSS/Steeltoe) from 3.2.5 to 3.2.8.
- [Release notes](https://github.com/SteeltoeOSS/Steeltoe/releases)
- [Changelog](https://github.com/SteeltoeOSS/Steeltoe/blob/main/Steeltoe.Release.ruleset)
- [Commits](SteeltoeOSS/Steeltoe@3.2.5...3.2.8)

---
updated-dependencies:
- dependency-name: Steeltoe.Discovery.Eureka
  dependency-type: direct:production
...

Signed-off-by: dependabot[bot] <[email protected]>

* Bump Steeltoe.Discovery.ClientCore from 3.2.5 to 3.2.8

---------

Signed-off-by: dependabot[bot] <[email protected]>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Co-authored-by: Raman Maksimchuk <[email protected]>

* #2110 Review load balancing and independent fetching the list of services in `Kube` provider (#2111)

* Move the creation of the services list from the class field to the method, to prevent modification list from different threads

* Early return after data checking

* Add unit test for concurrent get list of services

* Add logging for invalid service configuration error in RoundRobin load balancer

* Code review by @raman-m

* Workaround for mistakes made during acceptance testing of load balancing versus service discovery, where tests designed for parallel requests were mistakenly executed sequentially. This resulted in load balancers being loaded by sequential `HttpClient` calls, which was a significant oversight.

* Let's DRY StickySessionsTests

* Add acceptance tests, but...
RoundRobin is not actually RoundRobin 😁 -> 😆

* Independent static indexing iterators per route via service names

* Stabilize `CookieStickySessions` load balancer.
Review tests after refactoring of `RoundRobin` load balancer

* Refactor Lease operation for load balancing.
Review LeastConnection load balancer

* Leasing mechanism in Round Robin load balancer

* Acceptance tests, final version

* Apply Retry pattern for K8s endpoint integration

* Fix IDE warnings and messages

* Follow suggestions and fix issues from code review by @ggnaegi

* Bump KubeClient from 2.4.10 to 2.5.8

* Fix warnings

* Final version of `Retry` pattern

---------

Co-authored-by: Raman Maksimchuk <[email protected]>

* Downgrade the Warning to Information on missing `Content-Length` header in `MultiplexingMiddleware` (#2146)

* fix: downgrade the warning to information on missing content-length header

* chore: add route name to logs

* test: fixing multiplexing middleware tests

* Code review by @raman-m

---------

Co-authored-by: Paul Roy <[email protected]>
Co-authored-by: Raman Maksimchuk <[email protected]>

* Correct the broken link to the GraphQL sample's `README.md` (#2149)

Signed-off-by: Emmanuel Ferdman <[email protected]>
Co-authored-by: Raman Maksimchuk <[email protected]>

* #2116 Escaping unsafe pattern values of `Regex` constructor ​​derived from URL query parameter values containing special `Regex` chars (#2150)

* regex escape handling for url templates

* refactored regex method to lamda version

* Quick code review by @raman-m

* added acceptance test for url regex bug

* moved acceptance test to routing tests

* Convert to theory: define 2 test cases

---------

Co-authored-by: Raman Maksimchuk <[email protected]>

* #2119 Review load balancing (2nd round) and redesign `DefaultConsulServiceBuilder` with `ConsulProviderFactory` refactoring to make it thread safe and friendly (#2151)

* Review tests

* History of Service Discovery testing: add traits

* LoadBalancer traits

* #2119 Steps to Reproduce

* Reuse service handlers of `ConcurrentSteps`

* Reuse service counters of `ConcurrentSteps`

* Add LoadBalancer namespace and move classes

* Move `Lease`

* Move `LeaseEventArgs`

* Analyze load balancers aka `ILoadBalancerAnalyzer` interface objects

* Prefer using named local methods as delegates over anonymous methods for awesome call stack, ensuring the delegate's typed result matches the typed balancer's creator. Additionally, employ an IServiceProvider workaround.

* Review load balancing. Assert service & leasing counters as concurrent step. Final version of acceptance test.

* Fixed naming violation for asynchronous methods: `Lease` -> `LeaseAsync`

* Fix ugly reflection issue of dymanic detection in favor of static type property

* Propagate the `ConsulRegistryConfiguration` object through `HttpContext` in the scoped version of the default service builder, utilizing the injected `IHttpContextAccessor` object.
Update `ConsulProviderFactory`.
Update docs.
Update tests.

* Add tests from clean experiment

* Final review of the tests

* Review `IHttpContextAccessor` logic.
Convert anonymous delegates to named ones in placeholders processing

* Tried to enhance more, but failed

---------

Signed-off-by: dependabot[bot] <[email protected]>
Signed-off-by: Emmanuel Ferdman <[email protected]>
Co-authored-by: Ben Bartholomew <[email protected]>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Co-authored-by: Roman <[email protected]>
Co-authored-by: Paul Roy <[email protected]>
Co-authored-by: Paul Roy <[email protected]>
Co-authored-by: Emmanuel Ferdman <[email protected]>
Co-authored-by: Finn <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Aggregation Ocelot feature: Request Aggregation Logging Ocelot feature: Logging proposal Proposal for a new functionality in Ocelot
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants