scheduledlogging: shorten TestCaptureIndexUsageStats run time by THardy98 · Pull Request #89319 · cockroachdb/cockroach

THardy98 · 2022-10-04T18:54:53Z

Resolves: #87772

Previously, TestCaptureIndexUsageStats ran through 4 iterations of 20 seconds for a run time of over a minute. This change reduces the run time of the test to under 10 seconds.

Release note: None

cockroach-teamcity · 2022-10-04T18:55:03Z

This change is

knz · 2022-10-05T13:03:38Z

pkg/sql/scheduledlogging/captured_index_usage_stats_test.go

-	// Verify that a second schedule has run after the enabled interval has passed.
+	// Wait for channel value from end of 1st schedule.
+	<-scheduleCompleteChan
+	time.Sleep(timeBuffer)


Why do you need this? Can't you have the main code signal to the test when it's finished writing to logs?

The main code signals to the channel here:

https://github.com/cockroachdb/cockroach/pull/89319/files#diff-567a23559822ff60b8d9d63b7fda0e82a78d11fa6dced531e3f6d24966282362R165

after the logging has completed here:
https://github.com/cockroachdb/cockroach/pull/89319/files#diff-567a23559822ff60b8d9d63b7fda0e82a78d11fa6dced531e3f6d24966282362R153.

For some reason - that I have not been able to figure out why - the logs don't appear if you check immediately, despite logging being completed. The 1 second buffer seems to consistently allow for the logs to appear in the log file, including under stress.

maybe you're missing log.Flush?

Yup, was missing log.Flush, will remove the time.Sleep calls.

knz · 2022-10-05T13:03:44Z

pkg/sql/scheduledlogging/captured_index_usage_stats_test.go

-	// Verify that a third schedule has run after the overlap duration has passed.
+	// Wait for channel value from end of 2nd schedule.
+	<-scheduleCompleteChan
+	time.Sleep(timeBuffer)


removed time.Sleep

knz · 2022-10-05T13:03:56Z

pkg/sql/scheduledlogging/captured_index_usage_stats_test.go

-	}, sd.getOverlapDuration()+timeBuffer)
+	// Wait for channel value from end of 3rd schedule.
+	<-scheduleCompleteChan
+	time.Sleep(timeBuffer)


removed time.Sleep

knz

No objection from me, but please get a review from your own team and teach them what's going on here.

Reviewed 3 of 3 files at r1, 1 of 1 files at r2.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @THardy98)

xinhaoz

What was the reasoning behind using a channel directly in the knobs over a callback function (that then does the same thing, but keeps the channel local to the test). Just wondering if a callback might offer some more flexibility in the future.

THardy98 · 2022-10-05T19:20:19Z

What was the reasoning behind using a channel directly in the knobs over a callback function (that then does the same thing, but keeps the channel local to the test). Just wondering if a callback might offer some more flexibility in the future.

None, I hadn't considered a callback function though I think it's a better idea for the reasons you mentioned. Changed to use a callback instead.

xinhaoz · 2022-10-05T21:26:23Z

pkg/sql/scheduledlogging/captured_index_usage_stats.go line 116 at r3 (raw file):

	}
	// Otherwise, schedule the next interval normally.
	return telemetryCaptureIndexUsageStatsInterval.Get(&s.st.SV) - s.getLoggingDuration()

Can we save the result of s.getLoggingDuration() prior to this block? I guess there is an off chance that the second call here will actually result in a negative value otherwise.

Code quote:

	if s.getLoggingDuration() >= telemetryCaptureIndexUsageStatsInterval.Get(&s.st.SV) {
		return s.durationOnOverlap()
	}
	// Otherwise, schedule the next interval normally.
	return telemetryCaptureIndexUsageStatsInterval.Get(&s.st.SV) - s.getLoggingDuration()

Previously, TestCaptureIndexUsageStats ran through 4 iterations of 20 seconds for a run time of over a minute. This change reduces the run time of the test to under 10 seconds. Release note: None

THardy98

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @xinhaoz)

pkg/sql/scheduledlogging/captured_index_usage_stats.go line 116 at r3 (raw file):

Previously, xinhaoz (Xin Hao Zhang) wrote…

Can we save the result of s.getLoggingDuration() prior to this block? I guess there is an off chance that the second call here will actually result in a negative value otherwise.

Done

xinhaoz

LGTM, just wondering if anyone knows the answer to the question below.

xinhaoz · 2022-10-06T15:20:14Z

pkg/sql/scheduledlogging/captured_index_usage_stats.go

 				return
 			case <-timer.C:
