-
Notifications
You must be signed in to change notification settings - Fork 1.2k
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 ability to display intermediate result while the test is running #1849
Add ability to display intermediate result while the test is running #1849
Conversation
Thanks, we'll take a look soon! Before that, can you forego the update of the |
9fd84f2
to
81bed3b
Compare
done. |
35d979a
to
f6e81ca
Compare
Codecov Report
@@ Coverage Diff @@
## master #1849 +/- ##
==========================================
- Coverage 71.57% 71.46% -0.11%
==========================================
Files 179 179
Lines 13930 13957 +27
==========================================
+ Hits 9971 9975 +4
- Misses 3327 3350 +23
Partials 632 632
Flags with carried forward coverage won't be shown. Click here to find out more.
Continue to review full report at Codecov.
|
f6e81ca
to
164f911
Compare
164f911
to
a379c37
Compare
f6e81ca
to
3e3873e
Compare
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.
Thanks for making the PR! While it technically satisfies most of the requirements of the issue, there are some bugs, as well as several things that aren't done optimally - both from an UX and from an implementation perspective. I've noted some of them as inline comments and I'll explain the rest below.
First, there seem to be some data races when we run k6 with go run -race
:
Write at 0x00c000d94000 by goroutine 26:
github.com/loadimpact/k6/cmd.showProgress.func2()
github.com/loadimpact/k6/cmd/ui.go:296 +0x1ef
github.com/loadimpact/k6/cmd.showProgress()
github.com/loadimpact/k6/cmd/ui.go:363 +0x3c5
github.com/loadimpact/k6/cmd.getRunCmd.func1.1()
github.com/loadimpact/k6/cmd/run.go:191 +0x2cd
Previous read at 0x00c000d94000 by goroutine 32:
github.com/loadimpact/k6/cmd.showProgress.func1()
github.com/loadimpact/k6/cmd/ui.go:288 +0x90
github.com/loadimpact/k6/cmd.(*consoleWriter).Write()
github.com/loadimpact/k6/cmd/ui.go:73 +0x24a
bytes.(*Buffer).WriteTo()
bytes/buffer.go:239 +0x1e7
io.copyBuffer()
io/io.go:391 +0x482
io.Copy()
io/io.go:368 +0x464
github.com/loadimpact/k6/cmd.handleSummaryResult()
github.com/loadimpact/k6/cmd/run.go:453 +0x474
github.com/loadimpact/k6/cmd.printSummaryResults()
github.com/loadimpact/k6/cmd/run.go:473 +0x2e4
github.com/loadimpact/k6/cmd.readInput()
github.com/loadimpact/k6/cmd/run.go:502 +0x225
github.com/loadimpact/k6/cmd.getRunCmd.func1.4()
github.com/loadimpact/k6/cmd/run.go:258 +0x8a
and
Read at 0x00c00270a608 by goroutine 32:
github.com/loadimpact/k6/stats.(*RateSink).Calc()
<autogenerated>:1 +0x4f
github.com/loadimpact/k6/js.metricValueGetter.func1()
github.com/loadimpact/k6/js/summary.go:129 +0x72
github.com/loadimpact/k6/js.summarizeMetricsToObject()
github.com/loadimpact/k6/js/summary.go:176 +0x638
github.com/loadimpact/k6/js.(*Runner).HandleSummary()
github.com/loadimpact/k6/js/runner.go:312 +0x117
github.com/loadimpact/k6/cmd.printSummaryResults()
github.com/loadimpact/k6/cmd/run.go:467 +0x1ab
github.com/loadimpact/k6/cmd.readInput()
github.com/loadimpact/k6/cmd/run.go:502 +0x225
github.com/loadimpact/k6/cmd.getRunCmd.func1.4()
github.com/loadimpact/k6/cmd/run.go:258 +0x8a
Previous write at 0x00c00270a608 by goroutine 48:
github.com/loadimpact/k6/stats.(*RateSink).Add()
github.com/loadimpact/k6/stats/sink.go:168 +0x64
github.com/loadimpact/k6/core.(*Engine).processSamplesForMetrics()
github.com/loadimpact/k6/core/engine.go:413 +0xc1b
github.com/loadimpact/k6/core.(*Engine).processSamples()
github.com/loadimpact/k6/core/engine.go:443 +0x10b
github.com/loadimpact/k6/core.(*Engine).processMetrics.func2()
github.com/loadimpact/k6/core/engine.go:275 +0x38e
github.com/loadimpact/k6/core.(*Engine).processMetrics()
github.com/loadimpact/k6/core/engine.go:285 +0x333
And this is when the handleSummary()
call is synchronous with detecting the key presses, which it probably shouldn't be (see inline comment on the topic). I also realize that testing UI input is very difficult, but some tests of the actual logic here (without any keyboard) would have probably caught at least the second data race in CI. So please add some... 😅
Finally, I am not sure about the https://github.com/eiannone/keyboard dependency... It has some scary open issues, and me and @imiric actually managed to hit a strange bug we think was caused by the dependency. We haven't been able to consistently reproduce it, but we somehow managed to enter a state where hitting Esc
would sometimes disable special input entirely, ignoring even Ctrl-C
/ Ctrl-Z
! This messed up the terminal even after k6 exits - Ctrl-C/Ctrl-Z were ignored and are printed instead, and the only fix was running reset
in the terminal... 😕 We independently hit the issue while testing your code, him twice and me once, but we can't reproduce it consistently... 🤷♂️
Also, in general, I am not sure such a dependency is needed. See this SO answer for example. You can use golang.org/x/term.MakeRaw()
to switch the terminal to raw mode (and back to cooked mode at the end of k6) and just read a single character from stdin
. There are other ways to check what stdin actually is as well: https://stackoverflow.com/a/26567513/9629802
We already use a precursor to this stdlib-adjacent library, golang.org/x/crypto/ssh/terminal
for k6 login
forms and progressbars. I think using the same golang.org/x
dependency for reading characters from stdin
would have a much lower possibility of issues long-term. And if for some reason that library doesn't work on some OS, there seem to be a lot of drop-in replacements that enable setting terminals to raw mode (e.g. https://github.com/containerd/console, https://github.com/pkg/term), whereas this keyboard
seems to be its own special thing that doesn't work very well...
cmd/run.go
Outdated
@@ -457,3 +457,55 @@ func handleSummaryResult(fs afero.Fs, stdOut, stdErr io.Writer, result map[strin | |||
|
|||
return consolidateErrorMessage(errs, "Could not save some summary information:") | |||
} | |||
|
|||
func printSummaryResults(globalCtx context.Context, |
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.
This is a potentially a wrong name - handleSummary()
might not print anything to stdout or stderr, it might just write files.
Also, I realize that stdout
and stderr
are unfortunately global variables. We want to clean that up eventually, and the way to do that is to use dependency injection even with them, i.e. pass them as parameters. See how handleSummaryResult()
expects them as parameters, despite also having access to the same global variables directly. As a side-benefit, this also makes it much more testable...
cmd/run.go
Outdated
defer func() { | ||
_ = keyboard.Close() | ||
}() | ||
fmt.Println("Press R to get summary or esc to run Ctrl-C/Ctrl-Z") |
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.
This is suboptimal in two different ways. First, instead of directly printing to stdout with fmt.Println()
, it would be much better to use fmt.Fprintf(stdout, "Press R...")
, ideally with stdout
being injected as parameter.
Second, and more importantly, we wouldn't want to enter a separate state to handle R
specifically and ignore Ctrl+C
. If you must capture all keyboard input exclusively here, you can simply capture Ctrl+C as well and send an event over sigC
, so the Ctrl+C handling occurs normally. And if we don't have a separate mode for the summary, we don't need this message at all.
cmd/run.go
Outdated
return err | ||
} | ||
defer func() { | ||
_ = keyboard.Close() |
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.
An error here probably deserves at least logging it, you already have the logger anyway.
cmd/run.go
Outdated
forLoop: | ||
for { | ||
event := <-keysEvents |
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.
Why this code and not for event := range keysEvents
{}?
@@ -251,6 +252,15 @@ a commandline interface for interacting with it.`, | |||
os.Exit(externalAbortErrorCode) | |||
}() | |||
|
|||
// start reading user input | |||
if !runtimeOptions.NoSummary.Bool { |
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.
Checking if stdin is a terminal here is probably a good idea. I don't know how the github.com/eiannone/keyboard
dependency would react if it isn't, but at best, we're going to get a useless error in the logs from logger.Error(riErr)
below, when it fails on most CI systems to listen to key presses.
cmd/run.go
Outdated
return event.Err | ||
} | ||
if event.Rune == 'R' { | ||
printSummaryResults(globalCtx, runner, engine, executionState, 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.
This can potentially take quite a long time, e.g. if you have a ton of metrics data or you make HTTP requests in handleSummary()
. With the current code, k6 would be stuck waiting for it to complete before it processes any other input, including Esc
or Ctrl+C
... So, this needs to happen asynchronously.
To easily replicate the issue, try putting sleep(5)
in handleSummary()
and see how this code behaves.
few notes:
still there are few small bugs, i'm trying to fix right now. in OSX it's still break terminal size... so Please let me know wdyt regarding new approach? |
b0607f3
to
227eaa9
Compare
on separate note: |
I haven't looked at the new code, but yes, we'd like this feature to not require hitting enter after whatever trigger we've decided is written ( |
Few links might help when you try on your side: |
Wow, so this turned out to be a can of worms... 😅 Sorry Andrii! There's a couple of issues with the current implementation:
Given that k6 constantly writes to stdout, we can't really switch to raw mode for this feature. So how about this: interpret The obvious drawback of this is that we can't listen for any other key presses, but I'd argue that we really shouldn't anyway. WDYT? |
Thanks for the PR @AndriiChuzhynov 🎉 quick thoughts before actually looking at the code:
I have the feeling all of those visual artifacts are due to one problem, and fixing them IMO is more important than whether we will be hitting enter or not. I at least don't get my terminal botched if I additionally (although this is likely unfixable for now) if the scripts are read from the stdin as in edit: I am fine with just hitting enter as well as @imiric proposes. |
f376629
to
a0f18e7
Compare
@na-- @imiric @mstoykov
but than... i get stucked on any ideas where to check to fix this RC: but concerned how to fix showProgress one:
looks like we have global variable to lock also i found i can reproduce this bug from time to time in master branch ^^ using 0dd04a3 issue #1860 has been created. |
00a39d3
to
991f1ee
Compare
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.
Thanks for fixing the data race and reporting the one we have on master
! I've tested your latest code and it works, though it's apparent we have to go back to the drawing board with the feature itself... 😞 The UX of the current approach is not great, but the complexity and fragility of the alternative is also bad, even if we manage to get it working nicely without a full-blown ncurses-like CLI UI... I've added a note in #1315 to that effect and tag the issue as evaluation needed
.
The locking you've employed to get rid of the data race also deserves some further consideration and improvements. I'll try to explain, even though there's no point in doing the work for now, given that it doesn't seem likely we'll merge the feature soon because of the other problems with the whole feature.
You are currently locking the whole Engine
from processing new metrics and thresholds for the whole duration of handleSummary()
, however handleSummary()
can potentially take quite a long time to execute if it makes HTTP requests or something like that. If it takes a long time, various VUs can continue generating new metric samples and sending them to the buffered metric Samples
channel in the Engine
. I think it has a size of 1000 by default, and if that ever overflows, VUs will be blocked, which would affect the load test execution negatively.
A better locking approach instead would be to only lock the Engine.MetricsLock
only while we export the data we pass to handleSummary
, but not during the actual execution of the callback. So, basically, wrap this line: https://github.com/loadimpact/k6/blob/6bebdd632eceadf6f8b50d4c47814b3a1688e976/js/runner.go#L312
Or do it inside of the actual summarizeMetricsToObject()
function: https://github.com/loadimpact/k6/blob/6bebdd632eceadf6f8b50d4c47814b3a1688e976/js/summary.go#L160
But as I said, no need to fix this or spend any more time on improvements until we're sure what we want to do here. And despite the fact we're not going to merge the PR for now, the whole effort has been very useful in illuminating all of the tricky issues here, so thank you very much for that and sorry again for the unexpected complexity!
|
I'll close this so it doesn't clutter the list with open PRs. We are not going to merge it as it is, for the reasons explained in #1849 (review), and any lessons learned can still be gleaned from a closed PR, given that it's linked in #1315 (which I'll keep open). |
Closes #1315
https://terminalizer.com/view/fc96dd924634
Example of usage.