-
Notifications
You must be signed in to change notification settings - Fork 435
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
internal/log: Improve API for testing #916
Conversation
I just noticed that d9472a0 caused the profiler package to always emit some log output, regardless of `go test -v` being used or not. I'm very sorry about this. IMO tests should never print to stdout unless requested. This patch is my attempt to fix this by making it easy for individual tests to capture the log output (see UseLogger, RecordLogger). I've also added DiscardLogger since it can be very convenient for tests that want to ignore log output without capturing it. Arguably RecordLogger could be used for this as well, but that would do a poor job of capturing the intend of such code.
ef5a674
to
fd28bf2
Compare
internal/log/log.go
Outdated
// RecordLogger appends every call to Log() to Logs. | ||
type RecordLogger struct { | ||
m sync.Mutex | ||
Logs []string |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We should have some sort of accessor/getter for this, under the mutex. Otherwise we'll get race conditions in tests if someone tries to log and assert output at the same time...
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done in 8c61d7d.
Personally I would not have done this, but I don't feel strongly enough to start a discussion. My initial reaction was that this is solving a problem we don't have yet. Additionally it's encouraging a testing pattern that might not suffer from memory race conditions, but encourages other data races. IMO asserting log output before the test is done is an anti-pattern.
Anyway, as I said, I don't feel strongly about it, so I just made the change.
profiler/profiler_test.go
Outdated
@@ -17,6 +17,7 @@ import ( | |||
|
|||
"github.com/stretchr/testify/assert" | |||
"github.com/stretchr/testify/require" | |||
"gopkg.in/DataDog/dd-trace-go.v1/internal/log" |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please group these in the right place...
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done in bc28e2a - would you be able to explain the rational behind this? I'll have an easier time to remember this if I'm motivated to do it : p.
internal/log/log.go
Outdated
// UseLogger sets l as the active logger and returns the previously configured | ||
// logger. | ||
func UseLogger(l ddtrace.Logger) ddtrace.Logger { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Since this only makes sense in tests (returning the old logger), why not:
// UseLogger sets l as the active logger and returns the previously configured | |
// logger. | |
func UseLogger(l ddtrace.Logger) ddtrace.Logger { | |
// UseLogger sets l as the active logger and returns a function to restore the previous | |
// logger. The return value is mostly useful when testing. | |
func UseLogger(l ddtrace.Logger) (undo func()) { |
Then, in tests, you could do:
defer UseLogger(rc)()
Much shorter and cleaner imho.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done in bce3c86. I considered this but figured it might be overfitting the API to a singular use case. That being said, since we only have this use case for now and it's easy to iterate on an internal package like this, why not : )?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@gbbr thanks for the review! I addressed all your feedback. PTAL
internal/log/log.go
Outdated
// RecordLogger appends every call to Log() to Logs. | ||
type RecordLogger struct { | ||
m sync.Mutex | ||
Logs []string |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done in 8c61d7d.
Personally I would not have done this, but I don't feel strongly enough to start a discussion. My initial reaction was that this is solving a problem we don't have yet. Additionally it's encouraging a testing pattern that might not suffer from memory race conditions, but encourages other data races. IMO asserting log output before the test is done is an anti-pattern.
Anyway, as I said, I don't feel strongly about it, so I just made the change.
profiler/profiler_test.go
Outdated
@@ -17,6 +17,7 @@ import ( | |||
|
|||
"github.com/stretchr/testify/assert" | |||
"github.com/stretchr/testify/require" | |||
"gopkg.in/DataDog/dd-trace-go.v1/internal/log" |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done in bc28e2a - would you be able to explain the rational behind this? I'll have an easier time to remember this if I'm motivated to do it : p.
internal/log/log.go
Outdated
// UseLogger sets l as the active logger and returns the previously configured | ||
// logger. | ||
func UseLogger(l ddtrace.Logger) ddtrace.Logger { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done in bce3c86. I considered this but figured it might be overfitting the API to a singular use case. That being said, since we only have this use case for now and it's easy to iterate on an internal package like this, why not : )?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
All good. Feel free to ignore the nit.
@@ -59,20 +61,30 @@ func TestStart(t *testing.T) { | |||
}) | |||
|
|||
t.Run("options/GoodAPIKey/Agent", func(t *testing.T) { | |||
rl := &log.RecordLogger{} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There isn't really a need for a pointer. This could well be
rl := &log.RecordLogger{} | |
var rl log.RecordLogger |
internal/log: Improve API for testing I just noticed that d9472a0 caused the profiler package to always emit some log output, regardless of `go test -v` being used or not. I'm very sorry about this. IMO tests should never print to stdout unless requested. This patch is my attempt to fix this by making it easy for individual tests to capture the log output (see UseLogger, RecordLogger). I've also added DiscardLogger since it can be very convenient for tests that want to ignore log output without capturing it. Arguably RecordLogger could be used for this as well, but that would do a poor job of capturing the intend of such code.
* 'v1' of https://github.com/DataDog/dd-trace-go: Implement DD_PROFILING_OUTPUT_DIR for dev/debug (DataDog#924) contrib/go-pg/pg.v10: add INTEGRATION flag check for tests (DataDog#921) contrib/go-redis/redis.v8: optimize BeforeProcess and BeforeProcessPipeline (DataDog#920) CI: check go.sum is up-to-date (DataDog#918) README: Fix go get instructions (DataDog#913) internal/log: Improve API for testing (DataDog#916) ddtrace/tracer: add support for agent discovery endpoint, feature flags, stats & drops (DataDog#859) internal/version: bump to v1.31.0 (DataDog#910) CONTRIBUTING.md: add link to contrib/README.md (DataDog#802) profiler: Disable agentless mode for WithAPIKey (DataDog#906) contrib/Shopify/sarama: fix possible deadlock in WrapAsyncProducer (DataDog#907) contrib/database/sql.tracedConn implement driver.SessionResetter (DataDog#908) ddtrace/opentracer: consider FollowsFrom references as children (DataDog#905) ddtrace/opentracer: add support for opentracing.TracerContextWithSpanExtension (DataDog#855) ddtrace/tracer: follow noDebugStack setting when using SetTag with an error (DataDog#900) contrib/net/http: add a getter to retrieve original round tripper (DataDog#903) ddtrace/tracer: ensure Flush call is synchronous (DataDog#901)
I just noticed that d9472a0 caused the profiler package to always emit
some log output, regardless of
go test -v
being used or not. I'm verysorry about this. IMO tests should never print to stdout unless
requested.
This patch is my attempt to fix this by making it easy for individual
tests to capture the log output (see UseLogger, RecordLogger). I've also
added DiscardLogger since it can be very convenient for tests that want
to ignore log output without capturing it. Arguably RecordLogger could
be used for this as well, but that would do a poor job of capturing the
intend of such code.