[VC-36032] Pass the context to Venafi clients and enable debug roundtripper by wallrj · Pull Request #627 · jetstack/jetstack-secure

wallrj · 2024-11-21T10:27:40Z

Improve orderly shutdown by abandoning ongoing requests to Venafi when the context is cancelled
Make it easier to debug venafi data upload problems by allowing the request details to be logged with --log-level=6.

go run . agent --install-namespace venafi --one-shot --input-path out.json  --venafi-connection venafi-components -v6

I1127 09:58:16.779115 318776 metrics_transport.go:113] "outgoing http request succeeded" source="controller-runtime" method="POST" uri="https://api.venafi.eu/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token" status="200 OK" duration="582.557289ms"
I1127 09:58:17.313520 318776 round_trippers.go:553] POST https://api.venafi.eu/v1/tlspk/upload/clusterdata/no?name=my_cluster 200 OK in 502 milliseconds
I1127 09:58:17.313624 318776 run.go:405] "Data sent successfully" logger="Run.gatherAndOutputData.postData"

W1127 09:58:17.313811 318776 reflector.go:484] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: watch of *v1alpha1.VenafiConnection ended with: an error on the server ("unable to decode an event from the watch stream: context canceled") has prevented the request from succeeding
I1127 09:58:17.313874 318776 reflector.go:311] Stopping reflector *v1alpha1.VenafiConnection (10h1m26.347417125s) from pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243
I1127 09:58:17.313899 318776 run.go:484] "Shutting down" logger="Run.APIServer.ListenAndServe" addr=":8081"
I1127 09:58:17.314047 318776 run.go:499] "Shutdown complete" logger="Run.APIServer.ListenAndServe" addr=":8081"

Add the client-go debug round tripper to the venafi clients Signed-off-by: Richard Wall <richard.wall@venafi.com>

Signed-off-by: Richard Wall <richard.wall@venafi.com>

wallrj · 2024-11-27T14:14:35Z

deploy/charts/venafi-kubernetes-agent/README.md

