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

Remove a stray fmt.Printf, use a logger #14468

Merged
merged 5 commits into from
Sep 28, 2022

Conversation

atoulme
Copy link
Contributor

@atoulme atoulme commented Sep 24, 2022

Description:
Remove a stray fmt.Printf, use a logger

Link to tracking Issue:
#14467

Testing:
N/A

Documentation:
N/A

@atoulme atoulme requested a review from a team September 24, 2022 05:58
@atoulme atoulme force-pushed the fix_ottl_printf branch 3 times, most recently from 3befc4b to 4eeb6df Compare September 24, 2022 07:52
Copy link
Member

@kentquirk kentquirk left a comment

Choose a reason for hiding this comment

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

I'm home with COVID at the moment and not in a position to do any performance analysis today.

But I'm not very happy about adding a logger parameter everywhere and passing it on every function call. This code is designed to be as fast as possible.

The printf you're complaining about iin #14467 is telling you that you gave it bad data -- the example code in the bug (please link the bug with # before the bug number in the original so that GitHub does the right things with it!) is telling you that attributes["foo"] is not a string but you're comparing it to one.

In the original version of this code, I didn't have the printf at all, and then was asked to include it because we should generate some.

I guess if we think we need it, I would much prefer to move all of the functions here into member functions on the parser. There are also benchmarks in compare_test.go that I'd want to run a before/after comparison with, whichever path we take.

And finally, I don't believe that either transformprocessor or ottl has introduced a logger before. If we do, I don't think I want to depend on zap as the standard logging interface; I would prefer a more generic choice, especially now that there's some consideration going on in the Go community towards a more flexible standard logging model. Given that this is just a single call, I'd suggest we start with the Go standard log interface, or even define a logger interface locally that we can tweak over time.

@TylerHelmuth do you have an opinion on any of this?

@TylerHelmuth
Copy link
Member

TylerHelmuth commented Sep 25, 2022

@kentquirk I agree with everything you said except for not depending on zap. When @evan-bradley introduced the generic logger framework that was definitely the correct solution, but since that decision was made we've pivoted OTTL away from an agnostic solution and steered it towards a collector-specific solution.

