Adding correlation IDs to reconcile loops

[arschles]

Signed-off-by: Aaron Schlesinger [email protected]

What type of PR is this?

/kind feature

What this PR does / why we need it:

This PR adds shared correlation IDs to context.Contexts passed to reconcile loops, so that the API requests made to Azure get logged and tracked properly. That feature is especially useful for debugging.

Which issue(s) this PR fixes (optional, in fixes #<issue number>(, fixes #<issue_number>, ...) format, will close the issue(s) when PR gets merged):
Fixes #1310

Special notes for your reviewer:

Please confirm that if this PR changes any image versions, then that's the sole change this PR makes.

TODOs:

• squashed commits
• includes documentation
• adds unit tests

Release note:

Add 'x-ms-correlation-id' headers to all Azure API calls via distributed traces.

[k8s-ci-robot]

Welcome @arschles!

It looks like this is your first PR to kubernetes-sigs/cluster-api-provider-azure 🎉. Please refer to our pull request process documentation to help your PR have a smooth ride to approval.

You will be prompted by a bot to use commands during the review process. Do not be afraid to follow the prompts! It is okay to experiment. Here is the bot commands documentation.

You can also check if kubernetes-sigs/cluster-api-provider-azure has its own contribution guidelines.

You may want to refer to our testing guide if you run into trouble with your tests not passing.

If you are having difficulty getting your pull request seen, please follow the recommended escalation practices. Also, for tips and tricks in the contribution process you may want to read the Kubernetes contributor cheat sheet. We want to make sure your contribution gets all the attention it needs!

Thank you, and welcome to Kubernetes. 😃

[k8s-ci-robot]

Hi @arschles. Thanks for your PR.

I'm waiting for a kubernetes-sigs member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

[arschles]

/kind feature

[CecileRobertMichon]

/ok-to-test

Welcome @arschles!

[devigned]

WDYT about changing the way that tele.Tracer.Start() works such that anytime start is called and the context does not contain a correlationID, one is generated and added to the value bag. This could be done as a best effort kind of thing, so the error could be ignored, or a default value substituted if a new UUID can not be created?

Also, pkg/trace/corr.go requires a file header comment. You will see them littered through the other code files. If you run make test, it will generate files, lint, and run the local tests.

[arschles]

@devigned I think that's a great idea! I'm working on both the tele.Tracer.Start() change and fixing build issues now.

[arschles]

/retest

[devigned]

WDYT of something like this:

In ./util/tele.go, we wrap the otel.Tracer with our own struct that implements trace.Tracer. We then write our own Start(...) func which would then delegate back to otel.Tracer().Start(...). That way the interface can stay the same.

package tele

type tracer struct {
    otel.Tracer
}

func (t *tracer) Start(ctx, opName string, opt ...otel.SpanOption) (context.Context, otel.Span) {
    // add correlationID to ctx and continue as normal
    // return the inner implementation of Start
    return t.Tracer.Start(ctx, opName, opt...)
}

Then either in the same package or elsewhere, add context helpers to set / fetch the correlationID.

package corr  // or something else...

// FromCtx or some better name you think of
func FromCtx(ctx context.Context) (ctx, string) {
    // create new context.WithValue containing correlationID and return both if it does not exist, else return context and correlationID
}

[arschles]

Sure, happy to do that! A few questions before I get started, just to make sure I'm on the same page

• I'm assuming that you'd want to still call tele.Tracer().Start(...) in all the reconcilers, correct?
• Are you ok with creating our own tracer instance (the wrapper you mentioned) and then passing that -- instead of the default one -- to otel.SetTracerProvider in main.go?
• Do we need FromCtx to be exported at all? It seems like it would only be used inside the same package as the custom tracer, but not sure if you're thinking something more

[devigned]

I'm assuming that you'd want to still call tele.Tracer().Start(...) in all the reconcilers, correct?

If possible, that would be great.

Are you ok with creating our own tracer instance (the wrapper you mentioned) and then passing that -- instead of the default one -- to otel.SetTracerProvider in main.go?

💯

Do we need FromCtx to be exported at all? It seems like it would only be used inside the same package as the custom tracer, but not sure if you're thinking something more

I was adding that because I saw you were returning the correlationID in your StartSpan func. This led me to think you wanted a way to access it from the context. I think one might need to access the correlationID from the context to be able to add that as a HTTP header for the Azure SDK for Go clients.

[arschles]

perfect - I'll make these changes.

regarding FromCtx - just in case someone wants to access the correlation ID, I'll make FromCtx exported like you said.

[arschles]

@devigned just an update, so you know I haven't forgotten about this! I'm looking through the implementation & docs trying to figure out a way to create a new TracerProvider that we can pass to the SetTracerProvider function in main.go. That would need to create a new Tracer which wraps the implementation you referenced above. I think that's going to require a lot of plumbing, which we could make unnecessary if we called a custom function to get either:

• get a new tracer that which wraps the underlying tracer implementation, like what you showed here
• create a new span, which is what's already in this PR

I'll keep digging, but let me know about going with either of the above options in case there isn't a good way to wrap everything we need

[arschles]

Another option would be to create a custom TracerProvider that wraps the jaeger one. Let me know your thoughts on that too?

[devigned]

Sorry for the delay, @arschles. I was thinking something more like this: master...devigned:corr

The above diff should add the correlationID to the context without needing to manipulate the signature of the Tracer. wdyt?

[arschles]

Hi @devigned I see what you mean now! Thanks, I'll implement that.

[arschles]

@devigned got it, I've removed most of the formatting changes made earlier - there are a few still here in which I moved the creation of cancellable contexts below the creation of the spans. that is so the new contexts can be based on the contexts that were created by the new span. I do think it's valuable - but not critical - to do that so the cancellable context has the new correlation IDs in it. let me know what you think of that.

also to address your and @CecileRobertMichon's point about percolating these correlation IDs up to the Azure API - I had originally planned on doing that in a follow-up PR when this PR was large, to draw a clear line between the change to add the IDs and the change to send them up to Azure. now that this is smaller, would you prefer I do that all in this PR?

I'm happy to do it either way, whatever makes it easier for you all

[CecileRobertMichon]

I had originally planned on doing that in a follow-up PR when this PR was large, to draw a clear line between the change to add the IDs and the change to send them up to Azure. now that this is smaller, would you prefer I do that all in this PR?

separate PR is fine with me, up to you

[devigned]

/lgtm
/assign @CecileRobertMichon

[arschles]

Thanks @CecileRobertMichon - I'll submit a follow-up PR with those changes

[devigned]

/lgtm

[CecileRobertMichon]

why the change in order here but not in every controller? azuremachine and azurecluster still have the reverse order

[arschles]

I moved this context creation down to below the creation of the span so that the timeout context includes the correlation ID value. IIRC the others had this change but I reverted them by accident. Would it make more sense to save all these changes for a separate PR?

[CecileRobertMichon]

either way, as long as the changes are consistent (make the changes here to all the controllers or none of them)

[arschles]

ok, going to take this change out then because it's not strictly necessary

[arschles]

@CecileRobertMichon are you ok with this the the other similar format fixes?

[devigned]

/retest

[CecileRobertMichon]

/lgtm
/approve
/retest

[k8s-ci-robot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: CecileRobertMichon

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

• OWNERS [CecileRobertMichon]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[arschles]

/test pull-cluster-api-provider-azure-e2e