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

Add WithFatalHook/CheckedEntry.After to replace OnFatal/CheckedEntry.Should #1088

Merged
merged 7 commits into from Apr 26, 2022

Conversation

cardil
Copy link
Contributor

@cardil cardil commented Apr 22, 2022

Fixes #1086

Changes

  • Deterministic calculate the POSIX return code for Fatal method

@cardil cardil force-pushed the feature/retcode-from-error-message branch from 65ee9c6 to 3d70496 Compare Apr 25, 2022
@codecov
Copy link

codecov bot commented Apr 25, 2022

Codecov Report

Merging #1088 (7481e89) into master (75dacb4) will decrease coverage by 0.04%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master    #1088      +/-   ##
==========================================
- Coverage   98.31%   98.27%   -0.05%     
==========================================
  Files          49       49              
  Lines        2137     2142       +5     
==========================================
+ Hits         2101     2105       +4     
  Misses         28       28              
- Partials        8        9       +1     
Impacted Files Coverage Δ
internal/exit/exit.go 100.00% <100.00%> (+9.09%) ⬆️
logger.go 96.52% <100.00%> (ø)
options.go 100.00% <100.00%> (ø)
zapcore/entry.go 93.97% <100.00%> (+0.22%) ⬆️
zapcore/sampler.go 96.22% <0.00%> (-3.78%) ⬇️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 75dacb4...7481e89. Read the comment docs.

@cardil cardil force-pushed the feature/retcode-from-error-message branch 2 times, most recently from 049879d to 595958b Compare Apr 25, 2022
@cardil cardil force-pushed the feature/retcode-from-error-message branch 3 times, most recently from cb84ded to 5e4c49b Compare Apr 25, 2022
@cardil cardil force-pushed the feature/retcode-from-error-message branch from 5e4c49b to 5fe5ca9 Compare Apr 25, 2022
@cardil cardil force-pushed the feature/retcode-from-error-message branch from 0a8619a to e6465c2 Compare Apr 26, 2022
@sywhang sywhang force-pushed the feature/retcode-from-error-message branch from d1db6b8 to 39c2ed3 Compare Apr 26, 2022
@sywhang sywhang changed the title 🎁 Deterministic calc of POSIX return code for Fatal Add WithFatalHook/CheckedEntry.After to replace OnFatal/CheckedEntry.Should Apr 26, 2022
@sywhang
Copy link
Contributor

sywhang commented Apr 26, 2022

Thanks for the contribution @cardil! It mostly looked good; i just made a few tweaks to remove a race condition and some breaking changes in the change.

@abhinav PTAL when you get a chance.

logger_test.go Outdated
recovered := make(chan interface{})
go func() {
defer func() {
recovered <- recover()
}()
logger.Fatal("")
}()
<-recovered
Copy link
Contributor

@abhinav abhinav Apr 26, 2022

Choose a reason for hiding this comment

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

The goroutine or channel isn't necessary.
The logger.Fatal won't panic because we're overriding it.

zapcore/entry.go Outdated
var _ CheckWriteHook = WriteThenNoop
var _ CheckWriteHook = WriteThenGoexit
var _ CheckWriteHook = WriteThenPanic
var _ CheckWriteHook = WriteThenFatal
Copy link
Contributor

@abhinav abhinav Apr 26, 2022

Choose a reason for hiding this comment

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

The check is type-level, not value-level so we can just verify that CheckWriteAction implements the interface.

@abhinav abhinav merged commit 71ecc42 into uber-go:master Apr 26, 2022
6 checks passed
@cardil cardil deleted the feature/retcode-from-error-message branch Apr 27, 2022
return WithFatalHook(action)
}

// WithFatalHook sets a CheckWriteHook to run on fatal logs.
Copy link
Collaborator

@prashantv prashantv Apr 29, 2022

Choose a reason for hiding this comment

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

The documentation should probably call out that users of the logging package expect execution to end at Fatal, and so it's recommended that this either:

  • Exits the process
  • OR exits the goroutine (more for testing) where execution of the goroutine stops, but it can be used for testing.

It's pretty common to see code like:

resp, err = [...]
if err != nil {
  logger.Fatal(err)
}

data, err := ioutil.ReadAll(resp.Body)

This code would panic, but could be other cases where data ends up getting corrupt etc. It's similar to catching panics, but a little riskier since it doesn't even half execution of the specific goroutine that calls Fatal.

Should we make it more difficult to allow execution to continue by disallowing WriteThenNoop for this case (user can still specify their own hook).

One other option is to always runtime.Goexit at minimum after an onFatal, that completely disallows execution to continue for the goroutine calling Fatal, but may be too restrictive, it could simplify testing to allow continue execution after capturing that a Fatal happened, because the test is confident that there's no other logic that would be inadvertently executed.

Copy link
Contributor

@abhinav abhinav Apr 29, 2022

Choose a reason for hiding this comment

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

That's fair. Taking a second look, I may have misunderstood the WriteThenNoop hook to mean that it actually allows no-op-ing the Fatal log. But after testing it out, it seems that WriteThenNoop turns into a "os.Exit" as the logic suggests.

// is processed.
type CheckWriteHook interface {
// OnWrite gets invoked when an entry is written
OnWrite(*CheckedEntry, []Field)
Copy link
Collaborator

@prashantv prashantv Apr 29, 2022

Choose a reason for hiding this comment

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

It may be useful to document that the fields here are not all fields on the logger, but just the fields specific to the message.

abhinav added a commit that referenced this pull request Apr 29, 2022
In #1088, we deprecated the CheckWriteAction enum in favor of the new
fully customizable CheckWriteHook. Unfortunately, this introduced a
minor regression: it's now possible to set log.Fatal to no-op with
WriteThenNoop.

Such a configuration will break code that looks like the following:

```go
f, err := os.Open(..)
if err != nil {
    log.Fatal("Cannot open file", zap.Error(err))
}

// Control flow expects that if we get here,
// f is valid and non-nil.
// That's not the case if Fatal no-ops.

fmt.Println(f.Name())
```

This change fixes the regression by turning Noops into WriteThenFatal
when logging Fatal log messages. This matches the old behavior.

It further clarifies the documentation for CheckWriteHook so that users
know to call runtime.Goexit or os.Exit in them. It's still possible to
write a custom hook that no-ops the log.Fatal, but it requires a little
extra effort from the user to do so.
abhinav added a commit that referenced this pull request Apr 29, 2022
In #1088, we deprecated the CheckWriteAction enum in favor of the new
fully customizable CheckWriteHook. Unfortunately, this introduced a
minor regression: it's now possible to set log.Fatal to no-op with
WriteThenNoop.

Such a configuration will break code that looks like the following:

```go
f, err := os.Open(..)
if err != nil {
    log.Fatal("Cannot open file", zap.Error(err))
}

// Control flow expects that if we get here,
// f is valid and non-nil.
// That's not the case if Fatal no-ops.

fmt.Println(f.Name())
```

This change fixes the regression by turning Noops into WriteThenFatal
when logging Fatal log messages. This matches the old behavior.

It further clarifies the documentation for CheckWriteHook so that users
know to call runtime.Goexit or os.Exit in them. It's still possible to
write a custom hook that no-ops the log.Fatal, but it requires a little
extra effort from the user to do so.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

Fatal should deterministically calculate the POSIX return code
4 participants