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

feat: add olog package #420

Merged
merged 29 commits into from
Feb 14, 2024
Merged

feat: add olog package #420

merged 29 commits into from
Feb 14, 2024

Conversation

jaredallard
Copy link
Contributor

@jaredallard jaredallard commented Dec 7, 2023

Adds a new olog package with the intent of replacing the existing log
package. Based off of the Go Observability Tooling design document1.

For those without access to that document, the main goals are encapsulated
below:

  • Uses *slog.Logger as the returned logging library (Highly recommended
    read about the library
    )
  • Loggers must be instantiated with New() before a log line can be emitted,
    there is no singleton provided by the olog package.
  • Packages should create their own logger(s) as required, storing it as a
    package-level global singleton for ease of use (however, loggers can also
    be created on the fly).
  • Default global logging level of Info, which all New() loggers respect.
    Ability to change log level at a module and package level. Adjustable
    through configuration while the process is still running.
  • Creating wrapped loggers using a provided *slog.Logger (ideally from
    New()) to enable Outreach-specific functionality, like audit logs.
  • Pretty printing of logs by default when os.Stderr is a TTY (local development).
  • Automatically log otel-logging compliant TraceID and SpanID if a context with
    trace information is passed to the logger.
    • This will require Context function calls to work.

Expected usage is calling New to create new logger per package. This should
be done either as a global variable per-package, or once per-package and passed
around.

Provides a test helper (NewTestCapturer) that enables callers to capture all log
output for the purpose of checking the output/result of certain operations via logs.
This is primarily intended to be used only for the development of the logger, since
logs are not a stable way to ensure an operation has occurred.

Footnotes

  1. https://outreach-io.atlassian.net/wiki/spaces/DT/pages/2853765388/Go+Observability+Tooling+Design#Logging

Jared Allard and others added 10 commits December 6, 2023 15:01
PoC implementation of a logger using `slog.Logger` as the primary type
with wrappers around it. Adds a global registry used for determining the
log level of a logger based on the module. Eventually, `New()` will
associate loggers with the current package and module name.

LogLevels can be set based on module or package name using the
`(*levelRegistry).Set` function.

While it would be more performant to store the `leveler` instances in
the registry and update those on `Set`, I feel that would complicate the
code. I also feel that a should a logger become a bottleneck in the
execution of an application, it should be removed in favor of tracing or
metrics gathering.
// implemented on that type instead of passing a logger around. If
// trying to set attributes the be logged by default, this is not
// supported without retaining the original association.
func New() *slog.Logger {
Copy link
Contributor

Choose a reason for hiding this comment

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

Should we preemptively pass functional options to this? Maybe even a context too? Just so we don't have to potentially change function signatures in the future. I guess functional options wouldn't change the signature anyways since those are usually variadic..

But another thing I wanted to call out was the inability to force format. Right now you can't override text/JSON format, it only decides based on environment. We should probably allow this to be overridable.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Overriding the default handler would be good! I'll add that.

Copy link
Contributor Author

@jaredallard jaredallard Dec 7, 2023

Choose a reason for hiding this comment

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

I think we should hold off on options because New() is meant to not be configured right now. Given we can add it without breaking anything later, I think we should hold off until we have a good reason to do so.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

As for NewWithHandler, that doesn't play into this much because that's very much so meant to be used only for tests (honestly, we might want to unexport it).

Copy link
Contributor

Choose a reason for hiding this comment

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

Yeah, given I don't see a particular reason to pass context in this New func and that options can be easily added later without really changing it's interface (at least users won't need any immediate change), I don't think this is something we need to immediately address. Also, a lot of what we might want to do as far as configuration can be handled with wrappers or methods if needed.

@jaredallard jaredallard marked this pull request as ready for review December 7, 2023 22:54
@jaredallard jaredallard requested a review from a team as a code owner December 7, 2023 22:54
@amhester
Copy link
Contributor

After doing a lot more digging into what's here, as well as looking into the goals of this more, it seems to me there are 2 things missing or incomplete as of now (though it's possible I'm missing something):

  1. Ability to configure log levels per module/package. The registry in this package seems to allow for the possibility of setting and checking of log levels by module/package. However, as far as I can tell, there is currently no way for a caller to actually configure the registry, not to mention that nothing in this package is really setting the global registry's map by default (again, that I can tell). This shouldn't be difficult to change, but would need to determine the best way to expose that functionality to users.
  2. The ability to automatically log otel-logging compliant TraceID and SpanID is also not provided by this package, though I feel it could easily add a convenient way for users to do so. Currently it's still possible by manually providing the extracted attributes on each logger instance, or by putting them on a logger per RPC call and persisting those attributes for every log/logger made during that call (slog.With(...)). But it would be nice to wrap the logging handlers to provide either automatic extraction of those context vars onto the log record (when context is provided), or by allowing hooks into that context/record before it sends and providing an out of the box otel extraction hook. The wrapper for this could be very light:
import (
    "context"
    "log/slog"

    "github.com/getoutreach/gobox/pkg/trace"
)

type ContextHandler struct {
	slog.Handler
}

func newContextHandler(handler slog.Handler) *ContextHandler {
	return &ContextHandler{Handler: handler}
}

func (ch *ContextHandler) Handle(ctx context.Context, r slog.Record) error {
	traceID := trace.ID(ctx)
	r.AddAttrs(slog.String("traceId", traceID))
	return ch.Handler.Handle(ctx, r)
}

Just an example

Copy link
Member

@malept malept left a comment

Choose a reason for hiding this comment

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

The ability to automatically log otel-logging compliant TraceID and SpanID is also not provided by this package

Since the otrace package is yet to be written, I would generally argue that this should be punted until that package has a design doc.

pkg/olog/README.md Outdated Show resolved Hide resolved
pkg/shuffler/suite.go Show resolved Hide resolved
@jaredallard
Copy link
Contributor Author

  1. Ability to configure log levels per module/package. The registry in this package seems to allow for the possibility of setting and checking of log levels by module/package. However, as far as I can tell, there is currently no way for a caller to actually configure the registry, not to mention that nothing in this package is really setting the global registry's map by default (again, that I can tell). This shouldn't be difficult to change, but would need to determine the best way to expose that functionality to users.

Yes, I never implemented that functionality (oops). It was meant to be hooked into stencil-golang such that configuration files could set it. Since the goal was for that to be done through configuration. Also then code would be added to the managed HTTP handler to support setting it at runtime, eventually either using a CLI or just a grpcurl to change it at runtime.

I can't touch on point 2 because I honestly don't remember the context, but figured I'd chime in on 1 since it's an OSS repo, so hi! 👋

amhester and others added 8 commits February 5, 2024 08:16
<!-- A short description of what your PR does and what it solves. -->
## What this PR does / why we need it

This PR attempts to address the issues/omissions noted
[here](#420 (comment)).
This PR provides an example implementation of a log handler wrapper
which provides callers with the ability to automatically add further
attributes to all logs written to that logger instance. This helps solve
for callers being able to easily and consistently add standard
information to all logs, especially with information that is usually on
the context or controlled by other tools (such as tracing information).
This package provides both a handler and Logger function by which to
provide these hooks, as well as an out-of-the-box hook for adding
AppInfo (which also required an addition to the `app` package to
implement the `slog.LogValuer` interface).

Ideally, this package would be a place where we could provide other
out-of-the-box hooks for other information such as tracing, actor, and
whatever else makes sense. However, there is also an argument that these
hooks could simply live in the packages which govern that data (i.e. the
AppInfo hook could live in the `app` package).

TODO: Expose global registry level setting. More info below:

In addition to this hooks package, I also added a potential way to
actually get/set the levels for different modules/packages using the
global level registry (currently not used or accessible from what I can
tell). Not sure if this is something we want to support, but I feel
could be nice to adjust required logging levels for different packages
for a variety of purposes (debugging, cost cutting, etc...).

<!-- Notes that may be helpful for anyone reviewing this PR -->
## Notes for your reviewers

This is just an example implementation and is written primarily to start
the discussion around how we want to handle this workflow, as the base
`olog` implementation doesn't easily allow for adding data to logs,
especially from context (the `olog` log handler is not exposed in any
way). While a lot of this functionality could be provided by developers
in each of their funcs which are called per request/transaction, it
would be cumbersome and easily missed. That being said, there are a
number of points I think are worth discussing regarding this
implementation and I'd like thoughts on:

1. Should the hooks implementation (the handler which wraps the default
global handler and allows for hooks) reside in the `olog` package
directly instead of this `hooks` sub-package? The more I think about
this, the more I'm inclined to think it should, and then be exposed as
options on the `New` func. The options would basically just allow for
hook funcs to be provided similar to the `Logger` func provided by this
hooks package. However, I wanted to keep these concepts isolated for
now, which is why I chose to implement it in a separate package.
Thoughts?
2. Should the provided hook funcs live in this hooks package, or should
they simply live with their related domain. For example, this PR
provides an `AppInfo` hook for extracting and adding AppInfo data to the
logs, but should this hook just live in the `app` package?
3. Is this hooks pattern something we're comfortable with? It seems a
natural way to me to augment the log records automatically, but am open
to other patterns to accomplish this.

### Global registry level setting

Not sure if this is something we necessarily want/need to support,
especially in the near-term, but since it was noted as a goal (*[Ability
to change log level at a module and package
level.](#420 (comment)),
I felt it should probably be addressed or at least discussed. However, I
can't quite determine a great solution for this as of yet. I don't think
wholly exposing the entire global level registry necessarily makes
sense, and I personally think having users set levels by key where the
key is either some package or module name is also not that great of an
experience (what specifically is a module or package name key? You can
only really know for sure when looking under the hood at the
implementation). 2 possible ways to help ease the usage of the global
registry could be (but I'm not sold on either tbh):

1. Providing an iterator func to allow users to search all registered
packages/modules and determine what they want to do from there. This
iterator could even probably pass a level setting func to provide a
controlled and succinct way to set those levels per package. However,
this would be cumbersome and doesn't really help the problem of making
the registry and its keys both accessible and understandable. Also, as
is, the global registry isn't actually getting set when a package
creates a new logger. This is probably just not a good way to go.
2. Have each package which plans on using `olog`/`slog` to expose their
module/package names (as determined by the `olog` package) as package
vars. Then any called could simply use these vars when accessing
(set/get'ing) the global registry and not need to care about the actual
format of the keys for those packages/modules. However, this then puts
the burden on those packages to always expose this information, which
also isn't necessarily great.

Also, I could just be over-thinking this and it could be entirely
reasonable for people to know what the key for any given package/module
will be, and use that to directly access to registry. May not be too bad
if given proper documentation for expected format. Thoughts?

---------

Co-authored-by: Devbase CI <[email protected]>
This adds a `ometrics` package (as a sub-module, more on that later)
aimed at configuring the global otel.MeterProvider. This allows
consumers to instrument metrics through the standard otel metrics
package. The ideal usage is below:

```go
// main.go
ometrics.InitializeMeterProvider(ctx, ExporterTypePrometheus)

// every single package that exports metrics.
var meter otel.GetMeterProvider().Meter("packageName")

func doAThing() {
  counter, err := meter.Float64Counter("my_counter", api.WithDescription("counts a thing"))
  if err != nil {}
  counter.Add(ctx, 5)
}
```

**Note**: Yes, there is not a notion of package global metrics like
Prometheus had. Metrics have to be instrumented in a function and then
passed along to whatever consumes them. That was a design decision by
otel maintainers.

There's some open questions in comments in the code that I was unable to
get to as well as future direction. For example, to fully support the
collector exporter (push) there needs to be configuration instrumented.
It's up to the future implementor to decide how that should be done.
Though, I would suggest not utilizing environment variables for it :)

This is added a sub-module because the otel dependencies have been
_very_ painful in the past, so I'd like to avoid proliferating them to
every project that consumes `gobox`. Otherwise, just sourcing `pkg/app`
can break an application today.

---------

Co-authored-by: Professor X <[email protected]>
Co-authored-by: Mark Lee <[email protected]>
@amhester amhester merged commit 1b95767 into main Feb 14, 2024
3 of 4 checks passed
@amhester amhester deleted the jaredallard/feat/olog branch February 14, 2024 17:19
@getoutreach-ci-1
Copy link
Contributor

🎉 This PR is included in version 1.88.0 🎉

The release is available on GitHub release

Your semantic-release bot 📦🚀

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants