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

Adds Flattened logger #25

Merged
merged 4 commits into from
Aug 6, 2023
Merged

Adds Flattened logger #25

merged 4 commits into from
Aug 6, 2023

Conversation

basvanbeek
Copy link
Member

This adds a hybrid structured/unstructured output logger implementation for telemetry.Logger.

Context

telemetry.Logger is an abstract interface that expects structured data input (there are no Errorf, Infof, and Debugf style methods). Since telemetry.Logger has replaced a huge amount of unstructured log lines, the NewUnstructured Logger was created for the transition period. It assumes that variadic arguments are passed to Error, Info, and Debug where the main msg argument is a Printf style format string. This provides incorrect output if telemetry.Logger interface is properly using structured data.

Example:

    strLen := 12

    // using printf style data:
    logger.Info("we received a string of size %d", strLen)
    // Output: 2023/08/05 23:55:50  info   we received a string of size 12

    // using the logging interface correctly:
    logger.Info("we received a string", "size", stLen)
    // Output: 2023/08/05 23:55:50  info   we received a string%!(EXTRA string=size, int=12)

For structured data the New (structured) logger was created, which provides fully structured data.

Example:

    logger.Info("we received a string", "size", strLen)
    // Output: time="2023/08/05 23:55:50" level=info msg="we received a string" size=12

The NewFlattened logger provides a middle ground where the log line is partially unstructured except for key value pairs provided through Context, With(), as well as the key-value arguments from the Debug, Info, and Error messages. Attached errors are also rolled up in the structured section. This makes this new logger implementation ideally suited for usage in applications which packages have been instrumented with structured data while desiring a better human readable flattened log output.

Example:

  logger.With("method", "order").Error("unable to retrieve product", err, "product", "TSB")
  // Output: 2023/08/05 23:55:50  error  unable to retrieve product [error="database connection timed out" method="order" product="TSB"]

@codecov
Copy link

codecov bot commented Aug 5, 2023

Codecov Report

Merging #25 (7ab7155) into v2 (4a34e7e) will not change coverage.
The diff coverage is 100.00%.

Additional details and impacted files
@@            Coverage Diff            @@
##                v2       #25   +/-   ##
=========================================
  Coverage   100.00%   100.00%           
=========================================
  Files            1         1           
  Lines           91       148   +57     
=========================================
+ Hits            91       148   +57     
Files Changed Coverage Δ
logger.go 100.00% <100.00%> (ø)

@basvanbeek basvanbeek requested a review from nacx August 5, 2023 22:22
@basvanbeek basvanbeek enabled auto-merge (squash) August 5, 2023 22:28
@nacx
Copy link
Member

nacx commented Aug 6, 2023

LGTM! Thanks for this.

Would you mind updating the example test as well?
Also, can you provide the benchmarks for this new logger to compare it with the others? There was some work done to try minimize the memory allocations and I'm wondering if it is worth trying to remove the one for the "(missing)" arg.

@basvanbeek
Copy link
Member Author

Added flattened logger to example_test.

Here are the benchmark results

go test -bench=.  ./...
goos: darwin
goarch: amd64
pkg: github.com/tetratelabs/log
cpu: Intel(R) Core(TM) i9-8950HK CPU @ 2.90GHz
BenchmarkStructuredLog0Args-12       	 1417407	       869.3 ns/op	     152 B/op	       4 allocs/op
BenchmarkStructuredLog3Args-12       	  972115	      1175 ns/op	     280 B/op	       5 allocs/op
BenchmarkStructuredLog9Args-12       	  715173	      1645 ns/op	     280 B/op	       5 allocs/op
BenchmarkStructuredLog15Args-12      	  490642	      2180 ns/op	     536 B/op	       6 allocs/op
BenchmarkStructuredLog30Args-12      	  334177	      3450 ns/op	    1048 B/op	       7 allocs/op
BenchmarkUnstructuredLog0Args-12     	 1535112	       780.3 ns/op	     112 B/op	       4 allocs/op
BenchmarkUnstructuredLog3Args-12     	  976017	      1136 ns/op	     280 B/op	       5 allocs/op
BenchmarkUnstructuredLog9Args-12     	  668216	      1683 ns/op	     568 B/op	       6 allocs/op
BenchmarkUnstructuredLog15Args-12    	  462992	      2231 ns/op	     664 B/op	       6 allocs/op
BenchmarkUnstructuredLog30Args-12    	  326982	      3405 ns/op	    1096 B/op	       6 allocs/op
BenchmarkFlattenedLog0Args-12        	 1467752	       815.3 ns/op	     136 B/op	       4 allocs/op
BenchmarkFlattenedLog3Args-12        	  989272	      1146 ns/op	     136 B/op	       4 allocs/op
BenchmarkFlattenedLog9Args-12        	  644108	      1795 ns/op	     264 B/op	       5 allocs/op
BenchmarkFlattenedLog15Args-12       	  484154	      2439 ns/op	     520 B/op	       6 allocs/op
BenchmarkFlattenedLog30Args-12       	  274658	      3672 ns/op	     520 B/op	       6 allocs/op

Copy link
Member

@nacx nacx left a comment

Choose a reason for hiding this comment

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

Nice! Thx!!

@basvanbeek basvanbeek merged commit 9a96726 into v2 Aug 6, 2023
10 checks passed
@basvanbeek basvanbeek deleted the flattened-logger branch August 7, 2023 08:26
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.

2 participants