Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[slogger] Replace logger with slogger in dataflatten/exec #1612

Merged
13 changes: 12 additions & 1 deletion cmd/launcher/interactive.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import (
"errors"
"flag"
"fmt"
"log/slog"
"os"
"strings"

Expand All @@ -14,6 +15,7 @@ import (
"github.com/kolide/launcher/ee/tuf"
"github.com/kolide/launcher/pkg/autoupdate"
"github.com/kolide/launcher/pkg/launcher"
"github.com/kolide/launcher/pkg/log/multislogger"
"github.com/kolide/launcher/pkg/osquery/interactive"
)

Expand All @@ -34,6 +36,15 @@ func runInteractive(args []string) error {

logger := logutil.NewServerLogger(*flDebug)

slogLevel := slog.LevelInfo
if *flDebug {
slogLevel = slog.LevelDebug
}

slogger := multislogger.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
Level: slogLevel,
})).Logger

osquerydPath := *flOsquerydPath
if osquerydPath == "" {
latestOsquerydBinary, err := tuf.CheckOutLatestWithoutConfig("osqueryd", logger)
Expand Down Expand Up @@ -80,7 +91,7 @@ func runInteractive(args []string) error {
flOsqueryFlags = append(flOsqueryFlags, fmt.Sprintf("tls_server_certs=%s", certs))
}

osqueryProc, extensionsServer, err := interactive.StartProcess(logger, rootDir, osquerydPath, flOsqueryFlags)
osqueryProc, extensionsServer, err := interactive.StartProcess(slogger, rootDir, osquerydPath, flOsqueryFlags)
if err != nil {
return fmt.Errorf("error starting osqueryd: %s", err)
}
Expand Down
9 changes: 5 additions & 4 deletions ee/dataflatten/examples/flatten/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,8 @@ import (
"strings"
"text/tabwriter"

"github.com/kolide/kit/logutil"
"github.com/kolide/launcher/ee/dataflatten"
"github.com/kolide/launcher/pkg/log/multislogger"
"github.com/peterbourgon/ff/v3"
)

Expand Down Expand Up @@ -40,13 +40,14 @@ func main() {
checkError(fmt.Errorf("parsing flags: %w", err))
}

logger := logutil.NewCLILogger(*flDebug)

opts := []dataflatten.FlattenOpts{
dataflatten.WithLogger(logger),
dataflatten.WithSlogger(multislogger.New().Logger),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is example code. It feels slightly weirf to pass multislogger. Can we pass a simple slogger instead?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is what we tend to copy-paste everywhere we need an unused slogger -- e.g. it's all over our unit tests. I'm not sure that this is wrong.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤷

dataflatten.WithNestedPlist(),
dataflatten.WithQuery(strings.Split(*flQuery, `/`)),
}
if *flDebug {
opts = append(opts, dataflatten.WithDebugLogging())
}

rows := []dataflatten.Row{}

Expand Down
125 changes: 83 additions & 42 deletions ee/dataflatten/flatten.go
Original file line number Diff line number Diff line change
Expand Up @@ -39,16 +39,17 @@ package dataflatten

import (
"bytes"
"context"
"encoding/base64"
"fmt"
"log/slog"
"strconv"
"strings"
"time"
"unicode/utf8"

"github.com/go-kit/kit/log"
"github.com/go-kit/kit/log/level"
"github.com/groob/plist"
"github.com/kolide/launcher/pkg/log/multislogger"

howett "howett.net/plist"
)
Expand All @@ -66,16 +67,21 @@ import (
// It can optionally filtering and rewriting.
type Flattener struct {
debugLogging bool
logLevel slog.Level // the level that logs should be logged at
expandNestedPlist bool
includeNestedRaw bool
includeNils bool
logger log.Logger
slogger *slog.Logger
query []string
queryKeyDenoter string
queryWildcard string
rows []Row
}

// levelFlattenDebug is a log level below debug, so that we discard debugging logs
// that we only want for development purposes.
const levelFlattenDebug = slog.LevelDebug - 1

type FlattenOpts func(*Flattener)

// IncludeNulls indicates that Flatten should return null values,
Expand All @@ -93,21 +99,21 @@ func WithNestedPlist() FlattenOpts {
}
}

// WithLogger sets the logger to use
func WithLogger(logger log.Logger) FlattenOpts {
if logger == nil {
// WithSlogger sets the slogger to use
func WithSlogger(slogger *slog.Logger) FlattenOpts {
if slogger == nil {
return func(_ *Flattener) {}
}

return func(fl *Flattener) {
fl.logger = logger
fl.slogger = slogger
}
}

// WithDebugLogging enables debug logging. With debug logs,
// dataflatten is very verbose. This can overwhelm the other launcher
// logs. As we're not generally debugging this library, the default is
// to not enable debug logging.
// WithDebugLogging enables debug logging intended for development use.
// With debug logs, dataflatten is very verbose. This can overwhelm the
// other launcher logs. As we're not generally debugging this library,
// the default is to not enable debug logging.
func WithDebugLogging() FlattenOpts {
return func(fl *Flattener) {
fl.debugLogging = true
Expand All @@ -131,7 +137,8 @@ func WithQuery(q []string) FlattenOpts {
func Flatten(data interface{}, opts ...FlattenOpts) ([]Row, error) {
fl := &Flattener{
rows: []Row{},
logger: log.NewNopLogger(),
logLevel: levelFlattenDebug, // by default, log at a level below debug
slogger: multislogger.New().Logger,
queryWildcard: `*`,
queryKeyDenoter: `#`,
}
Expand All @@ -140,8 +147,8 @@ func Flatten(data interface{}, opts ...FlattenOpts) ([]Row, error) {
opt(fl)
}

if !fl.debugLogging {
fl.logger = level.NewFilter(fl.logger, level.AllowInfo())
if fl.debugLogging {
fl.logLevel = slog.LevelDebug
}
Comment on lines +150 to 152
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suspect we could drop this, and simply log everything at at levelFlattenDebug and let the caller apply the appropriate filter. But 🤷 maybe better to merge

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I liked this because it works the same way it used to 🤷‍♀️


if err := fl.descend([]string{}, data, 0); err != nil {
Expand All @@ -155,10 +162,10 @@ func Flatten(data interface{}, opts ...FlattenOpts) ([]Row, error) {
func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
queryTerm, isQueryMatched := fl.queryAtDepth(depth)

logger := log.With(fl.logger,
slogger := fl.slogger.With(
"caller", "descend",
"depth", depth,
"rows-so-far", len(fl.rows),
"rows_so_far", len(fl.rows),
"query", queryTerm,
"path", strings.Join(path, "/"),
)
Expand All @@ -167,7 +174,10 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
case []interface{}:
for i, e := range v {
pathKey := strconv.Itoa(i)
level.Debug(logger).Log("msg", "checking an array", "indexStr", pathKey)
slogger.Log(context.TODO(), fl.logLevel,
"checking an array",
"index_str", pathKey,
)

// If the queryTerm starts with
// queryKeyDenoter, then we want to rewrite
Expand All @@ -183,33 +193,44 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
keyQuery := strings.SplitN(strings.TrimPrefix(queryTerm, fl.queryKeyDenoter), "=>", 2)
keyName := keyQuery[0]

innerlogger := log.With(logger, "arraykeyname", keyName)
level.Debug(logger).Log("msg", "attempting to coerce array into map")
innerslogger := slogger.With("array_key_name", keyName)
innerslogger.Log(context.TODO(), fl.logLevel,
"attempting to coerce array into map",
)

e, ok := e.(map[string]interface{})
if !ok {
level.Debug(innerlogger).Log("msg", "can't coerce into map")
innerslogger.Log(context.TODO(), fl.logLevel,
"can't coerce into map",
)
continue
}

// Is keyName in this array?
val, ok := e[keyName]
if !ok {
level.Debug(innerlogger).Log("msg", "keyName not in map")
innerslogger.Log(context.TODO(), fl.logLevel,
"keyName not in map",
"key_name", keyName,
)
continue
}

pathKey, ok = val.(string)
if !ok {
level.Debug(innerlogger).Log("msg", "can't coerce pathKey val into string")
innerslogger.Log(context.TODO(), fl.logLevel,
"can't coerce pathKey val into string",
)
continue
}

// Looks good to descend. we're overwritten both e and pathKey. Exit this conditional.
}

if !(isQueryMatched || fl.queryMatchArrayElement(e, i, queryTerm)) {
level.Debug(logger).Log("msg", "query not matched")
slogger.Log(context.TODO(), fl.logLevel,
"query not matched",
)
continue
}

Expand All @@ -218,7 +239,9 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
}
}
case map[string]interface{}:
level.Debug(logger).Log("msg", "checking a map")
slogger.Log(context.TODO(), fl.logLevel,
"checking a map",
)
for k, e := range v {
// Check that the key name matches. If not, skip this entire
// branch of the map
Expand All @@ -231,7 +254,9 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
}
}
case []map[string]interface{}:
level.Debug(logger).Log("msg", "checking an array of maps")
slogger.Log(context.TODO(), fl.logLevel,
"checking an array of maps",
)
for i, e := range v {
if err := fl.descend(append(path, strconv.Itoa(i)), e, depth+1); err != nil {
return fmt.Errorf("flattening array of maps: %w", err)
Expand All @@ -240,7 +265,9 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
case nil:
// Because we want to filter nils out, we do _not_ examine isQueryMatched here
if !(fl.queryMatchNil(queryTerm)) {
level.Debug(logger).Log("msg", "query not matched")
slogger.Log(context.TODO(), fl.logLevel,
"query not matched",
)
return nil
}
fl.rows = append(fl.rows, NewRow(path, ""))
Expand All @@ -250,7 +277,7 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
// Most string like data comes in this way
return fl.descendMaybePlist(path, v, depth)
default:
if err := fl.handleStringLike(logger, path, v, depth); err != nil {
if err := fl.handleStringLike(slogger, path, v, depth); err != nil {
return fmt.Errorf("flattening at path %v: %w", path, err)
}
}
Expand All @@ -260,7 +287,7 @@ func (fl *Flattener) descend(path []string, data interface{}, depth int) error {
// handleStringLike is called when we finally have an object we think
// can be converted to a string. It uses the depth to compare against
// the query, and returns a stringify'ed value
func (fl *Flattener) handleStringLike(logger log.Logger, path []string, v interface{}, depth int) error {
func (fl *Flattener) handleStringLike(slogger *slog.Logger, path []string, v interface{}, depth int) error {
queryTerm, isQueryMatched := fl.queryAtDepth(depth)

stringValue, err := stringify(v)
Expand All @@ -269,7 +296,9 @@ func (fl *Flattener) handleStringLike(logger log.Logger, path []string, v interf
}

if !(isQueryMatched || fl.queryMatchString(stringValue, queryTerm)) {
level.Debug(logger).Log("msg", "query not matched")
slogger.Log(context.TODO(), fl.logLevel,
"query not matched",
)
return nil
}

Expand All @@ -281,37 +310,45 @@ func (fl *Flattener) handleStringLike(logger log.Logger, path []string, v interf
// embedded plist. In the case of failures, it falls back to treating
// it like a plain string.
func (fl *Flattener) descendMaybePlist(path []string, data []byte, depth int) error {
logger := log.With(fl.logger,
slogger := fl.slogger.With(
"caller", "descendMaybePlist",
"depth", depth,
"rows-so-far", len(fl.rows),
"rows_so_far", len(fl.rows),
"path", strings.Join(path, "/"),
)

// Skip if we're not expanding nested plists
if !fl.expandNestedPlist {
return fl.handleStringLike(logger, path, data, depth)
return fl.handleStringLike(slogger, path, data, depth)
}

// Skip if this doesn't look like a plist.
if !isPlist(data) {
return fl.handleStringLike(logger, path, data, depth)
return fl.handleStringLike(slogger, path, data, depth)
}

// Looks like a plist. Try parsing it
level.Debug(logger).Log("msg", "Parsing inner plist")
slogger.Log(context.TODO(), fl.logLevel,
"parsing inner plist",
)

var innerData interface{}

if err := plist.Unmarshal(data, &innerData); err != nil {
level.Info(logger).Log("msg", "plist parsing failed", "err", err)
return fl.handleStringLike(logger, path, data, depth)
slogger.Log(context.TODO(), slog.LevelInfo,
"plist parsing failed",
"err", err,
)
return fl.handleStringLike(slogger, path, data, depth)
}

// have a parsed plist. Descend and return from here.
if fl.includeNestedRaw {
if err := fl.handleStringLike(logger, append(path, "_raw"), data, depth); err != nil {
level.Error(logger).Log("msg", "Failed to add _raw key", "err", err)
if err := fl.handleStringLike(slogger, append(path, "_raw"), data, depth); err != nil {
slogger.Log(context.TODO(), slog.LevelError,
"failed to add _raw key",
"err", err,
)
}
}

Expand All @@ -337,9 +374,9 @@ func (fl *Flattener) queryMatchNil(queryTerm string) bool {
// We use `=>` as something that is reasonably intuitive, and not very
// likely to occur on it's own. Unfortunately, `==` shows up in base64
func (fl *Flattener) queryMatchArrayElement(data interface{}, arrIndex int, queryTerm string) bool {
logger := log.With(fl.logger,
slogger := fl.slogger.With(
"caller", "queryMatchArrayElement",
"rows-so-far", len(fl.rows),
"rows_so_far", len(fl.rows),
"query", queryTerm,
"arrIndex", arrIndex,
)
Expand All @@ -353,11 +390,15 @@ func (fl *Flattener) queryMatchArrayElement(data interface{}, arrIndex int, quer

// If the queryTerm is an int, then we expect to match the index
if queryIndex, err := strconv.Atoi(queryTerm); err == nil {
level.Debug(logger).Log("msg", "using numeric index comparison")
slogger.Log(context.TODO(), fl.logLevel,
"using numeric index comparison",
)
return queryIndex == arrIndex
}

level.Debug(logger).Log("msg", "checking data type")
slogger.Log(context.TODO(), fl.logLevel,
"checking data type",
)

switch dataCasted := data.(type) {
case []interface{}:
Expand Down
Loading
Loading