+extraArgs:
+- --logging-format=json
+- --log-level=6 # To enable HTTP request logging
+```


https://github.com/jetstack/jetstack-secure/blob/VC-36032/context-to-client/deploy/charts/venafi-kubernetes-agent/README.md#extraargs--array

wallrj · 2024-11-27T14:16:33Z

deploy/charts/venafi-kubernetes-agent/values.yaml

+#  extraArgs:
+#  - --logging-format=json
+#  - --log-level=6 # To enable HTTP request logging
 extraArgs: []


Matches what is now used in the E2E test:

https://github.com/jetstack/jetstack-secure/blob/VC-36032/context-to-client/hack/e2e/values.venafi-kubernetes-agent.yaml#L11-L13

jetstack-secure/hack/e2e/values.venafi-kubernetes-agent.yaml

Lines 11 to 13 in fcca2f1

extraArgs:

- --logging-format=json

- --log-level=6

wallrj · 2024-11-27T14:38:12Z

hack/e2e/values.venafi-kubernetes-agent.yaml

 extraArgs:
 - --logging-format=json
- --log-level=2
+- --log-level=6


Here's how it looks in Google Logs Explorer

wallrj · 2024-11-27T14:41:31Z

pkg/agent/config_test.go


-		err = cl.PostDataReadingsWithOptions(nil, client.Options{ClusterName: "test cluster name"})
+		err = cl.PostDataReadingsWithOptions(ctx, nil, client.Options{ClusterName: "test cluster name"})
 		require.NoError(t, err)


Nothing gets logged by the client in this test

$ go test ./pkg/agent/... -v -run "Test_ValidateAndCombineConfig_VenafiCloudKeyPair" === RUN Test_ValidateAndCombineConfig_VenafiCloudKeyPair === RUN Test_ValidateAndCombineConfig_VenafiCloudKeyPair/server,_uploader_id,_and_cluster_name_are_correctly_passed envtest.go:188: fake api.venafi.cloud received request: POST /v1/oauth/token/serviceaccount envtest.go:188: fake api.venafi.cloud received request: POST /v1/tlspk/upload/clusterdata/no --- PASS: Test_ValidateAndCombineConfig_VenafiCloudKeyPair (0.01s) --- PASS: Test_ValidateAndCombineConfig_VenafiCloudKeyPair/server,_uploader_id,_and_cluster_name_are_correctly_passed (0.01s) PASS ok github.com/jetstack/preflight/pkg/agent 0.044s

wallrj · 2024-11-27T14:43:09Z

pkg/agent/config_test.go

 		// PostDataReadingsWithOptions.
-		err = cl.PostDataReadingsWithOptions(nil, client.Options{ClusterName: cfg.ClusterID})
+		err = cl.PostDataReadingsWithOptions(ctx, nil, client.Options{ClusterName: cfg.ClusterID})
 		require.NoError(t, err)


$ go test ./pkg/agent/... -v -run "Test_ValidateAndCombineConfig_VenafiConnection" === RUN Test_ValidateAndCombineConfig_VenafiConnection === RUN Test_ValidateAndCombineConfig_VenafiConnection/err_when_cluster_id_field_is_empty === RUN Test_ValidateAndCombineConfig_VenafiConnection/the_server_field_is_ignored_when_VenafiConnection_is_used === NAME Test_ValidateAndCombineConfig_VenafiConnection envtest.go:188: fake api.venafi.cloud received request: POST /v1/tlspk/upload/clusterdata/no envtest.go:51: Waiting for envtest to exit --- PASS: Test_ValidateAndCombineConfig_VenafiConnection (7.01s) --- PASS: Test_ValidateAndCombineConfig_VenafiConnection/err_when_cluster_id_field_is_empty (0.00s) --- PASS: Test_ValidateAndCombineConfig_VenafiConnection/the_server_field_is_ignored_when_VenafiConnection_is_used (0.17s) PASS ok github.com/jetstack/preflight/pkg/agent 7.041s

wallrj · 2024-11-27T14:46:00Z

pkg/client/client_venconn_test.go

$ go test ./pkg/client/... -v -run "TestVenConnClient_PostDataReadin gsWithOptions" === RUN TestVenConnClient_PostDataReadingsWithOptions === PAUSE TestVenConnClient_PostDataReadingsWithOptions === CONT TestVenConnClient_PostDataReadingsWithOptions === RUN TestVenConnClient_PostDataReadingsWithOptions/valid_accessToken envtest.go:188: fake api.venafi.cloud received request: POST /v1/tlspk/upload/clusterdata/no === RUN TestVenConnClient_PostDataReadingsWithOptions/error_when_the_apiKey_field_is_used W1127 14:44:47.223096 366750 reflector.go:484] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: watch of *v1.PartialObjectMetadata ended with: an error on the server ("unable to decode an event from the watch stream: context canceled") has prevented the request from succeeding envtest.go:188: fake api.venafi.cloud received request: GET /v1/useraccounts envtest.go:188: fake api.venafi.cloud received request: GET /v1/useraccounts metrics_transport.go:113: I1127 14:44:47.488976] outgoing http request succeeded method="GET" uri="https://127.0.0.1:36713/v1/useraccounts" status="200 OK" duration="340.47µs" W1127 14:44:47.491474 366750 reflector.go:484] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: watch of *v1alpha1.VenafiConnection ended with: an error on the server ("unable to decode an event from the watch stream: context canceled") has prevented the request from succeeding === RUN TestVenConnClient_PostDataReadingsWithOptions/error_when_the_tpp_field_is_used W1127 14:44:47.491530 366750 reflector.go:484] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: watch of *v1.PartialObjectMetadata ended with: an error on the server ("unable to decode an event from the watch stream: context canceled") has prevented the request from succeeding envtest.go:235: fake tpp.example.com received request: GET /vedsdk/Identity/Self envtest.go:235: fake tpp.example.com received request: GET /vedsdk/Identity/Self metrics_transport.go:113: I1127 14:44:47.756336] outgoing http request succeeded method="GET" uri="https://127.0.0.1:46053/vedsdk/Identity/Self" status="200 OK" duration="453.761µs" === NAME TestVenConnClient_PostDataReadingsWithOptions envtest.go:51: Waiting for envtest to exit --- PASS: TestVenConnClient_PostDataReadingsWithOptions (7.93s) --- PASS: TestVenConnClient_PostDataReadingsWithOptions/valid_accessToken (2.35s) --- PASS: TestVenConnClient_PostDataReadingsWithOptions/error_when_the_apiKey_field_is_used (0.27s) --- PASS: TestVenConnClient_PostDataReadingsWithOptions/error_when_the_tpp_field_is_used (0.27s) PASS ok github.com/jetstack/preflight/pkg/client 7.958s

Signed-off-by: Richard Wall <richard.wall@venafi.com>

…rt values documentation. Signed-off-by: Richard Wall <richard.wall@venafi.com>

wallrj · 2024-11-27T14:58:31Z

pkg/client/client_venconn.go

client-go uses the global klog functions rather than the logger from the context. I didn't realise that when I started this PR and in hindsight the introduction of DebugWrappers could be split into a separate PR.

https://pkg.go.dev/k8s.io/client-go@v0.30.2/transport#DebugWrappers

https://github.com/kubernetes/client-go/blob/v0.30.2/transport/round_trippers.go#L459-L476

maelvls · 2024-11-28T10:04:38Z

I'm OK with these having these two seemingly unrelated changes (debug roundtripper + pass context down to Venafi clients) since it aims to the same thing: logging HTTP requests for the Venafi client and the Kubernetes client.

outgoing http request succeeded method="GET" uri="https://127.0.0.1:46053/vedsdk/Identity/Self" status="200 OK" duration="453.761µs"

Excellent! We will have a much easier way to debug customer issues with -v=6. Your PR will allow us to close #220, too. @hawksight will be super happy to hear about your change.

I have looked at the changes and they look OK to me. I have not tried the feature locally since you showed everything I needed in the PR description.

maelvls · 2024-11-28T10:08:09Z

Maybe one note: client-go seems to be forcing -v=6 on us. I don't particularly like -v=6 as it is super hidden, but it's such a helpful feature. Sometimes, I'd prefer that we had something like --log-http-requests, but -v=6 will do, especially since you have added some notes in the flag's help:

-v      0=Info, 1=Debug, 2=Trace. Use 6-9 for increasingly verbose HTTP request logging. (default: 0)

wallrj force-pushed the VC-36032/context-to-client branch 3 times, most recently from 12618ad to f46d396 Compare November 27, 2024 09:51

Pass the context to the Venafi clients

68bbb8f

Add the client-go debug round tripper to the venafi clients Signed-off-by: Richard Wall <richard.wall@venafi.com>

wallrj force-pushed the VC-36032/context-to-client branch from f46d396 to 68bbb8f Compare November 27, 2024 09:55

wallrj added 3 commits November 27, 2024 12:17

Fix the venconn client tests

79aa13f

Signed-off-by: Richard Wall <richard.wall@venafi.com>

Fix the config tests

02aa2f9

Signed-off-by: Richard Wall <richard.wall@venafi.com>

Fix golangci-lint contextcheck error

6ad7079

Signed-off-by: Richard Wall <richard.wall@venafi.com>

wallrj force-pushed the VC-36032/context-to-client branch 2 times, most recently from 3b3b68a to ec8af5f Compare November 27, 2024 14:18

wallrj commented Nov 27, 2024

View reviewed changes

wallrj added 2 commits November 27, 2024 14:48

Add a note about HTTP request logging to the logging flags

45fb767

Signed-off-by: Richard Wall <richard.wall@venafi.com>

Add a note about setting logging-format and log-level to the Helm cha…

fcca2f1

…rt values documentation. Signed-off-by: Richard Wall <richard.wall@venafi.com>

wallrj force-pushed the VC-36032/context-to-client branch from ec8af5f to fcca2f1 Compare November 27, 2024 14:48

wallrj changed the title ~~WIP: [VC-36032] Pass the context to the Venafi clients~~ [VC-36032] Pass the context to Venafi clients and enable debug roundtripper Nov 27, 2024

wallrj commented Nov 27, 2024

View reviewed changes

wallrj requested a review from maelvls November 27, 2024 15:01

maelvls approved these changes Nov 28, 2024

View reviewed changes

wallrj merged commit 98afe3b into master Nov 28, 2024

wallrj deleted the VC-36032/context-to-client branch November 28, 2024 10:10

wallrj restored the VC-36032/context-to-client branch November 28, 2024 10:10

wallrj deleted the VC-36032/context-to-client branch November 28, 2024 10:10

wallrj mentioned this pull request Nov 28, 2024

[VC-36032] Log the client-id when VenafiCloudKeypair authentication is used #625

Merged

wallrj linked an issue Nov 28, 2024 that may be closed by this pull request

A flag for setting the log level and more verbose log output #220

Closed

wallrj mentioned this pull request Nov 29, 2024

[VC-36032] Set User-Agent header containing the agent version in all HTTP requests #631

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[VC-36032] Pass the context to Venafi clients and enable debug roundtripper#627

[VC-36032] Pass the context to Venafi clients and enable debug roundtripper#627
wallrj merged 6 commits intomasterfrom
VC-36032/context-to-client

wallrj commented Nov 21, 2024 •

edited

Loading

Uh oh!

wallrj Nov 27, 2024

Uh oh!

wallrj Nov 27, 2024 •

edited

Loading

Uh oh!

wallrj Nov 27, 2024

Uh oh!

wallrj Nov 27, 2024

Uh oh!

wallrj Nov 27, 2024

Uh oh!

wallrj Nov 27, 2024

Uh oh!

wallrj Nov 27, 2024

Uh oh!

maelvls commented Nov 28, 2024

Uh oh!

maelvls commented Nov 28, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Conversation

wallrj commented Nov 21, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wallrj Nov 27, 2024

Choose a reason for hiding this comment

Uh oh!

wallrj Nov 27, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

wallrj Nov 27, 2024

Choose a reason for hiding this comment

Uh oh!

wallrj Nov 27, 2024

Choose a reason for hiding this comment

Uh oh!

wallrj Nov 27, 2024

Choose a reason for hiding this comment

Uh oh!

wallrj Nov 27, 2024

Choose a reason for hiding this comment

Uh oh!

wallrj Nov 27, 2024

Choose a reason for hiding this comment

Uh oh!

maelvls commented Nov 28, 2024

Uh oh!

maelvls commented Nov 28, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

wallrj commented Nov 21, 2024 •

edited

Loading

wallrj Nov 27, 2024 •

edited

Loading