Skip to content

Commit

Permalink
keyspan: use treeprinter for iterator stack logging
Browse files Browse the repository at this point in the history
The treeprinter library was lifted from cockroach without changes.

Sample output: https://gist.github.com/RaduBerinde/cc744c9922868740169cd670bfdb8b2a
  • Loading branch information
RaduBerinde committed Jan 10, 2024
1 parent 05f00a2 commit 3171a93
Show file tree
Hide file tree
Showing 4 changed files with 624 additions and 49 deletions.
32 changes: 21 additions & 11 deletions internal/keyspan/logging_iter.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,9 +6,9 @@ package keyspan

import (
"fmt"
"strings"

"github.com/cockroachdb/pebble/internal/base"
"github.com/cockroachdb/pebble/internal/treeprinter"
)

// WrapFn is the prototype for a function that wraps a FragmentIterator.
Expand All @@ -19,8 +19,7 @@ type WrapFn func(in FragmentIterator) FragmentIterator
func InjectLogging(iter FragmentIterator, logger base.Logger) FragmentIterator {
// All iterators in the stack will use the same logging state.
state := &loggingState{
depth: 0,
log: logger,
log: logger,
}
var wrap WrapFn
wrap = func(in FragmentIterator) FragmentIterator {
Expand Down Expand Up @@ -52,23 +51,34 @@ type loggingIter struct {

// loggingState is shared by all iterators in a stack.
type loggingState struct {
depth int
log base.Logger
node treeprinter.Node
log base.Logger
}

func (i *loggingIter) opStartf(format string, args ...any) func(results ...any) {
savedNode := i.state.node

n := i.state.node
topLevelOp := false
if n == (treeprinter.Node{}) {
n = treeprinter.New()
topLevelOp = true
}
op := fmt.Sprintf(format, args...)
msg := fmt.Sprintf("%s%s %s", strings.Repeat(" ", i.state.depth), i.context, op)

i.state.log.Infof("%s", msg)
savedDepth := i.state.depth
i.state.depth++
child := n.Childf("%s %s", i.context, op)
i.state.node = child

return func(results ...any) {
i.state.depth = savedDepth
if len(results) > 0 {
i.state.log.Infof("%s = %s", msg, fmt.Sprint(results...))
child.Childf("%s", fmt.Sprint(results...))
}
if topLevelOp {
for _, row := range n.FormattedRows() {
i.state.log.Infof("%s\n", row)
}
}
i.state.node = savedNode
}
}

Expand Down
76 changes: 38 additions & 38 deletions internal/keyspan/testdata/logging_iter
Original file line number Diff line number Diff line change
Expand Up @@ -15,39 +15,39 @@ last
prev
----
*keyspan.assertIter: SeekGE("a")
*keyspan.Iter: SeekGE("a")
*keyspan.Iter: SeekGE("a") = a-b:{(#2,SET) (#1,SET)}
*keyspan.assertIter: SeekGE("a") = a-b:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: SeekGE("a")
│ └── a-b:{(#2,SET) (#1,SET)}
└── a-b:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next()
*keyspan.Iter: Next()
*keyspan.Iter: Next() = b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next() = b-c:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Next()
│ └── b-c:{(#2,SET) (#1,SET)}
└── b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next()
*keyspan.Iter: Next()
*keyspan.Iter: Next() = c-d:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next() = c-d:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Next()
│ └── c-d:{(#2,SET) (#1,SET)}
└── c-d:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Prev()
*keyspan.Iter: Prev()
*keyspan.Iter: Prev() = b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Prev() = b-c:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Prev()
│ └── b-c:{(#2,SET) (#1,SET)}
└── b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: First()
*keyspan.Iter: First()
*keyspan.Iter: First() = a-b:{(#2,SET) (#1,SET)}
*keyspan.assertIter: First() = a-b:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: First()
│ └── a-b:{(#2,SET) (#1,SET)}
└── a-b:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next()
*keyspan.Iter: Next()
*keyspan.Iter: Next() = b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next() = b-c:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Next()
│ └── b-c:{(#2,SET) (#1,SET)}
└── b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Last()
*keyspan.Iter: Last()
*keyspan.Iter: Last() = c-d:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Last() = c-d:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Last()
│ └── c-d:{(#2,SET) (#1,SET)}
└── c-d:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Prev()
*keyspan.Iter: Prev()
*keyspan.Iter: Prev() = b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Prev() = b-c:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Prev()
│ └── b-c:{(#2,SET) (#1,SET)}
└── b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Close()
*keyspan.Iter: Close()
└── *keyspan.Iter: Close()

iter
seek-lt a
Expand All @@ -56,20 +56,20 @@ next
next
----
*keyspan.assertIter: SeekLT("a")
*keyspan.Iter: SeekLT("a")
*keyspan.Iter: SeekLT("a") = <nil>
*keyspan.assertIter: SeekLT("a") = <nil>
├── *keyspan.Iter: SeekLT("a")
│ └── <nil>
└── <nil>
*keyspan.assertIter: SeekLT("c")
*keyspan.Iter: SeekLT("c")
*keyspan.Iter: SeekLT("c") = b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: SeekLT("c") = b-c:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: SeekLT("c")
│ └── b-c:{(#2,SET) (#1,SET)}
└── b-c:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next()
*keyspan.Iter: Next()
*keyspan.Iter: Next() = c-d:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next() = c-d:{(#2,SET) (#1,SET)}
├── *keyspan.Iter: Next()
│ └── c-d:{(#2,SET) (#1,SET)}
└── c-d:{(#2,SET) (#1,SET)}
*keyspan.assertIter: Next()
*keyspan.Iter: Next()
*keyspan.Iter: Next() = <nil>
*keyspan.assertIter: Next() = <nil>
├── *keyspan.Iter: Next()
│ └── <nil>
└── <nil>
*keyspan.assertIter: Close()
*keyspan.Iter: Close()
└── *keyspan.Iter: Close()
Loading

0 comments on commit 3171a93

Please sign in to comment.