Skip to content

Commit

Permalink
kvstreamer: improve logging a bit
Browse files Browse the repository at this point in the history
This commit adjusts the logging for each `singleRangeBatch` to include
the number of scans inside of it (we only included the number of gets
previously). It also drops the bitmap for whether the scans were started
(this doesn't seem that useful - `positions` slice kinda implicitly has
that information).

Additionally, it includes the TargetBytes limit that each BatchRequest
was issued with into an existing log message (we have this information
down at the KV level too, but it makes things easier when grepping from
streamer logs specifically).

Release note: None
  • Loading branch information
yuzefovich committed May 13, 2024
1 parent 0b25bdb commit ee28f87
Show file tree
Hide file tree
Showing 2 changed files with 13 additions and 12 deletions.
11 changes: 6 additions & 5 deletions pkg/kv/kvclient/kvstreamer/requests_provider.go
Original file line number Diff line number Diff line change
Expand Up @@ -188,6 +188,7 @@ func (r singleRangeBatch) String() string {
// We try to limit the size based on the number of requests ourselves, so
// this is just a sane upper-bound.
maxBytes := 10 << 10 /* 10KiB */
numScansInReqs := int64(len(r.reqs)) - r.numGetsInReqs
if len(r.reqs) > 10 {
// To keep the size of this log message relatively small, if we have
// more than 10 requests, then we only include the information about the
Expand All @@ -199,17 +200,17 @@ func (r singleRangeBatch) String() string {
subIdx = fmt.Sprintf("%v...%v", r.subRequestIdx[:headEndIdx], r.subRequestIdx[tailStartIdx:])
}
return fmt.Sprintf(
"{reqs:%v...%v pos:%v...%v subIdx:%s start:%v gets:%v reserved:%v overhead:%v minTarget:%v}",
"{reqs:%v...%v pos:%v...%v subIdx:%s gets:%v scans:%v reserved:%v overhead:%v minTarget:%v}",
kvpb.TruncatedRequestsString(r.reqs[:headEndIdx], maxBytes),
kvpb.TruncatedRequestsString(r.reqs[tailStartIdx:], maxBytes),
r.positions[:headEndIdx], r.positions[tailStartIdx:],
subIdx, r.isScanStarted, r.numGetsInReqs, r.reqsReservedBytes, r.overheadAccountedFor, r.minTargetBytes,
r.positions[:headEndIdx], r.positions[tailStartIdx:], subIdx, r.numGetsInReqs,
numScansInReqs, r.reqsReservedBytes, r.overheadAccountedFor, r.minTargetBytes,
)
}
return fmt.Sprintf(
"{reqs:%v pos:%v subIdx:%v start:%v gets:%v reserved:%v overhead:%v minTarget:%v}",
"{reqs:%v pos:%v subIdx:%v gets:%v scans:%v reserved:%v overhead:%v minTarget:%v}",
kvpb.TruncatedRequestsString(r.reqs, maxBytes), r.positions, r.subRequestIdx,
r.isScanStarted, r.numGetsInReqs, r.reqsReservedBytes, r.overheadAccountedFor, r.minTargetBytes,
r.numGetsInReqs, numScansInReqs, r.reqsReservedBytes, r.overheadAccountedFor, r.minTargetBytes,
)
}

Expand Down
14 changes: 7 additions & 7 deletions pkg/kv/kvclient/kvstreamer/streamer.go
Original file line number Diff line number Diff line change
Expand Up @@ -1490,6 +1490,13 @@ func (w *workerCoordinator) performRequestAsync(

// Finally, process the results and add the ResumeSpans to be
// processed as well.
log.VEventf(ctx, 2,
"responses:%d targetBytes:%d {footprint:%v overhead:%v resumeMem:%v gets:%v scans:%v incpGets:%v "+
"incpScans:%v startedScans:%v kvs:%v}",
len(br.Responses), targetBytes, fp.memoryFootprintBytes, fp.responsesOverhead,
fp.resumeReqsMemUsage, fp.numGetResults, fp.numScanResults, fp.numIncompleteGets,
fp.numIncompleteScans, fp.numStartedScans, fp.kvPairsRead,
)
processSingleRangeResponse(ctx, w.s, req, br, fp)
}); err != nil {
// The new goroutine for the request wasn't spun up, so we have to
Expand Down Expand Up @@ -1635,13 +1642,6 @@ func processSingleRangeResults(
br *kvpb.BatchResponse,
fp singleRangeBatchResponseFootprint,
) {
log.VEventf(ctx, 2,
"responses:%d {footprint:%v overhead:%v resumeMem:%v gets:%v scans:%v incpGets:%v "+
"incpScans:%v startedScans:%v kvs:%v}",
len(br.Responses), fp.memoryFootprintBytes, fp.responsesOverhead, fp.resumeReqsMemUsage,
fp.numGetResults, fp.numScanResults, fp.numIncompleteGets, fp.numIncompleteScans,
fp.numStartedScans, fp.kvPairsRead,
)
// If there are no results, this function has nothing to do.
if !fp.hasResults() {
log.VEvent(ctx, 2, "no results")
Expand Down

0 comments on commit ee28f87

Please sign in to comment.