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.

Sign up for GitHub

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

Jump to bottom

feat/benchmarks #6

Merged
merged 4 commits into from
Aug 9, 2022
Merged

feat/benchmarks #6

merged 4 commits into from
Aug 9, 2022

Conversation

bep
Copy link
Owner

@bep bep commented Aug 9, 2022

  • Add /benchmarks
  • Add a sync.Pool for Entry passed to HandleLog
  • Get rid of the custom entry.MarshalJSON
  • Remove FatalLevel

bep added 4 commits August 8, 2022 23:44
@bep
Add /benchmarks
f2539fa 
Adapted from https://github.com/uber-go/zap

Removed the Zap tests as they depend on Zap internal packages.

Also some minor adjustments to the JSON handler.

Current numbers:

```
pkg: github.com/bep/log/benchmarks
BenchmarkDisabledWithoutFields/apex/log-10             33381511            31.94 ns/op         112 B/op           1 allocs/op
BenchmarkDisabledWithoutFields/bep/log-10              1000000000             0.2626 ns/op           0 B/op           0 allocs/op
BenchmarkDisabledWithoutFields/sirupsen/logrus-10      184702716             6.658 ns/op          16 B/op           1 allocs/op
BenchmarkDisabledWithoutFields/rs/zerolog-10           1000000000             0.3089 ns/op           0 B/op           0 allocs/op
BenchmarkDisabledAccumulatedContext/apex/log-10        1000000000             0.2540 ns/op           0 B/op           0 allocs/op
BenchmarkDisabledAccumulatedContext/bep/log-10         1000000000             0.2509 ns/op           0 B/op           0 allocs/op
BenchmarkDisabledAccumulatedContext/sirupsen/logrus-10             172711033             6.978 ns/op          16 B/op           1 allocs/op
BenchmarkDisabledAccumulatedContext/rs/zerolog-10                  1000000000             0.3107 ns/op           0 B/op           0 allocs/op
BenchmarkDisabledAddingFields/apex/log-10                           3546764           344.8 ns/op         886 B/op          10 allocs/op
BenchmarkDisabledAddingFields/bep/log-10                           1000000000             0.4054 ns/op           0 B/op           0 allocs/op
BenchmarkDisabledAddingFields/sirupsen/logrus-10                    1901714           637.0 ns/op        1525 B/op          12 allocs/op
BenchmarkDisabledAddingFields/rs/zerolog-10                        95219829            12.83 ns/op          24 B/op           1 allocs/op
BenchmarkWithoutFields/apex/log-10                                  1234471           967.4 ns/op         352 B/op           6 allocs/op
BenchmarkWithoutFields/bep/log-10                                   3886761           305.5 ns/op         400 B/op           7 allocs/op
BenchmarkWithoutFields/go-kit/kit/log-10                            4782997           249.2 ns/op         520 B/op           9 allocs/op
BenchmarkWithoutFields/inconshreveable/log15-10                      521266          2170 ns/op        1433 B/op          20 allocs/op
BenchmarkWithoutFields/sirupsen/logrus-10                           1330628           908.8 ns/op        1140 B/op          23 allocs/op
BenchmarkWithoutFields/stdlib.Println-10                           132966830             8.636 ns/op          16 B/op           1 allocs/op
BenchmarkWithoutFields/stdlib.Printf-10                            19818385            59.31 ns/op         136 B/op           6 allocs/op
BenchmarkWithoutFields/rs/zerolog-10                               31718690            33.17 ns/op           0 B/op           0 allocs/op
BenchmarkWithoutFields/rs/zerolog.Formatting-10                      735062          1552 ns/op        1915 B/op          58 allocs/op
BenchmarkWithoutFields/rs/zerolog.Check-10                         35039352            32.87 ns/op           0 B/op           0 allocs/op
BenchmarkAccumulatedContext/apex/log-10                               92566         12647 ns/op        3296 B/op          53 allocs/op
BenchmarkAccumulatedContext/bep/log-10                               264836          4530 ns/op        5425 B/op          56 allocs/op
BenchmarkAccumulatedContext/go-kit/kit/log-10                        396302          2906 ns/op        3677 B/op          56 allocs/op
BenchmarkAccumulatedContext/inconshreveable/log15-10                 127216          9217 ns/op        3306 B/op          70 allocs/op
BenchmarkAccumulatedContext/sirupsen/logrus-10                       323739          3936 ns/op        4733 B/op          68 allocs/op
BenchmarkAccumulatedContext/rs/zerolog-10                          34143409            34.31 ns/op           0 B/op           0 allocs/op
BenchmarkAccumulatedContext/rs/zerolog.Check-10                    35422959            32.22 ns/op           0 B/op           0 allocs/op
BenchmarkAccumulatedContext/rs/zerolog.Formatting-10                 716893          1497 ns/op        1916 B/op          58 allocs/op
BenchmarkAddingFields/apex/log-10                                     89449         13251 ns/op        4187 B/op          63 allocs/op
BenchmarkAddingFields/bep/log-10                                     253292          4866 ns/op        6256 B/op          65 allocs/op
BenchmarkAddingFields/go-kit/kit/log-10                              409681          2611 ns/op        3317 B/op          57 allocs/op
BenchmarkAddingFields/inconshreveable/log15-10                        82022         14363 ns/op        6683 B/op          74 allocs/op
BenchmarkAddingFields/sirupsen/logrus-10                             252860          4840 ns/op        6276 B/op          79 allocs/op
BenchmarkAddingFields/rs/zerolog-10                                 3099764           395.5 ns/op          24 B/op           1 allocs/op
BenchmarkAddingFields/rs/zerolog.Check-10                           3102861           383.2 ns/op          24 B/op           1 allocs/op
```
@bep
Add a sync.Pool for Entry passed to HandleLog
125d95e 
This commit does several things:

