-
Notifications
You must be signed in to change notification settings - Fork 38.7k
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
Add performance test phase timing export. #54992
Merged
Merged
Changes from all commits
Commits
Show all changes
2 commits
Select commit
Hold shift + click to select a range
File filter
Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,34 @@ | ||
load("@io_bazel_rules_go//go:def.bzl", "go_library", "go_test") | ||
|
||
go_library( | ||
name = "go_default_library", | ||
srcs = ["timer.go"], | ||
importpath = "k8s.io/kubernetes/test/e2e/framework/timer", | ||
visibility = ["//visibility:public"], | ||
deps = [ | ||
"//test/e2e/framework:go_default_library", | ||
"//test/e2e/perftype:go_default_library", | ||
], | ||
) | ||
|
||
go_test( | ||
name = "go_default_test", | ||
srcs = ["timer_test.go"], | ||
importpath = "k8s.io/kubernetes/test/e2e/framework/timer", | ||
library = ":go_default_library", | ||
deps = ["//vendor/github.com/onsi/gomega:go_default_library"], | ||
) | ||
|
||
filegroup( | ||
name = "package-srcs", | ||
srcs = glob(["**"]), | ||
tags = ["automanaged"], | ||
visibility = ["//visibility:private"], | ||
) | ||
|
||
filegroup( | ||
name = "all-srcs", | ||
srcs = [":package-srcs"], | ||
tags = ["automanaged"], | ||
visibility = ["//visibility:public"], | ||
) |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,126 @@ | ||
/* | ||
Copyright 2017 The Kubernetes Authors. | ||
|
||
Licensed under the Apache License, Version 2.0 (the "License"); | ||
you may not use this file except in compliance with the License. | ||
You may obtain a copy of the License at | ||
|
||
http://www.apache.org/licenses/LICENSE-2.0 | ||
|
||
Unless required by applicable law or agreed to in writing, software | ||
distributed under the License is distributed on an "AS IS" BASIS, | ||
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | ||
See the License for the specific language governing permissions and | ||
limitations under the License. | ||
*/ | ||
|
||
package timer | ||
|
||
import ( | ||
"time" | ||
|
||
"bytes" | ||
"fmt" | ||
|
||
"k8s.io/kubernetes/test/e2e/framework" | ||
"k8s.io/kubernetes/test/e2e/perftype" | ||
"sync" | ||
) | ||
|
||
var now = time.Now | ||
|
||
// Represents a phase of a test. Phases can overlap. | ||
type Phase struct { | ||
sequenceNumber int | ||
name string | ||
startTime time.Time | ||
endTime time.Time | ||
} | ||
|
||
func (phase *Phase) ended() bool { | ||
return !phase.endTime.IsZero() | ||
} | ||
|
||
// End marks the phase as ended, unless it had already been ended before. | ||
func (phase *Phase) End() { | ||
if !phase.ended() { | ||
phase.endTime = now() | ||
} | ||
} | ||
|
||
func (phase *Phase) label() string { | ||
return fmt.Sprintf("%03d-%s", phase.sequenceNumber, phase.name) | ||
} | ||
|
||
func (phase *Phase) duration() time.Duration { | ||
endTime := phase.endTime | ||
if !phase.ended() { | ||
endTime = now() | ||
} | ||
return endTime.Sub(phase.startTime) | ||
} | ||
|
||
func (phase *Phase) humanReadable() string { | ||
if phase.ended() { | ||
return fmt.Sprintf("Phase %s: %v\n", phase.label(), phase.duration()) | ||
} else { | ||
return fmt.Sprintf("Phase %s: %v so far\n", phase.label(), phase.duration()) | ||
} | ||
} | ||
|
||
// A TestPhaseTimer groups phases and provides a way to export their measurements as JSON or human-readable text. | ||
// It is safe to use concurrently. | ||
type TestPhaseTimer struct { | ||
lock sync.Mutex | ||
phases []*Phase | ||
} | ||
|
||
// NewTestPhaseTimer creates a new TestPhaseTimer. | ||
func NewTestPhaseTimer() *TestPhaseTimer { | ||
return &TestPhaseTimer{} | ||
} | ||
|
||
// StartPhase starts a new phase. | ||
// sequenceNumber is an integer prepended to phaseName in the output, such that lexicographic sorting | ||
// of phases in perfdash reconstructs the order of execution. Unfortunately it needs to be | ||
// provided manually, since a simple incrementing counter would have the effect that inserting | ||
// a new phase would renumber subsequent phases, breaking the continuity of historical records. | ||
func (timer *TestPhaseTimer) StartPhase(sequenceNumber int, phaseName string) *Phase { | ||
timer.lock.Lock() | ||
defer timer.lock.Unlock() | ||
newPhase := &Phase{sequenceNumber: sequenceNumber, name: phaseName, startTime: now()} | ||
timer.phases = append(timer.phases, newPhase) | ||
return newPhase | ||
} | ||
|
||
func (timer *TestPhaseTimer) SummaryKind() string { | ||
return "TestPhaseTimer" | ||
} | ||
|
||
func (timer *TestPhaseTimer) PrintHumanReadable() string { | ||
buf := bytes.Buffer{} | ||
timer.lock.Lock() | ||
defer timer.lock.Unlock() | ||
for _, phase := range timer.phases { | ||
buf.WriteString(phase.humanReadable()) | ||
} | ||
return buf.String() | ||
} | ||
|
||
func (timer *TestPhaseTimer) PrintJSON() string { | ||
data := perftype.PerfData{ | ||
Version: "v1", | ||
DataItems: []perftype.DataItem{{ | ||
Unit: "s", | ||
Labels: map[string]string{"test": "phases"}, | ||
Data: make(map[string]float64)}}} | ||
timer.lock.Lock() | ||
defer timer.lock.Unlock() | ||
for _, phase := range timer.phases { | ||
data.DataItems[0].Data[phase.label()] = phase.duration().Seconds() | ||
if !phase.ended() { | ||
data.DataItems[0].Labels["ended"] = "false" | ||
} | ||
} | ||
return framework.PrettyPrintJSON(data) | ||
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,92 @@ | ||
/* | ||
Copyright 2017 The Kubernetes Authors. | ||
|
||
Licensed under the Apache License, Version 2.0 (the "License"); | ||
you may not use this file except in compliance with the License. | ||
You may obtain a copy of the License at | ||
|
||
http://www.apache.org/licenses/LICENSE-2.0 | ||
|
||
Unless required by applicable law or agreed to in writing, software | ||
distributed under the License is distributed on an "AS IS" BASIS, | ||
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | ||
See the License for the specific language governing permissions and | ||
limitations under the License. | ||
*/ | ||
|
||
package timer | ||
|
||
import ( | ||
"testing" | ||
"time" | ||
|
||
. "github.com/onsi/gomega" | ||
) | ||
|
||
var currentTime time.Time | ||
|
||
func init() { | ||
setCurrentTimeSinceEpoch(0) | ||
now = func() time.Time { return currentTime } | ||
} | ||
|
||
func setCurrentTimeSinceEpoch(duration time.Duration) { | ||
currentTime = time.Unix(0, duration.Nanoseconds()) | ||
} | ||
|
||
func testUsageWithDefer(timer *TestPhaseTimer) { | ||
defer timer.StartPhase(33, "two").End() | ||
setCurrentTimeSinceEpoch(6*time.Second + 500*time.Millisecond) | ||
} | ||
|
||
func TestTimer(t *testing.T) { | ||
RegisterTestingT(t) | ||
|
||
timer := NewTestPhaseTimer() | ||
setCurrentTimeSinceEpoch(1 * time.Second) | ||
phaseOne := timer.StartPhase(1, "one") | ||
setCurrentTimeSinceEpoch(3 * time.Second) | ||
testUsageWithDefer(timer) | ||
|
||
Expect(timer.PrintJSON()).To(MatchJSON(`{ | ||
"version": "v1", | ||
"dataItems": [ | ||
{ | ||
"data": { | ||
"001-one": 5.5, | ||
"033-two": 3.5 | ||
}, | ||
"unit": "s", | ||
"labels": { | ||
"test": "phases", | ||
"ended": "false" | ||
} | ||
} | ||
] | ||
}`)) | ||
Expect(timer.PrintHumanReadable()).To(Equal(`Phase 001-one: 5.5s so far | ||
Phase 033-two: 3.5s | ||
`)) | ||
|
||
setCurrentTimeSinceEpoch(7*time.Second + 500*time.Millisecond) | ||
phaseOne.End() | ||
|
||
Expect(timer.PrintJSON()).To(MatchJSON(`{ | ||
"version": "v1", | ||
"dataItems": [ | ||
{ | ||
"data": { | ||
"001-one": 6.5, | ||
"033-two": 3.5 | ||
}, | ||
"unit": "s", | ||
"labels": { | ||
"test": "phases" | ||
} | ||
} | ||
] | ||
}`)) | ||
Expect(timer.PrintHumanReadable()).To(Equal(`Phase 001-one: 6.5s | ||
Phase 033-two: 3.5s | ||
`)) | ||
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
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.
You seem to set this sequence number manually for ordering the steps. However, that doesn't seem very convenient and is an overhead for someone adding new phases to rightly calculate it by looking at ordering of other code blocks. I suggest automating it - probably by using a counter inside TestPhaseTimer.
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.
I added a comment to StartPhase explaining why this is necessary.
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.
Yup.. saw that. But I'm not sure I understand why that can't be auto-calculated using a counter?
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 address.
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.
Are you sure you've seen the extended comment at https://github.com/kubernetes/kubernetes/pull/54992/files#diff-798659a13d17841486bbd8ceb70acb64R87? I pushed it only a dozen or so minutes ago, so I don't think that's what you referred to when writing "Yup.. saw that."? Let me know if it's still not clear enough.
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.
Nope... I was seeing the older comments when I wrote that:
I'm still not convinced that the way to solve the issue with ordering for perfdash is by using such synthetic numbering. The msg should be used as the phase ID instead. Besides, what if we run out of numbers in b/w 2 steps?
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.
I agree that it would be best if there was a separate field for sorting, and another to use as a stable label. But currently the
perftype.DataItem
schema does not support that. So this concatenation of 3-digit number and label is a hack to get around that limitation.It's no big deal if we run out of numbers: we'll just reuse them, they don't have to be unique. This hack is only meant to provide rough sorting, such that initialization steps at least show up earlier than shutdown steps. I think it's better than having a complete mess, but if you feel strongly against it, I can remove the numeric prefix.
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.
That's alright for now.