From b6e6cde589546e97011eb91e9cc1643951b31f41 Mon Sep 17 00:00:00 2001
From: Peter Mattis <petermattis@gmail.com>
Date: Mon, 16 Dec 2019 07:35:31 -0500
Subject: [PATCH] storage/engine: small logging fixes

Change `Pebble.GetCompactionStats` to be prefixed with a newline to
match the formatting of RocksDB. This ensures that the compaction stats
display will not contain the log prefix which was misaligning the table
header.

Adding a missing sort to `Pebble.GetSSTables`. This was causing the
sstable summary log message to be much busier than for RocksDB because
`SSTableInfos.String` expects the infos to be sorted.

Move the formatting of `estimated_pending_compaction_bytes: x` into
`RocksDB.GetCompactionStats`. The Pebble compaction stats already
included this and it is useful to see the estimated pending compaction
bytes whenever the compaction stats are output.

Release note: None
---
 pkg/storage/engine/pebble.go  | 8 +++++++-
 pkg/storage/engine/rocksdb.go | 9 ++++++++-
 pkg/storage/store.go          | 4 +---
 3 files changed, 16 insertions(+), 5 deletions(-)

diff --git a/pkg/storage/engine/pebble.go b/pkg/storage/engine/pebble.go
index d4bced4c94b7..c6e073eb5146 100644
--- a/pkg/storage/engine/pebble.go
+++ b/pkg/storage/engine/pebble.go
@@ -17,6 +17,7 @@ import (
 	"io"
 	"io/ioutil"
 	"os"
+	"sort"
 
 	"github.com/cockroachdb/cockroach/pkg/base"
 	"github.com/cockroachdb/cockroach/pkg/roachpb"
@@ -487,7 +488,10 @@ func (p *Pebble) Get(key MVCCKey) ([]byte, error) {
 
 // GetCompactionStats implements the Engine interface.
 func (p *Pebble) GetCompactionStats() string {
-	return p.db.Metrics().String()
+	// NB: The initial blank line matches the formatting used by RocksDB and
+	// ensures that compaction stats display will not contain the log prefix
+	// (this method is only used for logging purposes).
+	return "\n" + p.db.Metrics().String()
 }
 
 // GetTickersAndHistograms implements the Engine interface.
@@ -879,6 +883,8 @@ func (p *Pebble) GetSSTables() (sstables SSTableInfos) {
 			sstables = append(sstables, info)
 		}
 	}
+
+	sort.Sort(sstables)
 	return sstables
 }
 
diff --git a/pkg/storage/engine/rocksdb.go b/pkg/storage/engine/rocksdb.go
index fe3fceae3037..1360e7f70cc2 100644
--- a/pkg/storage/engine/rocksdb.go
+++ b/pkg/storage/engine/rocksdb.go
@@ -33,6 +33,7 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/util"
 	"github.com/cockroachdb/cockroach/pkg/util/envutil"
 	"github.com/cockroachdb/cockroach/pkg/util/hlc"
+	"github.com/cockroachdb/cockroach/pkg/util/humanizeutil"
 	"github.com/cockroachdb/cockroach/pkg/util/log"
 	"github.com/cockroachdb/cockroach/pkg/util/protoutil"
 	"github.com/cockroachdb/cockroach/pkg/util/syncutil"
@@ -1261,7 +1262,13 @@ func (r *RocksDB) GetTickersAndHistograms() (*enginepb.TickersAndHistograms, err
 // GetCompactionStats returns the internal RocksDB compaction stats. See
 // https://github.com/facebook/rocksdb/wiki/RocksDB-Tuning-Guide#rocksdb-statistics.
 func (r *RocksDB) GetCompactionStats() string {
-	return cStringToGoString(C.DBGetCompactionStats(r.rdb))
+	s := cStringToGoString(C.DBGetCompactionStats(r.rdb)) +
+		"estimated_pending_compaction_bytes: "
+	stats, err := r.GetStats()
+	if err != nil {
+		return s + err.Error()
+	}
+	return s + humanizeutil.IBytes(stats.PendingCompactionBytesEstimate)
 }
 
 // GetEnvStats returns stats for the RocksDB env. This may include encryption stats.
diff --git a/pkg/storage/store.go b/pkg/storage/store.go
index 1cd6704c47b7..5399fba51785 100644
--- a/pkg/storage/store.go
+++ b/pkg/storage/store.go
@@ -53,7 +53,6 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/util/contextutil"
 	"github.com/cockroachdb/cockroach/pkg/util/envutil"
 	"github.com/cockroachdb/cockroach/pkg/util/hlc"
-	"github.com/cockroachdb/cockroach/pkg/util/humanizeutil"
 	"github.com/cockroachdb/cockroach/pkg/util/limit"
 	"github.com/cockroachdb/cockroach/pkg/util/log"
 	"github.com/cockroachdb/cockroach/pkg/util/metric"
@@ -2354,8 +2353,7 @@ func (s *Store) ComputeMetrics(ctx context.Context, tick int) error {
 	// stats.
 	if tick%logSSTInfoTicks == 1 /* every 10m */ {
 		log.Infof(ctx, "sstables (read amplification = %d):\n%s", readAmp, sstables)
-		log.Infof(ctx, "%sestimated_pending_compaction_bytes: %s",
-			s.engine.GetCompactionStats(), humanizeutil.IBytes(stats.PendingCompactionBytesEstimate))
+		log.Infof(ctx, "%s", s.engine.GetCompactionStats())
 	}
 	return nil
 }