larryh/corso
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

minor logging updates (#3546)

Browse Source 
Co-authored-by: aviator-app[bot] <48659329+aviator-app[bot]@users.noreply.github.com>
This commit is contained in:
Keepers 2023-06-01 01:01:08 -06:00 committed by GitHub
parent 59ff00ceaa
commit 2da554f00e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 26 additions and 36 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

51
src/internal/connector/graph/middleware.go
View File

@ -140,29 +140,21 @@ func (mw *LoggingMiddleware) Intercept(
var (
log = logger.Ctx(ctx)
respClass = resp.StatusCode / 100
logExtra = logger.DebugAPIFV || os.Getenv(logGraphRequestsEnvKey) != ""
// special cases where we always dump the response body, since the response
// details might be critical to understanding the response when debugging.
// * 400-bad-request
// * 403-forbidden
logBody = logger.DebugAPIFV ||
os.Getenv(logGraphRequestsEnvKey) != "" ||
resp.StatusCode == http.StatusBadRequest ||
resp.StatusCode == http.StatusForbidden
)
// special case: always info log 429 responses
// special case: always info-level status 429 logs
if resp.StatusCode == http.StatusTooManyRequests {
if logExtra {
log = log.With("response", getRespDump(ctx, resp, true))
}
log.Infow(
"graph api throttling",
"limit", resp.Header.Get(rateLimitHeader),
"remaining", resp.Header.Get(rateRemainingHeader),
"reset", resp.Header.Get(rateResetHeader),
"retry-after", resp.Header.Get(retryAfterHeader))
return resp, err
}
// special case: always dump status-400-bad-request
if resp.StatusCode == http.StatusBadRequest {
log.With("response", getRespDump(ctx, resp, true)).
Error("graph api error: " + resp.Status)
log.With("response", getRespDump(ctx, resp, logBody)).
Info("graph api throttling")
return resp, err
}
@ -170,25 +162,18 @@ func (mw *LoggingMiddleware) Intercept(
// Log api calls according to api debugging configurations.
switch respClass {
case 2:
if logExtra {
if logBody {
// only dump the body if it's under a size limit. We don't want to copy gigs into memory for a log.
dump := getRespDump(ctx, resp, os.Getenv(log2xxGraphResponseEnvKey) != "" && resp.ContentLength < logMBLimit)
log.Infow("2xx graph api resp", "response", dump)
}
case 3:
log = log.With("redirect_location", LoggableURL(resp.Header.Get(locationHeader)))
if logExtra {
log = log.With("response", getRespDump(ctx, resp, false))
}
log.Info("graph api redirect: " + resp.Status)
log.With("redirect_location", LoggableURL(resp.Header.Get(locationHeader))).
With("response", getRespDump(ctx, resp, false)).
Info("graph api redirect: " + resp.Status)
default:
if logExtra {
log = log.With("response", getRespDump(ctx, resp, true))
}
log.Error("graph api error: " + resp.Status)
log.With("response", getRespDump(ctx, resp, logBody)).
Error("graph api error: " + resp.Status)
}
return resp, err

3
src/internal/operations/backup.go
View File

@ -177,7 +177,8 @@ func (op *BackupOperation) Run(ctx context.Context) (err error) {
ctx = clues.Add(
ctx,
"tenant_id", clues.Hide(op.account.ID()),
"resource_owner", clues.Hide(op.ResourceOwner.Name()),
"resource_owner_id", op.ResourceOwner.ID(),
"resource_owner_name", clues.Hide(op.ResourceOwner.Name()),
"backup_id", op.Results.BackupID,
"service", op.Selectors.Service,
"incremental", op.incremental)

8
src/internal/operations/restore.go
View File

@ -194,6 +194,10 @@ func (op *RestoreOperation) do(
detailsStore streamstore.Reader,
start time.Time,
) (*details.Details, error) {
logger.Ctx(ctx).
With("control_options", op.Options, "selectors", op.Selectors).
Info("restoring selection")
bup, deets, err := getBackupAndDetailsFromID(
ctx,
op.BackupID,
@ -213,7 +217,8 @@ func (op *RestoreOperation) do(
ctx = clues.Add(
ctx,
"resource_owner", bup.Selector.DiscreteOwner,
"resource_owner_id", bup.Selector.ID(),
"resource_owner_name", clues.Hide(bup.Selector.Name()),
"details_entries", len(deets.Entries),
"details_paths", len(paths),
"backup_snapshot_id", bup.SnapshotID,
@ -230,7 +235,6 @@ func (op *RestoreOperation) do(
})
observe.Message(ctx, fmt.Sprintf("Discovered %d items in backup %s to restore", len(paths), op.BackupID))
logger.Ctx(ctx).With("control_options", op.Options, "selectors", op.Selectors).Info("restoring selection")
kopiaComplete, closer := observe.MessageWithCompletion(ctx, "Enumerating items in repository")
defer closer()