+				if !telemetryCaptureIndexUsageStatsEnabled.Get(&s.st.SV) {
+					timer.Reset(telemetryCaptureIndexUsageStatsStatusCheckEnabledInterval.Get(&s.st.SV))


I'm just wondering out loud here, but I noticed this timer was created directly from the std lib over the one wrapped in timeutil pkg. I recall reading that the timeutil one had a fix relating to Reset or something. Does it matter which one we're using when the return value of Reset isn't being used? 🤔

THardy98 · 2022-10-06T15:58:49Z

TYFR :)

THardy98 · 2022-10-06T15:58:54Z

bors r+

craig · 2022-10-06T16:55:59Z

Build succeeded:

Bazel Essential CI (Cockroach)

blathers-crl · 2022-10-06T16:56:19Z

Encountered an error creating backports. Some common things that can go wrong:

The backport branch might have already existed.
There was a merge conflict.
The backport branch contained merge commits.

You might need to create your backport manually using the backport tool.

error creating merge commit from bb18504 to blathers/backport-release-22.1-89319: POST https://api.github.com/repos/cockroachdb/cockroach/merges: 409 Merge conflict []

you may need to manually resolve merge conflicts with the backport tool.

Backport to branch 22.1.x failed. See errors above.

error creating merge commit from bb18504 to blathers/backport-release-22.2-89319: POST https://api.github.com/repos/cockroachdb/cockroach/merges: 409 Merge conflict []

you may need to manually resolve merge conflicts with the backport tool.

Backport to branch 22.2.x failed. See errors above.

error creating merge commit from bb18504 to blathers/backport-release-22.2.0-89319: POST https://api.github.com/repos/cockroachdb/cockroach/merges: 409 Merge conflict []

you may need to manually resolve merge conflicts with the backport tool.

Backport to branch 22.2.0 failed. See errors above.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is otan.}

maryliag · 2022-10-11T16:54:48Z

looks like your backports failed to be created, can you create them? (you don't need one for 22.2.0)

THardy98 added the T-sql-observability label Oct 4, 2022

THardy98 requested review from a team and knz October 4, 2022 18:54

THardy98 force-pushed the shorten_capture_index_usage_stats_test branch from cd40aa4 to 2ebdca3 Compare October 4, 2022 19:11

knz reviewed Oct 5, 2022

View reviewed changes

THardy98 force-pushed the shorten_capture_index_usage_stats_test branch from 2ebdca3 to 2f0dc3f Compare October 5, 2022 15:11

knz reviewed Oct 5, 2022

View reviewed changes

THardy98 force-pushed the shorten_capture_index_usage_stats_test branch from 2f0dc3f to 4a3faf8 Compare October 5, 2022 15:49

xinhaoz reviewed Oct 5, 2022

View reviewed changes

THardy98 force-pushed the shorten_capture_index_usage_stats_test branch from 4a3faf8 to 127b34f Compare October 5, 2022 19:19

THardy98 added backport-22.2.0 labels Oct 5, 2022

scheduledlogging: shorten TestCaptureIndexUsageStats run time

bb18504

Previously, TestCaptureIndexUsageStats ran through 4 iterations of 20 seconds for a run time of over a minute. This change reduces the run time of the test to under 10 seconds. Release note: None

THardy98 force-pushed the shorten_capture_index_usage_stats_test branch from 127b34f to bb18504 Compare October 6, 2022 14:02

THardy98 commented Oct 6, 2022

View reviewed changes

xinhaoz approved these changes Oct 6, 2022

View reviewed changes

xinhaoz reviewed Oct 6, 2022

View reviewed changes

craig bot merged commit ea43f89 into cockroachdb:master Oct 6, 2022

This was referenced Oct 12, 2022

release-22.2: scheduledlogging: shorten TestCaptureIndexUsageStats run time #89822

Merged

release-22.1: scheduledlogging: shorten TestCaptureIndexUsageStats run time #90072

Merged

Conversation

THardy98 commented Oct 4, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

cockroach-teamcity commented Oct 4, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

THardy98 Oct 5, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

knz left a comment

Choose a reason for hiding this comment

Uh oh!

xinhaoz left a comment

Choose a reason for hiding this comment

Uh oh!

THardy98 commented Oct 5, 2022

Uh oh!

xinhaoz commented Oct 5, 2022

Uh oh!

THardy98 left a comment

Choose a reason for hiding this comment

Uh oh!

xinhaoz left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

THardy98 commented Oct 6, 2022

Uh oh!

THardy98 commented Oct 6, 2022

Uh oh!

craig bot commented Oct 6, 2022

Uh oh!

blathers-crl bot commented Oct 6, 2022

Uh oh!

maryliag commented Oct 11, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

THardy98 commented Oct 4, 2022 •

edited

Loading

THardy98 Oct 5, 2022 •

edited

Loading

xinhaoz left a comment •

edited

Loading