With the pivot in mind, I think zap makes sense since the collector's logger of choice is zap. The OTTL parser now requires the collector's TelemetrySettings struct, which includes its zap logger. (You we're out for this PR but still willing to discuss if you have thoughts).

@TylerHelmuth
Copy link
Member

I would also say we do want to replace the print statement with the logger usage so it can conform with the collectors logging settings. I agree that I would rather not pass it around.

@kentquirk
Copy link
Member

Ok, thanks. I agree that if the collector has standardized on zap that we can use that (although I wish it had been a more general solution, it's done now).

So then, the right answer here is, I think, to move the compare functions into private member functions so that we don't have to add the logger to their signatures.

@atoulme
Copy link
Contributor Author

atoulme commented Sep 26, 2022

I'm home with COVID at the moment and not in a position to do any performance analysis today.

Please rest up!

But I'm not very happy about adding a logger parameter everywhere and passing it on every function call. This code is designed to be as fast as possible.

It would be best not to print out anything then.

The printf you're complaining about iin #14467 is telling you that you gave it bad data -- the example code in the bug (please link the bug with # before the bug number in the original so that GitHub does the right things with it!) is telling you that attributes["foo"] is not a string but you're comparing it to one.

This is not bad data - attributes["foo"] is a nil value, and this new behavior now makes us print this line for every record, which is a regression of our system. We have customers asking for a fix at once.

There is a simpler fix - we delete the fmt.Printf line.

@TylerHelmuth
Copy link
Member

This print statement is serving a useful purpose of letting customers know when there are issues or unexpected outcomes during hot path execution. The issue this print statement is informing users about cannot be determined during collector validation. For this reason we need to continue to inform users of this situation.

This print statement, as well as other situations we haven't addressed yet in Context and Functions, should use the collectors logger so that the processor honors the collectors telemetry settings for logging.

@dmitryax
Copy link
Member

dmitryax commented Sep 27, 2022

Just to summarize what was discussed here and in the issue.

We all agree that the log message is valid, but should be replaced with a debug log entry instead.

This PR reaches the goal, but passing the logger around as an argument is not ideal solution, so we want to move the functions to member functions on the parser.

@TylerHelmuth @kentquirk please correct me if I'm missing anything.

My question if we can merge this PR as is and handle the refactoring mentioned above as part of another issue. @TylerHelmuth @kentquirk WDYT?

@TylerHelmuth
Copy link
Member

@dmitryax you've got it all summarized correctly.

I'd really rather not fix #14467 via passing the logger around as it is a fix where we are instantly introducing more work for ourselves and potentially degrading performance (we have benchmarks for comparison to test this).

If we can't fix the issue using member functions at this time and absolutely need to deal with the spurious logs before the next release I'd rather the print statement be removed entirely and a new, high priority issue opened to address passing logging around the parser. This isn't ideal, but it feels better than adding code we already know we want to remove that could affect performance.

@atoulme if you can run the comparison benchmarks in the package on the main branch and on this PR's branch and confirm there is no performance degradation, then I'd be more inclined to handled the issue via passing the logger.

Copy link
Member

@TylerHelmuth TylerHelmuth left a comment

Choose a reason for hiding this comment

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

@atoulme thanks for running those benchmarks

@atoulme
Copy link
Contributor Author

atoulme commented Sep 28, 2022

New benchmark:

goos: darwin
goarch: amd64
pkg: github.com/open-telemetry/opentelemetry-collector-contrib/pkg/ottl
cpu: Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz
BenchmarkCompareEQInt64
BenchmarkCompareEQInt64-16 206829811 5.394 ns/op
BenchmarkCompareEQFloat
BenchmarkCompareEQFloat-16 235811641 5.546 ns/op
BenchmarkCompareEQString
BenchmarkCompareEQString-16 100000000 10.49 ns/op
BenchmarkCompareEQPString
BenchmarkCompareEQPString-16 253092255 4.790 ns/op
BenchmarkCompareEQBytes
BenchmarkCompareEQBytes-16 131612401 9.184 ns/op
BenchmarkCompareEQNil
BenchmarkCompareEQNil-16 501326972 2.349 ns/op
BenchmarkCompareNEInt
BenchmarkCompareNEInt-16 210399183 6.153 ns/op
BenchmarkCompareNEFloat
BenchmarkCompareNEFloat-16 200999788 5.971 ns/op
BenchmarkCompareNEString
BenchmarkCompareNEString-16 100000000 10.24 ns/op
BenchmarkCompareLTFloat
BenchmarkCompareLTFloat-16 227600818 5.554 ns/op
BenchmarkCompareLTString
BenchmarkCompareLTString-16 120098608 10.34 ns/op
BenchmarkCompareLTNil
BenchmarkCompareLTNil-16 535652295 2.035 ns/op
BenchmarkCompareEQFunction
BenchmarkCompareEQFunction-16 167140707 7.545 ns/op

goos: darwin
goarch: amd64
pkg: github.com/open-telemetry/opentelemetry-collector-contrib/pkg/ottl
cpu: Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz
BenchmarkCompareEQInt64
BenchmarkCompareEQInt64-16 206253358 5.933 ns/op
BenchmarkCompareEQFloat
BenchmarkCompareEQFloat-16 173147316 5.936 ns/op
BenchmarkCompareEQString
BenchmarkCompareEQString-16 134722820 8.380 ns/op
BenchmarkCompareEQPString
BenchmarkCompareEQPString-16 249906909 4.567 ns/op
BenchmarkCompareEQBytes
BenchmarkCompareEQBytes-16 132361765 8.793 ns/op
BenchmarkCompareEQNil
BenchmarkCompareEQNil-16 525513944 2.351 ns/op
BenchmarkCompareNEInt
BenchmarkCompareNEInt-16 204466880 5.512 ns/op
BenchmarkCompareNEFloat
BenchmarkCompareNEFloat-16 235253712 5.576 ns/op
BenchmarkCompareNEString
BenchmarkCompareNEString-16 129672235 8.464 ns/op
BenchmarkCompareLTFloat
BenchmarkCompareLTFloat-16 219071109 4.984 ns/op
BenchmarkCompareLTString
BenchmarkCompareLTString-16 140862020 8.623 ns/op
BenchmarkCompareLTNil
BenchmarkCompareLTNil-16 509819265 2.447 ns/op
BenchmarkCompareEQFunction
BenchmarkCompareEQFunction-16 191675306 6.654 ns/op
PASS

Copy link
Member

@kentquirk kentquirk left a comment

Choose a reason for hiding this comment

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

Thank you for making these changes.

@TylerHelmuth TylerHelmuth added the ready to merge Code review completed; ready to merge by maintainers label Sep 28, 2022
@dmitryax dmitryax merged commit d5bb86c into open-telemetry:main Sep 28, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
ready to merge Code review completed; ready to merge by maintainers
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants