Performance/CPU usage regression in v0.40.0

[David-Wobrock]

Preflight checklist

• I could not find a solution in the existing issues, docs, nor discussions.
• I agree to follow this project's Code of Conduct.
• I have read and am following this repository's Contribution Guidelines.
• This issue affects my Ory Network project.
• I have joined the Ory Community Slack.
• I am signed up to the Ory Security Patch Newsletter.

Describe the bug

When upgrading from v0.39.4 to v0.40.0, we experience an increase of CPU load on our Oathkeeper instances.
In our case, our Kubernetes pods were throttled and our response times at least doubled.

There is the experienced increased CPU usage:

From roughly 20-30 mcores, to around 200 mcores.

Discussed in the Ory Slack here https://ory-community.slack.com/archives/C01340V8KSM/p1668072872425319

Reproducing the bug

In version v0.40.0 and in our oathkeeper config we have 3 rules and one mutator.

• oauth2_introspection, being the most used
• cookie_session
• bearer_token
  And a mutator that injects an HTTP header.

Relevant log output

No response

Relevant configuration

No response

Version

v0.40.0

On which operating system are you observing this issue?

Linux

In which environment are you deploying?

Kubernetes

Additional Context

No response

[aeneasr]

Thank you for the report! I think this is for sure a regression introduced by the new config system. Maybe, we're now unmarshalling JSON on every request or something similar. Could you maybe make a memory / cpu profile of oathkeeper so that we can identify the culprit?

• https://go.dev/blog/pprof
• https://medium.com/@openmohan/profiling-in-golang-3e51c68eb6a8

[David-Wobrock]

Hey @aeneasr
Indeed, it seems that when serving a request (in my profiling the /anything/header route from the local config):

In v0.39.4, we are unmarshalling JSON only once, on pipeline.mutate.Validate

Whereas in v0.40.0, it seems that we unmarshal JSON 4 times, after:

• pipeline.authn.Authenticate
• pipeline.authn.Validate
• pipeline.mutate.Mutate
• pipeline.mutate.Validate

Any idea what happened there? :)

[aeneasr]

This is probably for @hperl to pick up. He's however busy for the next 4-8 weeks. We will add this to our backlog but can't promise an immediate remedy.

[daviddelucca]

Hey there! @hperl @alnr

Any news on it? CPU usage is being insane after bump to v0.40.0

[aeneasr]

There's unfortunately not an easy and straight forward fix for this. The profiling above shows where the problem is, and there is also a PR, but unfortunately there are several edge cases that would break with such a cache in place, in particular hot reloading.

I don't currently know what the appropriate solution is. Most likely it's improving the decoding in https://github.com/ory/oathkeeper/pull/1042/files#diff-cc3b4579387dc2abd0841eff38ec96aa687447a9bd2f1327b124e5678c443cd8R340 by using koanf built ins instead of marshal/unmarshal.

But as we're ok with the CPU usage (even if it is significantly higher it's still quite low), it's currently not a priority on our side to fix, but we do encourage PRs and ideas how to resolve it!

[aeneasr]

Ok, I double checked and think I found a solution, posted it here: #1042 (comment)

[aeneasr]

Merged, please check if this resolves the issues!

[David-Wobrock]

Seems to work for us 👍
Looking forward a release with this patch 🚀

[daviddelucca]

Same here!

How long will take to release a version with this patch?

[aeneasr]

We just merged another refactor to fix a pesky bug, we'll be testing that in our env and once we have confidence do a release. The release policy for bigger changes is once every quarter (at least) :)