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

proxy-injector doesn't respect JSON logging configuration for all log messages #13168

Closed
woz5999 opened this issue Oct 10, 2024 · 9 comments · Fixed by #13335
Closed

proxy-injector doesn't respect JSON logging configuration for all log messages #13168

woz5999 opened this issue Oct 10, 2024 · 9 comments · Fixed by #13335

Comments

@woz5999
Copy link

woz5999 commented Oct 10, 2024

What is the issue?

When JSON logging is enabled, the proxy-injector uses the proper JSON format for some log messages, but not all.

How can it be reproduced?

  • Enable JSON logging for the proxy-injector (we use helm and set controllerLogFormat: json
  • Ensure you had pods in your cluster that are configured NOT to be injected by the injector
  • View proxy-injector logs

Logs, error output, etc

This is an example of mix-format log messages from a proxy-injector pod:

{"level":"info","msg":"received admission review request \"83a0ce4d-ab81-42c9-abe4-e0ade0f926e2\"","time":"2024-10-10T21:06:18Z"}
time="2024-10-10T21:06:18Z" level=info msg="received pod/mypod"
time="2024-10-10T21:06:18Z" level=info msg="skipped pod/mypod: neither the namespace nor the pod have the annotation \"linkerd.io/inject:enabled\""
{"level":"info","msg":"received admission review request \"c2321ce9-7c3d-4f37-86c7-33a4a337ded0\"","time":"2024-10-10T21:06:28Z"}
time="2024-10-10T21:06:28Z" level=info msg="received pod/mypod2"
time="2024-10-10T21:06:28Z" level=info msg="skipped pod/mypod2: neither the namespace nor the pod have the annotation \"linkerd.io/inject:enabled\""
{"level":"info","msg":"received admission review request \"ba4d8337-ec51-46d1-931e-610c067fbc58\"","time":"2024-10-10T21:08:11Z"}
time="2024-10-10T21:08:11Z" level=info msg="received pod/mypod3"
time="2024-10-10T21:08:11Z" level=info msg="injection patch generated for: pod/mypod3"

output of linkerd check -o short

linkerd-version
---------------
‼ cli is up-to-date
    unsupported version channel: stable-2.14.10
    see https://linkerd.io/2.14/checks/#l5d-version-cli for hints

control-plane-version
---------------------
‼ control plane and cli versions match
    control plane running edge-24.10.2 but cli running stable-2.14.10
    see https://linkerd.io/2.14/checks/#l5d-version-control for hints

linkerd-control-plane-proxy
---------------------------
‼ control plane proxies and cli versions match
    linkerd-destination-5cf894ff9c-5jshx running edge-24.10.2 but cli running stable-2.14.10
    see https://linkerd.io/2.14/checks/#l5d-cp-proxy-cli-version for hints

linkerd-ha-checks
-----------------
‼ pod injection disabled on kube-system
    kube-system namespace needs to have the label config.linkerd.io/admission-webhooks: disabled if injector webhook failure policy is Fail
    see https://linkerd.io/2.14/checks/#l5d-injection-disabled for hints

linkerd-viz
-----------
‼ viz extension proxies and cli versions match
    metrics-api-86dd7f89dd-n6dvp running edge-24.10.2 but cli running stable-2.14.10
    see https://linkerd.io/2.14/checks/#l5d-viz-proxy-cli-version for hints

Status check results are √

Environment

  • Server Version: version.Info{Major:"1", Minor:"29+", GitVersion:"v1.29.8-eks-a737599"
  • EKS
  • Bottlerocket

Possible solution

No response

Additional context

No response

Would you like to work on fixing this bug?

None

@woz5999 woz5999 added the bug label Oct 10, 2024
@woz5999 woz5999 changed the title proxy-injector doesn't response JSON logging for all log messages proxy-injector doesn't respect JSON logging configuration for all log messages Oct 10, 2024
@VISHESH0932
Copy link

Hey @woz5999 , I would love to work on this issue.

@woz5999
Copy link
Author

woz5999 commented Oct 14, 2024

That's great. Let me know what I can do to assist.

@MicahSee
Copy link
Contributor

MicahSee commented Nov 9, 2024

Look like this issue is still open! I can take it over if needed.

@MicahSee
Copy link
Contributor

It looks like the file controller/proxy-injector/webhook.go is creating local instance of logrus and therefore may not be reflecting the global config when you set controllerLogFormat: json.

The lines that do respect the json format seem to be generated in controller/webhook/server.go while the lines that do not respect the json formatting are being generated in controller/proxy-injector/webhook.go. I can make the appropriate fixes if that's okay.

@woz5999
Copy link
Author

woz5999 commented Nov 13, 2024

I'm not sure which maintainers would be the ones to review the resulting PR, but that assessment and approach seems reasonable to me.

@MicahSee
Copy link
Contributor

MicahSee commented Nov 13, 2024

Sounds good! One clarifying question is how were you viewing the logs? Were you using kubectl logs?

@woz5999
Copy link
Author

woz5999 commented Nov 13, 2024

You can reproduce this with kubectl logs, yes

@MicahSee
Copy link
Contributor

Okay great and one other question. Installation with helm you just used a command similar to:
helm install linkerd-control-plane \ -n linkerd \ --set controllerLogFormat=json \ --set-file identityTrustAnchorsPEM=ca.crt \ --set-file identity.issuer.tls.crtPEM=issuer.crt \ --set-file identity.issuer.tls.keyPEM=issuer.key \ linkerd-edge/linkerd-control-plane

@woz5999
Copy link
Author

woz5999 commented Nov 13, 2024

Correct, installed via helm

olix0r pushed a commit that referenced this issue Nov 18, 2024
Ensure consistent JSON logging for proxy-injector container

When JSON logging is enabled in the proxy-injector `controllerLogFormat: json` some log messages adhere to the JSON format while others do not. This inconsistency creates difficulty in parsing logs, especially in automated workflows. For example:

```
{"level":"info","msg":"received admission review request \"83a0ce4d-ab81-42c9-abe4-e0ade0f926e2\"","time":"2024-10-10T21:06:18Z"}
time="2024-10-10T21:06:18Z" level=info msg="received pod/mypod"
```

Modified the logging implementation in the `controller/proxy-injector/webhook.go` to ensure all log messages follow the JSON format consistently. This was achieved by removing a new instance of the logrus logger that was being created in the file and replacing it with the global logger instance, ensuring all logs respect the controllerLogFormat configuration.

Reproduced the issue by enabling JSON logging and observing mixed-format logs when install the emojivoto sample application. Applied the changes and verified that all logs consistently use the JSON format.
Ran the linkerd check command and confirmed there are no additional warnings or issues.
Tested various scenarios, including pods with and without the injection annotation, to ensure consistent logging behavior.
Fixes #13168

Signed-off-by: Micah See [email protected]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants