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

chore: correlation for worker logger #710

Merged
merged 1 commit into from
Oct 12, 2023
Merged

Conversation

lzap
Copy link
Member

@lzap lzap commented Oct 11, 2023

During investigation of a problem, I noticed that worker is missing jobID from all pgx log messages therefore you will not see some records which are useful. This fixes it and unifies how context (and logger) is created across jobs. It also adds trace/edge IDs so logs can be correlated across api/worker to see the whole workflow of a reservation.

I cannot figure out why tests are failing, it is too late my brain does not work anymore. Will take a look tomorrow.

@lzap lzap force-pushed the sql-logging branch 2 times, most recently from 0f682a6 to aba6075 Compare October 11, 2023 18:12
@lzap
Copy link
Member Author

lzap commented Oct 11, 2023

This is weird, unit tests are failing locally for me. Not on CI tho :-)

@ezr-ondrej
Copy link
Member

/retest
weird error ... public_ip missing, I'm guessing omitempty is not delt with properly on OpenAPI level 🤔

@ezr-ondrej
Copy link
Member

Huh, I've started reviewing and then decided to actually learn about tracing bit more.
I've ended up with following: #711 unfortunatelly the rename makes it hard to read :/

Let's discuss tomorrow? I guess I'd prefer a meeting, I'm too deep and in need of second brain xD

@lzap
Copy link
Member Author

lzap commented Oct 12, 2023

Found a typo, rebased.

principal := identity.Identity(ctx)
zx = zx.Str("org_id", principal.Identity.OrgID)
zx = zx.Str("account_number", principal.Identity.AccountNumber)
return zx
}))
Copy link
Member Author

Choose a reason for hiding this comment

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

This hunk ensures that all pgx logging has a proper context and will appear in Kibana correctly.

if val == nil {
return Principal{}
}
return val.(Principal)
Copy link
Member Author

Choose a reason for hiding this comment

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

The Get from middleware project does not handle nil correctly, so this is a copy.

@lzap
Copy link
Member Author

lzap commented Oct 12, 2023

Ah test do fail locally on the main branch as well. Likely my local environment, need to take a look.

Logger())
ctx = logger.WithContext(ctx)
return ctx, logger
}
Copy link
Member Author

Choose a reason for hiding this comment

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

Just saw your PR and realized some of this code should live in worker.contextLogger instead. Moving.

@lzap
Copy link
Member Author

lzap commented Oct 12, 2023

I just moved most of the logging/context handling into worker/ package where it belongs. Only reservation ID is in the jobs/ package now.

Signed-off-by: Lukas Zapletal <[email protected]>
Signed-off-by: Lukáš Zapletal <[email protected]>
@lzap
Copy link
Member Author

lzap commented Oct 12, 2023

One additional change: otelpgx.WithIncludeQueryParameters() will cause the otel version of the pgx tracer to include parameters in logs. We do not store any sensitive data, this will vastly help me to understand the issue I am solving.

@@ -96,7 +83,11 @@ func (w *RedisWorker) Enqueue(ctx context.Context, job *Job) error {
}
}

logger := loggerWithJob(ctx, job)
Copy link
Member

Choose a reason for hiding this comment

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

Why did you removed the function? 🤔

Copy link
Member Author

Choose a reason for hiding this comment

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

Yeah there is replacement now, only for two cases there is not yet enough information so I replaced it with plain code.

ctx = contextLogger(ctx, job)
ctx, logger := contextLogger(origCtx, job)
defer recoverAndLog(ctx)
logger.Info().Msgf("Dequeued job %s %s from Redis", job.Type.String(), job.ID)
Copy link
Member

Choose a reason for hiding this comment

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

We are now not logging the attributes on Dequeue, is that intentional?

Copy link
Member Author

Choose a reason for hiding this comment

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

We do, it is in the contextLogger function now (every log entry has it now).

Copy link
Member

@ezr-ondrej ezr-ondrej left a comment

Choose a reason for hiding this comment

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

I believe this should work! :)
Left few nits, but we can address in follow-ups 👍

@ezr-ondrej ezr-ondrej merged commit e0a5b13 into RHEnVision:main Oct 12, 2023
6 checks passed
@ezr-ondrej
Copy link
Member

One additional change: otelpgx.WithIncludeQueryParameters() will cause the otel version of the pgx tracer to include parameters in logs. We do not store any sensitive data, this will vastly help me to understand the issue I am solving.

We do not yet, but we should keep it in mind, there might be some sensitive data in the future.

@lzap lzap deleted the sql-logging branch October 12, 2023 10:59
@lzap
Copy link
Member Author

lzap commented Oct 12, 2023

Hmm unfortunately, I don’t see query parameters being logged at all. Other than that it works and with your patch the trace will be actually correct :-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants