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

sleep() ignored when there's a JS error #688

Closed
SaberStrat opened this issue Jul 4, 2018 · 6 comments
Closed

sleep() ignored when there's a JS error #688

SaberStrat opened this issue Jul 4, 2018 · 6 comments

Comments

@SaberStrat
Copy link

The sleep() function is getting ignored when the JS code in the script produces an error during runtime.
Example:

script.js:

import {sleep} from 'k6';

export default function(){
        console.log("Iteration...");
        someNonsense
        sleep(3);
}

Output:

$ k6 run -i 5 script.js

          /\      |‾‾|  /‾‾/  /‾/
     /\  /  \     |  |_/  /  / /
    /  \/    \    |      |  /  ‾‾\
   /          \   |  |‾\  \ | (_) |
  / __________ \  |__|  \__\ \___/ .io

  execution: local
     output: -
     script: script.js

    duration: -,  iterations: 5
         vus: 1, max: 1

INFO[0001] Iteration...
ERRO[0001] ReferenceError: someNonesense is not defined
        at /home/user/script.js:5:2(7)

INFO[0001] Iteration...
ERRO[0001] ReferenceError: someNonesense is not defined
        at /home/user/script.js:5:2(7)

INFO[0001] Iteration...
ERRO[0001] ReferenceError: someNonesense is not defined
        at /home/user/script.js:5:2(7)

INFO[0001] Iteration...
ERRO[0001] ReferenceError: someNonesense is not defined
        at /home/user/script.js:5:2(7)

INFO[0001] Iteration...
ERRO[0001] ReferenceError: someNonesense is not defined
        at /home/user/script.js:5:2(7)

    done [==========================================================] 5 / 5

    iterations...: 5 4622.900741/s
    vus..........: 1 min=1 max=1
    vus_max......: 1 min=1 max=1

Compared to code that does not produce an error:
script.js:

import {sleep} from 'k6';

export default function(){
        console.log("Iteration...");
        //someNonsense
        sleep(3);
}

Output:

$ k6 run -i 5 script.js

          /\      |‾‾|  /‾‾/  /‾/
     /\  /  \     |  |_/  /  / /
    /  \/    \    |      |  /  ‾‾\
   /          \   |  |‾\  \ | (_) |
  / __________ \  |__|  \__\ \___/ .io

  execution: local
     output: -
     script: script.js

    duration: -,  iterations: 5
         vus: 1, max: 1

INFO[0001] Iteration...
INFO[0004] Iteration...
INFO[0007] Iteration...
INFO[0010] Iteration...
INFO[0013] Iteration...
    done [==========================================================] 5 / 5

    data_received........: 0 B 0 B/s
    data_sent............: 0 B 0 B/s
    iteration_duration...: avg=3s min=3s med=3s max=3s p(90)=3s p(95)=3s
    iterations...........: 5   0.333309/s
    vus..................: 1   min=1 max=1
    vus_max..............: 1   min=1 max=1

This is a trivial example, but the problem has been causing quite the hassle in more complex scripts. For example, when the test parameter isn't iteration, but duration. Judging by the iteration rate above, the output can spam 4623 error messages in 1 second.

@na--
Copy link
Member

na-- commented Jul 4, 2018

I've hit this issue before, only it was with an exception I was trowing. I think you can catch the error in both cases though, this seems to solve the issue:

import { sleep } from 'k6';

export default function () {
	console.log("Iteration...");
	try {
		someNonsense
	}
	catch (err) {
		console.warn(err);
	}
	sleep(3);
}

I don't have a good idea how to fix this by default though. Introducing some sort of minimum iteration time that's enforced by k6 (i.e. after a VU iteration ends in X ms, if it took less than Y ms, sleep for Y-X ms) seems a bit much - some users might want to finish some of the iterations pretty quickly for example.

Edit: just to be clear, sleep() is not ignored, the script execution just never reaches it because it's interrupted before that.

@SaberStrat
Copy link
Author

Makes sense. And catching the error, or fixing it if possible, is the best way. Though I found it a bit unintuitive so to say, that the execution continues after an exception/error:

just to be clear, sleep() is not ignored, the script execution just never reaches it because it's interrupted before that.

In retrospect, it's as you wrote, the script is just interrupted on every iteration. In my head the script corresponded to the test, so I expected the entire test to fail alltogether if it encountered an exception/error.

How about an option parameter that makes the test execution abort in case of a script exception/error?

@na--
Copy link
Member

na-- commented Jul 4, 2018

Edit: nevermind, I totally misread what you wrote...

@na--
Copy link
Member

na-- commented Jul 4, 2018

How about an option parameter that makes the test execution abort in case of a script exception/error?

I think such an option has a lot of merit, but the tricky question is whether it should be enabled by default. If it is disabled by default, we're back to square one - if you know you can hit this issue with exceptions causing "instantaneous" iterations and want to guard against it, you can just use a global try { /* your code */ } catch(e) {sleep(1); throw e; } to avoid the issue and use thresholds that abort the test early if needed.

If it is enabled by default, writing tests can become a lot more complicated. You'd have to very carefully guard and null-check everything. Especially code that parses and uses data from the responses of the tested website, which may become unreliable under the heavy load. In a way, enabling this behavior by default could potentially cause people to have the opposite global try{} catch(e) {} blocks just so they suppress those errors and don't needlessly abort the script.

@SaberStrat
Copy link
Author

I hadn't thought of a global try-catch plus threshold as a workaround :), that's cool. Not the prettiest workaround, but it's a workaround.

Yeah, having it enabled by default is very bad imo and can lead to bad things, as you wrote, when working with response data. So a setting like that should definitely be off by default.

@na--
Copy link
Member

na-- commented Dec 18, 2018

Closing this issue, since one of the solutions discussed here (minimum iteration duration) was implemented in this pull request and was released as part of k6 0.23.0. I also created a new, separate issue for the other idea partially mentioned above (and in a few other places): #877

@na-- na-- closed this as completed Dec 18, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants