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

Rework log interface to avoid allocation when log level is not met #5

Merged
merged 2 commits into from
Aug 8, 2022

Conversation

bep
Copy link
Owner

@bep bep commented Aug 7, 2022

The new interfaces are:

type Leveler interface {
    WithLevel(Level) *EntryFields
}

type Logger interface {
    Log(fmt.Stringer)
    Leveler
    WithFields(Fielder) *EntryFields
    WithField(string, any) *EntryFields
    WithDuration(time.Duration) *EntryFields
    WithError(error) *EntryFields
}

This is also more effective, especially in the situations where the log level is not met:

name                                    old time/op    new time/op    delta
Logger_small-10                           76.8ns ± 0%    54.1ns ± 0%  -29.58%  (p=0.029 n=4+4)
Logger_medium-10                           167ns ± 0%     124ns ± 0%  -25.60%  (p=0.029 n=4+4)
Logger_large-10                            399ns ± 1%     340ns ± 0%  -14.72%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Logger-10    1.00µs ± 0%    0.18µs ± 0%  -81.83%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Entry-10     5.77µs ± 0%    0.18µs ± 0%  -96.85%  (p=0.029 n=4+4)
Logger_levels/level_met-10                 223µs ± 0%      20µs ± 0%  -91.17%  (p=0.029 n=4+4)
Logger_levels/level_met,_Entry-10         26.0µs ± 0%     2.0µs ± 0%  -92.43%  (p=0.029 n=4+4)

name                                    old alloc/op   new alloc/op   delta
Logger_small-10                            96.0B ± 0%     48.0B ± 0%  -50.00%  (p=0.029 n=4+4)
Logger_medium-10                            312B ± 0%      192B ± 0%  -38.46%  (p=0.029 n=4+4)
Logger_large-10                           1.26kB ± 0%    1.12kB ± 0%  -10.83%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Logger-10    1.31kB ± 0%    0.17kB ± 0%  -87.20%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Entry-10     13.5kB ± 0%     0.2kB ± 0%  -98.76%  (p=0.029 n=4+4)
Logger_levels/level_met-10                 554kB ± 0%      18kB ± 0%  -96.67%  (p=0.029 n=4+4)
Logger_levels/level_met,_Entry-10         64.9kB ± 0%     1.8kB ± 0%  -97.17%  (p=0.029 n=4+4)

name                                    old allocs/op  new allocs/op  delta
Logger_small-10                             2.00 ± 0%      1.00 ± 0%  -50.00%  (p=0.029 n=4+4)
Logger_medium-10                            5.00 ± 0%      3.00 ± 0%  -40.00%  (p=0.029 n=4+4)
Logger_large-10                             10.0 ± 0%       7.0 ± 0%  -30.00%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Logger-10      82.0 ± 0%      11.0 ± 0%  -86.59%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Entry-10        257 ± 0%        11 ± 0%  -95.72%  (p=0.029 n=4+4)
Logger_levels/level_met-10                 4.92k ± 0%     0.51k ± 0%  -89.64%  (p=0.029 n=4+4)
Logger_levels/level_met,_Entry-10            585 ± 0%        51 ± 0%  -91.28%  (p=0.029 n=4+4)

@bep bep force-pushed the feat/lazy2 branch 2 times, most recently from 31f17ca to 040e693 Compare August 7, 2022 20:11
@bep bep closed this Aug 8, 2022
@bep bep reopened this Aug 8, 2022
The new interfaces are:

```go
type Leveler interface {
    WithLevel(Level) *EntryFields
}

type Logger interface {
    Log(fmt.Stringer)
    Leveler
    WithFields(Fielder) *EntryFields
    WithField(string, any) *EntryFields
    WithDuration(time.Duration) *EntryFields
    WithError(error) *EntryFields
}
```

This is also more effective, especially in the situations where the log level is not met:

```bash
name                                    old time/op    new time/op    delta
Logger_small-10                           76.8ns ± 0%    54.1ns ± 0%  -29.58%  (p=0.029 n=4+4)
Logger_medium-10                           167ns ± 0%     124ns ± 0%  -25.60%  (p=0.029 n=4+4)
Logger_large-10                            399ns ± 1%     340ns ± 0%  -14.72%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Logger-10    1.00µs ± 0%    0.18µs ± 0%  -81.83%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Entry-10     5.77µs ± 0%    0.18µs ± 0%  -96.85%  (p=0.029 n=4+4)
Logger_levels/level_met-10                 223µs ± 0%      20µs ± 0%  -91.17%  (p=0.029 n=4+4)
Logger_levels/level_met,_Entry-10         26.0µs ± 0%     2.0µs ± 0%  -92.43%  (p=0.029 n=4+4)

name                                    old alloc/op   new alloc/op   delta
Logger_small-10                            96.0B ± 0%     48.0B ± 0%  -50.00%  (p=0.029 n=4+4)
Logger_medium-10                            312B ± 0%      192B ± 0%  -38.46%  (p=0.029 n=4+4)
Logger_large-10                           1.26kB ± 0%    1.12kB ± 0%  -10.83%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Logger-10    1.31kB ± 0%    0.17kB ± 0%  -87.20%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Entry-10     13.5kB ± 0%     0.2kB ± 0%  -98.76%  (p=0.029 n=4+4)
Logger_levels/level_met-10                 554kB ± 0%      18kB ± 0%  -96.67%  (p=0.029 n=4+4)
Logger_levels/level_met,_Entry-10         64.9kB ± 0%     1.8kB ± 0%  -97.17%  (p=0.029 n=4+4)

name                                    old allocs/op  new allocs/op  delta
Logger_small-10                             2.00 ± 0%      1.00 ± 0%  -50.00%  (p=0.029 n=4+4)
Logger_medium-10                            5.00 ± 0%      3.00 ± 0%  -40.00%  (p=0.029 n=4+4)
Logger_large-10                             10.0 ± 0%       7.0 ± 0%  -30.00%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Logger-10      82.0 ± 0%      11.0 ± 0%  -86.59%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_Entry-10        257 ± 0%        11 ± 0%  -95.72%  (p=0.029 n=4+4)
Logger_levels/level_met-10                 4.92k ± 0%     0.51k ± 0%  -89.64%  (p=0.029 n=4+4)
Logger_levels/level_met,_Entry-10            585 ± 0%        51 ± 0%  -91.28%  (p=0.029 n=4+4)
```
@bep bep force-pushed the feat/lazy2 branch 6 times, most recently from 804b652 to 011b3b0 Compare August 8, 2022 18:35
This is a big saver when doing debug logging in tight loop, but needs to be clearly documented.

```bash
name                                         old alloc/op   new alloc/op   delta
Logger_levels/level_not_met-10                   264B ± 0%      264B ± 0%     ~     (all equal)
Logger_levels/level_not_met,_one_field-10        344B ± 0%      264B ± 0%  -23.26%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_many_fields-10    6.17kB ± 0%    0.52kB ± 0%  -91.57%  (p=0.029 n=4+4)
Logger_levels/level_met-10                     18.5kB ± 0%    18.5kB ± 0%     ~     (all equal)
Logger_levels/level_met,_one_field-10          2.02kB ± 0%    2.02kB ± 0%     ~     (all equal)
Logger_levels/level_met,_many_fields-10        7.84kB ± 0%    7.84kB ± 0%     ~     (all equal)

name                                         old allocs/op  new allocs/op  delta
Logger_levels/level_not_met-10                   13.0 ± 0%      13.0 ± 0%     ~     (all equal)
Logger_levels/level_not_met,_one_field-10        15.0 ± 0%      13.0 ± 0%  -13.33%  (p=0.029 n=4+4)
Logger_levels/level_not_met,_many_fields-10      85.0 ± 0%      45.0 ± 0%  -47.06%  (p=0.029 n=4+4)
Logger_levels/level_met-10                        512 ± 0%       512 ± 0%     ~     (all equal)
Logger_levels/level_met,_one_field-10            55.0 ± 0%      55.0 ± 0%     ~     (all equal)
Logger_levels/level_met,_many_fields-10           125 ± 0%       125 ± 0%     ~     (all equal)
```
@bep bep merged commit df03e14 into master Aug 8, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant