Skip to content

Commit

Permalink
MB-41688 Reduce logging in metadata client (meta_client.go printstats())
Browse files Browse the repository at this point in the history
In meta_client.go printstats() function, change all of the messages to
Verbose level (which is between Info and Debug levels), except:

1. Keep "connected with %v indexers" message at Info level. (This is
   just one message per logging iteration, not one per index.)

2. For "client stats current" message, log a new message at Info level
   giving just the count of indexes with non-current stats. (This is
   also only one message per iteration.) The messages logging the ID
   and current/not current status of every index will change to Verbose
   level.

Also improved performance:

1. Skip all work for Verbose level if this level is not enabled.
2. Short-circuit isAllStatsCurrent() as soon as it finds a
   non-current stats.

Change-Id: I7289bccfbc5be2bfc30f604a7dbf0cbd9d7fdd9d
  • Loading branch information
cherkauer-couchbase committed Dec 24, 2020
1 parent 054d52d commit 9307ee1
Showing 1 changed file with 59 additions and 40 deletions.
99 changes: 59 additions & 40 deletions secondary/queryport/client/meta_client.go
Expand Up @@ -938,13 +938,12 @@ func (b *loadStats) updateStatsTime(partitionId common.PartitionId, value int64)
}

func (b *loadStats) isAllStatsCurrent() bool {

current := true
for _, stale := range b.staleCount {
current = current && stale < 10
if stale >= 10 {
return false
}
}

return current
return true
}

func (b *loadStats) isStatsCurrent(partitionId common.PartitionId) bool {
Expand Down Expand Up @@ -1375,53 +1374,73 @@ loop:
}

func (b *metadataClient) printstats() {

s := make([]string, 0, 16)
var s []string
currmeta := (*indexTopology)(atomic.LoadPointer(&b.indexers))
verbose := logging.IsEnabled(logging.Verbose)

logging.Infof("connected with %v indexers\n", len(currmeta.topology))
for id, replicas := range currmeta.replicas {
logging.Infof("index %v has replicas %v: \n", id, replicas)
}
for id, equivalents := range currmeta.equivalents {
logging.Infof("index %v has equivalents %v: \n", id, equivalents)
}
// currmeta.loads is immutable
for id, _ := range currmeta.insts {
load := currmeta.loads[id]
s = append(s, fmt.Sprintf(`"%v": %v`, id, load.getAvgLoad()))
}
logging.Infof("client load stats {%v}", strings.Join(s, ","))

s = make([]string, 0, 16)
for id, _ := range currmeta.insts {
load := currmeta.loads[id]
s = append(s, fmt.Sprintf(`"%v": %v`, id, load.getAvgHit()))
}
logging.Infof("client hit stats {%v}", strings.Join(s, ","))
if verbose {
for id, replicas := range currmeta.replicas {
logging.Verbosef("index %v has replicas %v: \n", id, replicas)
}
for id, equivalents := range currmeta.equivalents {
logging.Verbosef("index %v has equivalents %v: \n", id, equivalents)
}

s = make([]string, 0, 16)
for id, _ := range currmeta.insts {
load := currmeta.loads[id]
s = append(s, fmt.Sprintf(`"%v": %v`, id, load.getStats().getTotalPendingItems()))
}
logging.Infof("client pending item stats {%v}", strings.Join(s, ","))
// currmeta.loads is immutable
s = make([]string, 0, 16)
for id, _ := range currmeta.insts {
s = append(s, fmt.Sprintf(`"%v": %v`,
id, currmeta.loads[id].getAvgLoad()))
}
logging.Verbosef("client load stats {%v}", strings.Join(s, ","))

s = make([]string, 0, 16)
for id, _ := range currmeta.insts {
s = append(s, fmt.Sprintf(`"%v": %v`,
id, currmeta.loads[id].getAvgHit()))
}
logging.Verbosef("client hit stats {%v}", strings.Join(s, ","))

/*
s = make([]string, 0, 16)
for id, _ := range currmeta.insts {
load := currmeta.loads[id]
s = append(s, fmt.Sprintf(`"%v": %v`, id, load.getStats().getRollbackTime()))
s = append(s, fmt.Sprintf(`"%v": %v`,
id, currmeta.loads[id].getStats().getTotalPendingItems()))
}
logging.Infof("client rollback times {%v}", strings.Join(s, ","))
*/
logging.Verbosef("client pending item stats {%v}", strings.Join(s, ","))

/*
s = make([]string, 0, 16)
for id, _ := range currmeta.insts {
s = append(s, fmt.Sprintf(`"%v": %v`,
id, currmeta.loads[id].getStats().getRollbackTime()))
}
logging.Verbosef("client rollback times {%v}", strings.Join(s, ","))
*/
}

s = make([]string, 0, 16)
current := 0
notCurrent := 0
if verbose {
s = make([]string, 0, 16)
}
for id, _ := range currmeta.insts {
load := currmeta.loads[id]
s = append(s, fmt.Sprintf(`"%v": %v`, id, load.getStats().isAllStatsCurrent()))
isAllStatsCurrent := currmeta.loads[id].getStats().isAllStatsCurrent()
if isAllStatsCurrent {
current++
} else {
notCurrent++
}
if verbose {
s = append(s, fmt.Sprintf(`"%v": %v`, id, isAllStatsCurrent))
}
}
logging.Infof("client stats current counts: current: %v, not current: %v",
current, notCurrent)
if verbose {
logging.Verbosef("client stats current {%v}", strings.Join(s, ","))
}
logging.Infof("client stats current {%v}", strings.Join(s, ","))
}

// unprotected access to shared structures.
Expand Down

0 comments on commit 9307ee1

Please sign in to comment.