Problem:
I have a delay of 135 seconds in a unit test to cause a timeout when testing with a real keycloak container and in order to ensure that node-tap does not timeout I have include a t.timout(360000); at the top of the test case as shown below (it is one of many in the file btw).
Have I done something wrong as I am new to TAP? Is this a real bug? If it is is there a work arround for this? (besides setting the global timeout to 6 minutes)?
Test case failing:
t.test('GrantManager should not be able to refresh token after ssoSessionIdleTimeout', (t) => {
t.plan(2);
t.setTimeout(360000); // Change timeout from 30 sec to 360 sec
const fixtureConfig = new Config('./test/fixtures/auth-utils/keycloak-token-test.json');
const manager = new GrantManager(fixtureConfig);
manager.obtainDirectly('bburke@redhat.com', 'password')
.then((grant) => {
return manager.validateAccessToken(grant.access_token)
.then(firstToken => {
t.not(firstToken, false, 'Ensure manager.validateAccessToken token is not empty'); // test #1
console.log('Delay 135 seconds (2 minutes 15 seconds), please wait for delay to complete.');
t.comment('Delay 135 seconds (2 minutes 15 seconds), please wait for delay to complete.');
return grant;
})
.then(
// 15 second ssoSessionIdleTimeout + 120s IDLE_TIMEOUT_WINDOW_SECONDS from
// https://github.com/keycloak/keycloak/blob/master/server-spi-private/src/main/java/org/keycloak/models/utils/SessionTimeoutHelper.java
delay(135000)
)
.then( () => {
return manager.ensureFreshness(grant);
})
.catch((e) => {
t.equal(e.message, 'Unable to refresh with expired refresh token', 'Check manager.ensureFreshness times out due to waiting before calling manager.ensureFreshness'); // test #2
});
})
.catch((e) => {
t.fail(e.message);
})
.finally( () => {
t.end();
})
});
I get a timeout base on the CLI (or default value if no timeout is specified on CLI)
My configuration is
package.json test script:
"test": "./node_modules/.bin/rimraf .nyc_output && ./node_modules/.bin/nyc ./node_modules/.bin/tap --timeout=60 -j1 test/*-spec.js"
TAP v15.0.9
NodeJS v16.1.0
The following snippet from the github action log shows the SIGTERM event and that it occurred after 60 seconds instead of 6 minutes.
2021-05-08T08:07:16.6708016Z # Subtest: GrantManager should not be able to refresh token after ssoSessionIdleTimeout
2021-05-08T08:07:16.6709019Z 1..2
2021-05-08T08:07:16.8045385Z ok 1 - Ensure manager.validateAccessToken token is not empty
2021-05-08T08:07:16.8051645Z Delay 135 seconds (2 minutes 15 seconds), please wait for delay to complete.
2021-05-08T08:08:06.1199173Z # Delay 135 seconds (2 minutes 15 seconds), please wait for delay to complete.
2021-05-08T08:08:06.1200652Z not ok 2 - timeout!
2021-05-08T08:08:06.1201208Z ---
2021-05-08T08:08:06.1201643Z signal: SIGTERM
2021-05-08T08:08:06.1202112Z expired: TAP
2021-05-08T08:08:06.1202546Z stack: |
2021-05-08T08:08:06.1203334Z emit (node_modules/signal-exit/index.js:78:11)
2021-05-08T08:08:06.1204391Z process.listener (node_modules/signal-exit/index.js:92:7)
2021-05-08T08:08:06.1205520Z test: GrantManager should not be able to refresh token after ssoSessionIdleTimeout
2021-05-08T08:08:06.1206272Z ...
2021-05-08T08:08:06.1230642Z
2021-05-08T08:08:06.1236880Z # failed 1 of 2 tests
2021-05-08T08:08:06.1240308Z not ok 2 - GrantManager should not be able to refresh token after ssoSessionIdleTimeout # time=49450.348ms
2021-05-08T08:08:06.1243222Z
2021-05-08T08:08:06.1245982Z 1..2
2021-05-08T08:08:06.1248634Z # failed 1 of 2 tests
2021-05-08T08:08:06.1251308Z # time=59735.154ms
2021-05-08T08:08:06.1346356Z not ok 2 - test/grant-manager-token-timeout-spec.js # time=59735.154ms
2021-05-08T08:08:06.1348051Z ---
2021-05-08T08:08:06.1348628Z env: {}
2021-05-08T08:08:06.1349807Z file: test/grant-manager-token-timeout-spec.js
2021-05-08T08:08:06.1350826Z timeout: 60000
2021-05-08T08:08:06.1351612Z command: /opt/hostedtoolcache/node/16.1.0/x64/bin/node
2021-05-08T08:08:06.1352322Z args:
2021-05-08T08:08:06.1353446Z - test/grant-manager-token-timeout-spec.js
2021-05-08T08:08:06.1354380Z stdio:
2021-05-08T08:08:06.1355456Z - 0
2021-05-08T08:08:06.1356235Z - pipe
2021-05-08T08:08:06.1356991Z - 2
2021-05-08T08:08:06.1359648Z cwd: /home/runner/work/keycloak-nodejs-connect/keycloak-nodejs-connect
2021-05-08T08:08:06.1360714Z exitCode: null
2021-05-08T08:08:06.1361294Z signal: SIGTERM
2021-05-08T08:08:06.1361824Z ...
Problem: I have a delay of 135 seconds in a unit test to cause a timeout when testing with a real keycloak container and in order to ensure that node-tap does not timeout I have include a t.timout(360000); at the top of the test case as shown below (it is one of many in the file btw).
Have I done something wrong as I am new to TAP? Is this a real bug? If it is is there a work arround for this? (besides setting the global timeout to 6 minutes)?
Test case failing:
I get a timeout base on the CLI (or default value if no timeout is specified on CLI)
My configuration is
The following snippet from the github action log shows the SIGTERM event and that it occurred after 60 seconds instead of 6 minutes.