* Makes it into one Entry strcut
* Creates a object pool for Entry objects passed to HandleLog
* This means that if someone wants to use an Event after HandleLog, he/she needs to make a copy via entry.Clone.
* This is unfortunate, but the performance benefits are obvious, especially when the common context (fields) are big.

```bash
name                                  old time/op    new time/op    delta
Logger_common_context-10                 118ns ± 9%      62ns ± 4%   -47.23%  (p=0.029 n=4+4)
Logger_common_context_many_fields-10    2.35µs ± 0%    2.17µs ± 0%    -7.79%  (p=0.029 n=4+4)

name                                  old alloc/op   new alloc/op   delta
Logger_common_context-10                  176B ± 0%        0B       -100.00%  (p=0.029 n=4+4)
Logger_common_context_many_fields-10    1.49kB ± 0%    0.00kB       -100.00%  (p=0.029 n=4+4)

name                                  old allocs/op  new allocs/op  delta
Logger_common_context-10                  2.00 ± 0%      0.00       -100.00%  (p=0.029 n=4+4)
Logger_common_context_many_fields-10      2.00 ± 0%      0.00       -100.00%  (p=0.029 n=4+4)
```

And the "Zap benchmarks":

```bash
name                                   old time/op    new time/op    delta
DisabledWithoutFields/bep/log-10         0.27ns ± 2%    0.29ns ± 3%   +7.22%  (p=0.029 n=4+4)
DisabledAccumulatedContext/bep/log-10    0.25ns ± 2%    0.26ns ± 2%   +2.45%  (p=0.029 n=4+4)
DisabledAddingFields/bep/log-10          0.38ns ± 1%    0.39ns ± 2%     ~     (p=0.057 n=4+4)
WithoutFields/bep/log-10                  336ns ± 1%     302ns ± 1%  -10.20%  (p=0.029 n=4+4)
AccumulatedContext/bep/log-10            4.68µs ± 3%    4.36µs ± 2%   -6.73%  (p=0.029 n=4+4)
AddingFields/bep/log-10                  5.11µs ± 1%    5.06µs ± 1%     ~     (p=0.057 n=4+4)

name                                   old alloc/op   new alloc/op   delta
DisabledWithoutFields/bep/log-10          0.00B          0.00B          ~     (all equal)
DisabledAccumulatedContext/bep/log-10     0.00B          0.00B          ~     (all equal)
DisabledAddingFields/bep/log-10           0.00B          0.00B          ~     (all equal)
WithoutFields/bep/log-10                   465B ± 0%      385B ± 0%  -17.20%  (p=0.029 n=4+4)
AccumulatedContext/bep/log-10            5.49kB ± 0%    5.09kB ± 0%   -7.32%  (p=0.029 n=4+4)
AddingFields/bep/log-10                  6.36kB ± 0%    5.96kB ± 0%   -6.23%  (p=0.029 n=4+4)

name                                   old allocs/op  new allocs/op  delta
DisabledWithoutFields/bep/log-10           0.00           0.00          ~     (all equal)
DisabledAccumulatedContext/bep/log-10      0.00           0.00          ~     (all equal)
DisabledAddingFields/bep/log-10            0.00           0.00          ~     (all equal)
WithoutFields/bep/log-10                   7.00 ± 0%      6.00 ± 0%  -14.29%  (p=0.029 n=4+4)
AccumulatedContext/bep/log-10              56.0 ± 0%      54.0 ± 0%   -3.57%  (p=0.029 n=4+4)
AddingFields/bep/log-10                    65.0 ± 0%      63.0 ± 0%   -3.08%  (p=0.029 n=4+4)
```
@bep
Get rid of the custom entry.MarshalJSON
da4331e 
It makes for a slightly uglier JSON (the fields are a slice), but it looks much better with the Zap benchmarks:

```bash
name                                   old time/op    new time/op    delta
DisabledWithoutFields/bep/log-10         0.30ns ± 3%    0.30ns ± 4%     ~     (p=0.486 n=4+4)
DisabledAccumulatedContext/bep/log-10    0.26ns ± 1%    0.27ns ± 1%   +4.82%  (p=0.029 n=4+4)
DisabledAddingFields/bep/log-10          0.39ns ± 2%    0.40ns ± 4%     ~     (p=0.057 n=4+4)
WithoutFields/bep/log-10                  313ns ± 3%     104ns ± 3%  -66.84%  (p=0.029 n=4+4)
AccumulatedContext/bep/log-10            4.39µs ± 1%    1.55µs ± 2%  -64.73%  (p=0.029 n=4+4)
AddingFields/bep/log-10                  5.06µs ± 2%    1.98µs ± 1%  -60.75%  (p=0.029 n=4+4)

name                                   old alloc/op   new alloc/op   delta
DisabledWithoutFields/bep/log-10          0.00B          0.00B          ~     (all equal)
DisabledAccumulatedContext/bep/log-10     0.00B          0.00B          ~     (all equal)
DisabledAddingFields/bep/log-10           0.00B          0.00B          ~     (all equal)
WithoutFields/bep/log-10                   385B ± 0%       56B ± 0%  -85.45%  (p=0.029 n=4+4)
AccumulatedContext/bep/log-10            5.09kB ± 0%    1.16kB ± 0%  -77.18%  (p=0.029 n=4+4)
AddingFields/bep/log-10                  5.96kB ± 0%    2.03kB ± 0%  -66.00%  (p=0.029 n=4+4)

name                                   old allocs/op  new allocs/op  delta
DisabledWithoutFields/bep/log-10           0.00           0.00          ~     (all equal)
DisabledAccumulatedContext/bep/log-10      0.00           0.00          ~     (all equal)
DisabledAddingFields/bep/log-10            0.00           0.00          ~     (all equal)
WithoutFields/bep/log-10                   6.00 ± 0%      2.00 ± 0%  -66.67%  (p=0.029 n=4+4)
AccumulatedContext/bep/log-10              54.0 ± 0%      25.0 ± 0%  -53.70%  (p=0.029 n=4+4)
AddingFields/bep/log-10                    63.0 ± 0%      34.0 ± 0%  -46.03%  (p=0.029 n=4+4)
```
@bep
Remove FatalLevel
c85516d 
Doing `os.Exit(-1)` inside a library doesn't sit right.
@bep bep merged commit 167b63a into master Aug 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
1 participant
@bep