doc/dev: raise prominence of logtest.Scoped, make more tweaks (#37282)

This commit is contained in:
Robert Lin 2022-06-17 10:44:06 -07:00 committed by GitHub
parent 7e4e8c4370
commit c0a5f3eb3a
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 45 additions and 30 deletions

View File

@ -65,7 +65,16 @@ func main() {
}
```
Once initialized, you can use `log.Scoped()` to create some top-level loggers to propagate, from which you can:
### Basic conventions
- The logger parameter should either be immediately after `ctx context.Context`, or be the first parameter.
- In some cases there might already be a `log` module imported. Use the alias `sglog` to refer to `github.com/sourcegraph/log`, for example `import sglog "github.com/sourcegraph/log"`.
- When testing, provide [test loggers](#testing-usage) for improved output management.
- For more conventions, see relevant subsections in this guide, such as [top-level loggers](#top-level-loggers), [sub-loggers](#sub-loggers), and [writing log messages](#writing-log-messages).
### Top-level loggers
Once initialized, you can use `log.Scoped()` to create some top-level loggers to propagate. From each logger, you can:
- [create sub-loggers](#sub-loggers)
- [write log entries](#writing-log-messages)
@ -74,11 +83,6 @@ The first top-level scoped logger is typically `"server"`, since most logging is
Background jobs, etc. can have additional top-level loggers created that better describe each components.
### Basic conventions
- The logger parameter should either be immediately after `ctx context.Context`, or be the first parameter.
- In some cases there might already be a `log` module imported. Use the alias `sglog` to refer to `github.com/sourcegraph/log`, for example `import sglog "github.com/sourcegraph/log"`.
### Sub-loggers
When your service starts logging, obtain a `log.Logger` instance, attach some relevant context, and start propagating your logger for use.
@ -93,7 +97,7 @@ Using sub-loggers allows you to easily trace, for example, the execution of an e
#### Scoped loggers
Scopes are used to identify the component of a system a log message comes from, and generally should provide enough information for an uninitiated reader (such as a new teammate, or a Sourcegraph administrator) to get a rough idea the context in which a log message might have occured.
Scopes are used to identify the component of a system a log message comes from, and generally should provide enough information for an uninitiated reader (such as a new teammate, or a Sourcegraph administrator) to get a rough idea the context in which a log message might have occurred.
There are several ways to create scoped loggers:
@ -105,8 +109,9 @@ In general:
- From the caller, only add a scope if, as a caller, you care that the log output enough to want to differentiate it
- For example, if you create multiple clients for a service, you will probably want to create a separate scoped logger for each
- From the callee, add a scope if you will be logging output that should be meaningfully differentiated (e.g. inside a client, or inside a significant helper function)
- Scope names should be `CamelCase` or `camelCase`, and the scope description should follow [the same conventions as a log message](#writing-log-messages).
Scope names should be `CamelCase` or `camelCase`, and the scope description should follow [the same conventions as a log message](#writing-log-messages).
Example:
```go
func NewClient() *Client {
@ -252,28 +257,14 @@ Additionally, in `SRC_DEVELOPMENT=true` using `log.Scoped` without calling `log.
For testing purposes, we also provide:
1. An optional initialization function to be called in `func TestMain(*testing.M)`, [`logtest.Init`](https://sourcegraph.com/search?q=context:global+repo:%5Egithub%5C.com/sourcegraph/sourcegraph%24+logtest.Init+lang:go&patternType=literal)
2. A getter to retrieve a `log.Logger` instance and a callback to programmatically iterate log output, [`logtest.Scoped`](https://sourcegraph.com/search?q=context:global+repo:%5Egithub%5C.com/sourcegraph/sourcegraph%24+logtest.Scoped+lang:go&patternType=literal)
1. A getter to retrieve a `log.Logger` instance and a callback to programmatically iterate log output, [`logtest.Scoped`](https://sourcegraph.com/search?q=context:global+repo:%5Egithub%5C.com/sourcegraph/sourcegraph%24+logtest.Scoped+lang:go&patternType=literal)
1. The standard `log.Scoped` will also work after `logtest.Init`
2. Programatically iterable logs are available from the `logtest.Captured` logger instance
3. Can be provided in code that accepts [injected loggers](#injected-loggers)
2. An *optional* initialization function to be called in `func TestMain(*testing.M)`, [`logtest.Init`](https://sourcegraph.com/search?q=context:global+repo:%5Egithub%5C.com/sourcegraph/sourcegraph%24+logtest.Init+lang:go&patternType=literal).
1. Useful for testing code that [*does not* accept injected loggers](#instantiated-loggers)
In the absense of `log.Init` in `main()`, `github.com/sourcegraph/log` can be initialized using `libtest` in packages that use `log.Scoped`:
```go
import (
"os"
"testing"
"github.com/sourcegraph/log/logtest"
)
func TestMain(m *testing.M) {
logtest.Init(m)
os.Exit(m.Run())
}
```
You can control the log level used during initialization with `logtest.InitWithLevel`.
### Injected loggers
If the code you are testing accepts `Logger` instances as a parameter, you can skip the above and simply use `logtest.Scoped` to instantiate a `Logger` to provide. You can also use `logtest.Captured`, which also provides a callback for exporting logs, though be wary of making overly strict assertions on log entries to avoid brittle tests:
@ -298,4 +289,24 @@ func TestFooBar(t *testing.T) {
When writing a test, ensure that `logtest.Scope` in the tightest scope possible. This ensures that if a test fails, that the logging is closely tied to the test that failed. Especially if you testcase has sub tests with `t.Run`, prefer to created the test logger inside `t.Run`.
If you can provide a `Logger` instance, `logtest.NoOp()` can be used to silence output. Levels can also be adjusted using `(Logger).IncreaseLevel`.
Alternatively, `logtest.NoOp()` creates a logger that can be used to silence output. Levels can also be adjusted using `(Logger).IncreaseLevel`.
### Instantiated loggers
In the absense of `log.Init` in `main()`, testing code that instantiates loggers with `log.Scoped` (as opposed to `(Logger).Scoped`), `github.com/sourcegraph/log` can be initialized using `libtest` in packages that use `log.Scoped`:
```go
import (
"os"
"testing"
"github.com/sourcegraph/log/logtest"
)
func TestMain(m *testing.M) {
logtest.Init(m)
os.Exit(m.Run())
}
```
You can control the log level used during initialization with `logtest.InitWithLevel`.

4
go.mod
View File

@ -140,7 +140,7 @@ require (
github.com/sourcegraph/go-lsp v0.0.0-20200429204803-219e11d77f5d
github.com/sourcegraph/go-rendezvous v0.0.0-20210910070954-ef39ade5591d
github.com/sourcegraph/jsonx v0.0.0-20200629203448-1a936bd500cf
github.com/sourcegraph/log v0.0.0-20220613150728-bb50c87ba841
github.com/sourcegraph/log v0.0.0-20220615162128-abf79fa7246a
github.com/sourcegraph/run v0.9.0
github.com/sourcegraph/scip v0.1.0
github.com/sourcegraph/sourcegraph/enterprise/dev/ci/images v0.0.0-20220203145655-4d2a39d3038a
@ -168,7 +168,7 @@ require (
golang.org/x/net v0.0.0-20220526153639-5463443f8c37
golang.org/x/oauth2 v0.0.0-20220411215720-9780585627b5
golang.org/x/sync v0.0.0-20210220032951-036812b2e83c
golang.org/x/sys v0.0.0-20220610221304-9f5ed59c137d
golang.org/x/sys v0.0.0-20220614162138-6c1b26c55098
golang.org/x/time v0.0.0-20220411224347-583f2d630306
golang.org/x/tools v0.1.10
google.golang.org/api v0.77.0

4
go.sum
View File

@ -2165,6 +2165,8 @@ github.com/sourcegraph/jsonx v0.0.0-20200629203448-1a936bd500cf h1:oAdWFqhStsWii
github.com/sourcegraph/jsonx v0.0.0-20200629203448-1a936bd500cf/go.mod h1:ppFaPm6kpcHnZGqQTFhUIAQRIEhdQDWP1PCv4/ON354=
github.com/sourcegraph/log v0.0.0-20220613150728-bb50c87ba841 h1:kiYxuyQ1zSNA4YPtVVJQAFw5ZRNaFRkFqgKyEJQTzhg=
github.com/sourcegraph/log v0.0.0-20220613150728-bb50c87ba841/go.mod h1:A+9F6IicYvBbl2aT0R81lMraKcXjVfdfw352yPe2yJI=
github.com/sourcegraph/log v0.0.0-20220615162128-abf79fa7246a h1:Xs/Lr9yr4fEo1lHx01y1rXLTXCh28q5dKXhbXDAJFnw=
github.com/sourcegraph/log v0.0.0-20220615162128-abf79fa7246a/go.mod h1:A+9F6IicYvBbl2aT0R81lMraKcXjVfdfw352yPe2yJI=
github.com/sourcegraph/oauth2 v0.0.0-20210825125341-77c1d99ece3c h1:HGa4iJr6MGKnB5qbU7tI511NdGuHUHnNCqP67G6KmfE=
github.com/sourcegraph/oauth2 v0.0.0-20210825125341-77c1d99ece3c/go.mod h1:KelEdhl1UZF7XfJ4dDtk6s++YSgaE7mD/BuKKDLBl4A=
github.com/sourcegraph/run v0.9.0 h1:mj4pwBqCB+5qEaTp+rhauh5ubYI8n/icOkeiLTCT9Xg=
@ -2829,6 +2831,8 @@ golang.org/x/sys v0.0.0-20220328115105-d36c6a25d886/go.mod h1:oPkhp1MJrh7nUepCBc
golang.org/x/sys v0.0.0-20220412211240-33da011f77ad/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220610221304-9f5ed59c137d h1:Zu/JngovGLVi6t2J3nmAf3AoTDwuzw85YZ3b9o4yU7s=
golang.org/x/sys v0.0.0-20220610221304-9f5ed59c137d/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220614162138-6c1b26c55098 h1:PgOr27OhUx2IRqGJ2RxAWI4dJQ7bi9cSrB82uzFzfUA=
golang.org/x/sys v0.0.0-20220614162138-6c1b26c55098/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
golang.org/x/term v0.0.0-20210615171337-6886f2dfbf5b/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8=