--Task-- name: Reporting_authn-users-1500 enabled: True class_name: GatlingResultTask source_name: overseer-0 source_namespace: >default< target_name: overseer-0 target_namespace: >default< start: 0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates bellow loop: False interval: None dependencies: [] wait_for: ['Reporting_authn-users-100', 'Reporting_authn-users-400', 'Reporting_authn-users-800', 'Reporting_authn-users-1200'] options: {'task_name': 'authn-users-1500'} group_name: None Current dir: /mnt/disks/data/xslou/lodestar-fork/pyrock ________________________________________________________________________________ [28/Sep/2022 00:56:50] Reporting_authn-users-1500 pre : N/A ________________________________________________________________________________ source (overseer-0) is a component [28/Sep/2022 00:56:50] - INFO: Timeout for this Task has changed to 1h (3600 seconds) Pod stdout file : /results/orders/Reporting_authn-users-1500/stdout.txt Pod stderr file : /results/orders/Reporting_authn-users-1500/stderr.txt Pod log : /results/orders/Reporting_authn-users-1500 ________________________________________________________________________________ [28/Sep/2022 00:56:50] Reporting_authn-users-1500 step1 : Write order for overseer to generate the report ________________________________________________________________________________ Order file : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/order.json { "name": "Reporting_authn-users-1500", "command": "/lodestar/clients/gatling-report-only-for-pyrock.sh authn-users-1500", "out-dir": "/results/orders/Reporting_authn-users-1500" } ________________________________________________________________________________ [28/Sep/2022 00:56:50] Reporting_authn-users-1500 step2 : Make sure overseer is ready to accept order (not already busy) ________________________________________________________________________________ [loop_until]: curl -k https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" [loop_until]: (max_time=120, interval=5, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found [loop_until]: OK (rc = 0) --- stdout --- WAITING --- stderr --- % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 22 0 --:--:-- --:--:-- --:--:-- 22 ________________________________________________________________________________ [28/Sep/2022 00:56:51] Reporting_authn-users-1500 step3 : Send order to overseer ________________________________________________________________________________ [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou cp /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/order.json overseer-0-c7fc5cc47-x4c97:/results/orders/order.json [loop_until]: (max_time=180, interval=5, expected_rc=[0] [loop_until]: OK (rc = 0) --- stdout --- --- stderr --- Order has been successfully forwarded to overseer ________________________________________________________________________________ [28/Sep/2022 00:56:52] Reporting_authn-users-1500 step4 : Wait order is done ________________________________________________________________________________ Workaround for PERF-1966. Sleeping for 5 seconds. [loop_until]: curl -k https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" [loop_until]: (max_time=3600, interval=5, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 5s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 10s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 16s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 21s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 26s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 31s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 37s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 42s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 47s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 53s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 58s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 03s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 08s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 14s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 19s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 24s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 29s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 35s (rc=0) - failed to find expected output: WAITING - retry [loop_until]: Function succeeded after 1m 40s (rc=0) - expected pattern found [loop_until]: OK (rc = 0) --- stdout --- WAITING --- stderr --- % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 30 0 --:--:-- --:--:-- --:--:-- 30 ________________________________________________________________________________ [28/Sep/2022 00:58:38] Reporting_authn-users-1500 step5 : Wait until gatling report is generated on overseer ________________________________________________________________________________ [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- Checking pod: overseer-0-c7fc5cc47-x4c97 for file exists, if not wait. [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- bash -c 'if [ -f "/results/gatling/authn-users-1500.tar.gz" ]; then echo "/results/gatling/authn-users-1500.tar.gz file found"; exit 0; else echo "/results/gatling/authn-users-1500.tar.gz file not found"; exit 1; fi' | grep "/results/gatling/authn-users-1500.tar.gz file found" [loop_until]: (max_time=180, interval=5, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found [loop_until]: OK (rc = 0) --- stdout --- /results/gatling/authn-users-1500.tar.gz file found --- stderr --- [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [run_command]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- du -k /results/gatling/authn-users-1500.tar.gz [run_command]: OK (rc = 0 - expected to be in [0]) --- stdout --- 372 /results/gatling/authn-users-1500.tar.gz --- stderr --- - Download file (size 372k) [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- source : /results/gatling/authn-users-1500.tar.gz @ overseer-0-c7fc5cc47-x4c97 destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/shared/authn-users-1500.tar.gz [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou cp overseer-0-c7fc5cc47-x4c97:/results/gatling/authn-users-1500.tar.gz /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/shared/authn-users-1500.tar.gz [loop_until]: (max_time=-1, interval=5, expected_rc=[0] [loop_until]: OK (rc = 0) --- stdout --- tar: Removing leading `/' from member names --- stderr --- ________________________________________________________________________________ [28/Sep/2022 00:58:42] Reporting_authn-users-1500 step6 : Unzip the result ________________________________________________________________________________ [run_command]: tar zxf /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/shared/authn-users-1500.tar.gz -C /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/05_scenario/05_authn-users-1500/gatling [run_command]: OK (rc = 0 - expected to be in [0]) --- stdout --- --- stderr --- ________________________________________________________________________________ [28/Sep/2022 00:58:42] Reporting_authn-users-1500 step7 : Print rc order ________________________________________________________________________________ [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- Checking pod: overseer-0-c7fc5cc47-x4c97 for file exists, if not wait. [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- bash -c 'if [ -f "/results/orders/Reporting_authn-users-1500/rc.txt" ]; then echo "/results/orders/Reporting_authn-users-1500/rc.txt file found"; exit 0; else echo "/results/orders/Reporting_authn-users-1500/rc.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting_authn-users-1500/rc.txt file found" [loop_until]: (max_time=180, interval=5, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found [loop_until]: OK (rc = 0) --- stdout --- /results/orders/Reporting_authn-users-1500/rc.txt file found --- stderr --- [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [run_command]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- du -k /results/orders/Reporting_authn-users-1500/rc.txt [run_command]: OK (rc = 0 - expected to be in [0]) --- stdout --- 4 /results/orders/Reporting_authn-users-1500/rc.txt --- stderr --- - Download file (size 4k) [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- source : /results/orders/Reporting_authn-users-1500/rc.txt @ overseer-0-c7fc5cc47-x4c97 destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/rc.txt [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou cp overseer-0-c7fc5cc47-x4c97:/results/orders/Reporting_authn-users-1500/rc.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/rc.txt [loop_until]: (max_time=-1, interval=5, expected_rc=[0] [loop_until]: OK (rc = 0) --- stdout --- tar: Removing leading `/' from member names --- stderr --- [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/rc.txt is small (1 lines), printing all lines: ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [28/Sep/2022 00:58:47] Reporting_authn-users-1500 step8 : Check rc log ________________________________________________________________________________ PASS: no error found in rc log ________________________________________________________________________________ [28/Sep/2022 00:58:47] Reporting_authn-users-1500 step9 : Print stdout order ________________________________________________________________________________ [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- Checking pod: overseer-0-c7fc5cc47-x4c97 for file exists, if not wait. [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- bash -c 'if [ -f "/results/orders/Reporting_authn-users-1500/stdout.txt" ]; then echo "/results/orders/Reporting_authn-users-1500/stdout.txt file found"; exit 0; else echo "/results/orders/Reporting_authn-users-1500/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting_authn-users-1500/stdout.txt file found" [loop_until]: (max_time=180, interval=5, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found [loop_until]: OK (rc = 0) --- stdout --- /results/orders/Reporting_authn-users-1500/stdout.txt file found --- stderr --- [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [run_command]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- du -k /results/orders/Reporting_authn-users-1500/stdout.txt [run_command]: OK (rc = 0 - expected to be in [0]) --- stdout --- 8 /results/orders/Reporting_authn-users-1500/stdout.txt --- stderr --- - Download file (size 8k) [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- source : /results/orders/Reporting_authn-users-1500/stdout.txt @ overseer-0-c7fc5cc47-x4c97 destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/stdout.txt [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou cp overseer-0-c7fc5cc47-x4c97:/results/orders/Reporting_authn-users-1500/stdout.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/stdout.txt [loop_until]: (max_time=-1, interval=5, expected_rc=[0] [loop_until]: OK (rc = 0) --- stdout --- tar: Removing leading `/' from member names --- stderr --- [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/stdout.txt is small (93 lines), printing all lines: ----- output ----- [cmd] /lodestar/clients/gatling/bin/gatling.sh -ro /results/gatling/authn-users-1500/loadtest-20220927234610015 GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling Parsing log file(s)... Parsing log file(s) done Generating reports... ================================================================================ ---- Global Information -------------------------------------------------------- > request count 10575964 (OK=9324252 KO=1251712) > min response time 13 (OK=19 KO=13 ) > max response time 61437 (OK=61437 KO=60696 ) > mean response time 4956 (OK=4947 KO=5024 ) > std deviation 5699 (OK=4655 KO=10631 ) > response time 50th percentile 4308 (OK=4505 KO=594 ) > response time 75th percentile 6213 (OK=6263 KO=4774 ) > response time 95th percentile 11573 (OK=10626 KO=16275 ) > response time 99th percentile 29840 (OK=27449 KO=60052 ) > mean requests/sec 2955.831 (OK=2605.996 KO=349.836) ---- Response Time Distribution ------------------------------------------------ > t < 800 ms 1070123 ( 10%) > 800 ms < t < 1200 ms 275507 ( 3%) > t > 1200 ms 7978622 ( 75%) > failed 1251712 ( 12%) ---- Errors -------------------------------------------------------------------- > status.find.is(200), but actually found 503 653175 (29.56%) > restloginProgressiveProfileCallback: Failed to build request: 478942 (21.68%) No attribute named 'callbacks' is defined > restLoginUsernamePasswordCallback: Failed to build request: No 478942 (21.68%) attribute named 'callbacks' is defined > status.find.is(200), but actually found 502 374232 (16.94%) > status.find.is(200), but actually found 400 163544 ( 7.40%) > i.g.h.c.i.RequestTimeoutException: Request timeout to openam-p 34527 ( 1.56%) erf-100m-testing.forgeblocks.com/34.111.179.107:443 after 6000... > status.find.is(200), but actually found 401 13029 ( 0.59%) > jsonPath($.tokenId).find.exists, found nothing 12301 ( 0.56%) > i.n.c.AbstractChannel$AnnotatedSocketException: Cannot assign 892 ( 0.04%) requested address: openam-perf-100m-testing.forgeblocks.com/34... > i.n.c.ConnectTimeoutException: connection timed out: openam-pe 9 ( 0.00%) rf-100m-testing.forgeblocks.com/34.111.179.107:443 > j.i.IOException: Premature close 3 ( 0.00%) ================================================================================ Reports generated in 0s. Please open the following file: /results/gatling/authn-users-1500/loadtest-20220927234610015/index.html ---------------------- [28/Sep/2022 01:58:33] Create tar file /results/gatling/authn-users-1500.tar.gz ---------------------- SIMULATION_PATH=/results/gatling/authn-users-1500/loadtest-20220927234610015 RESULT_FOLDER=authn-users-1500 RESULT_PATH=/results/gatling/authn-users-1500 PWD=/results/gatling/authn-users-1500/loadtest-20220927234610015 [cmd] tar -czvf /results/gatling/authn-users-1500.tar.gz --exclude=simulation.log * index.html js/ js/theme.js js/assertions.json js/bootstrap.min.js js/stats.json js/highstock.js js/moment.min.js js/highcharts-more.js js/assertions.xml js/menu.js js/global_stats.json js/jquery.min.js js/stats.js js/unpack.js js/gatling.js js/all_sessions.js req_restlogininitia-e2b9b.html req_restloginprogre-9fc93.html req_restloginuserna-d98ea.html style/ style/logo.png style/stat-fond.png style/arrow_right_black.png style/logo-gatling.jpg style/arrow_down_black.png style/arrow_down.png style/stat-l-roue.png style/stat-fleche-bas.png style/cible.png style/logo.svg style/arrow_right.png style/bootstrap.min.css style/stat-l-temps.png style/favicon.ico style/style.css style/little_arrow_right.png style/sortable.png style/sorted-down.png style/sorted-up.png ________________________________________________________________________________ [28/Sep/2022 00:58:51] Reporting_authn-users-1500 step10 : Check stdout log ________________________________________________________________________________ PASS: no error found in stdout log ________________________________________________________________________________ [28/Sep/2022 00:58:51] Reporting_authn-users-1500 step11 : Print stderr order ________________________________________________________________________________ [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- Checking pod: overseer-0-c7fc5cc47-x4c97 for file exists, if not wait. [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- bash -c 'if [ -f "/results/orders/Reporting_authn-users-1500/stderr.txt" ]; then echo "/results/orders/Reporting_authn-users-1500/stderr.txt file found"; exit 0; else echo "/results/orders/Reporting_authn-users-1500/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting_authn-users-1500/stderr.txt file found" [loop_until]: (max_time=180, interval=5, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found [loop_until]: OK (rc = 0) --- stdout --- /results/orders/Reporting_authn-users-1500/stderr.txt file found --- stderr --- [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [run_command]: kubectl --namespace=xlou exec overseer-0-c7fc5cc47-x4c97 -i -- du -k /results/orders/Reporting_authn-users-1500/stderr.txt [run_command]: OK (rc = 0 - expected to be in [0]) --- stdout --- 0 /results/orders/Reporting_authn-users-1500/stderr.txt --- stderr --- - Download file (size 0k) [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- source : /results/orders/Reporting_authn-users-1500/stderr.txt @ overseer-0-c7fc5cc47-x4c97 destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/stderr.txt [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou get pods -l app=overseer-0 -o jsonpath={.items[*].metadata.name}` | grep 1 [loop_until]: (max_time=180, interval=10, expected_rc=[0] [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found [loop_until]: OK (rc = 0) --- stdout --- overseer-0-c7fc5cc47-x4c97 --- stderr --- [loop_until]: kubectl --namespace=xlou cp overseer-0-c7fc5cc47-x4c97:/results/orders/Reporting_authn-users-1500/stderr.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/stderr.txt [loop_until]: (max_time=-1, interval=5, expected_rc=[0] [loop_until]: OK (rc = 0) --- stdout --- tar: Removing leading `/' from member names --- stderr --- [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/06_Verification/08_Reporting_authn-users-1500/stderr.txt is small (0 lines), printing all lines: ----- output ----- ________________________________________________________________________________ [28/Sep/2022 00:58:55] Reporting_authn-users-1500 step12 : Check stderr log ________________________________________________________________________________ PASS: no error found in stderr log ________________________________________________________________________________ [28/Sep/2022 00:58:55] Reporting_authn-users-1500 step13 : Analyze graphs for spikes ________________________________________________________________________________ Analyze Gatling graphs for spikes checking parameters open overall stats JSON file checking simulation request restLoginInitiate checking simulation request restLoginUsernamePasswordCallback checking simulation request restloginProgressiveProfileCallback 26 spikes found - see "spikes" sections in js/stats.json ________________________________________________________________________________ [28/Sep/2022 00:58:55] Reporting_authn-users-1500 step14 : Collect gatling simulation data ________________________________________________________________________________ collected stats : { "global": { "name": "Global Information", "numberOfRequests": { "total": 10575964, "ok": 9324252, "ko": 1251712 }, "minResponseTime": { "total": 13, "ok": 19, "ko": 13 }, "maxResponseTime": { "total": 61437, "ok": 61437, "ko": 60696 }, "meanResponseTime": { "total": 4956, "ok": 4947, "ko": 5024 }, "standardDeviation": { "total": 5699, "ok": 4655, "ko": 10631 }, "percentiles1": { "total": 4308, "ok": 4505, "ko": 594 }, "percentiles2": { "total": 6213, "ok": 6263, "ko": 4774 }, "percentiles3": { "total": 11573, "ok": 10626, "ko": 16275 }, "percentiles4": { "total": 29840, "ok": 27449, "ko": 60052 }, "group1": { "name": "t < 800 ms", "count": 1070123, "percentage": 10 }, "group2": { "name": "800 ms < t < 1200 ms", "count": 275507, "percentage": 3 }, "group3": { "name": "t > 1200 ms", "count": 7978622, "percentage": 75 }, "group4": { "name": "failed", "count": 1251712, "percentage": 12 }, "meanNumberOfRequestsPerSecond": { "total": 2955.831190609279, "ok": 2605.9955282280603, "ko": 349.8356623812186 } }, "details": [ { "name": "restLoginInitiate", "numberOfRequests": { "total": 5336602, "ok": 4857660, "ko": 478942 }, "minResponseTime": { "total": 13, "ok": 19, "ko": 13 }, "maxResponseTime": { "total": 60696, "ok": 60422, "ko": 60696 }, "meanResponseTime": { "total": 4991, "ok": 4667, "ko": 8279 }, "standardDeviation": { "total": 7304, "ok": 5773, "ko": 15636 }, "percentiles1": { "total": 3973, "ok": 4002, "ko": 540 }, "percentiles2": { "total": 5620, "ok": 5571, "ko": 8455 }, "percentiles3": { "total": 13725, "ok": 11409, "ko": 60003 }, "percentiles4": { "total": 54764, "ok": 32143, "ko": 60178 }, "group1": { "name": "t < 800 ms", "count": 809498, "percentage": 15 }, "group2": { "name": "800 ms < t < 1200 ms", "count": 202371, "percentage": 4 }, "group3": { "name": "t > 1200 ms", "count": 3845791, "percentage": 72 }, "group4": { "name": "failed", "count": 478942, "percentage": 9 }, "meanNumberOfRequestsPerSecond": { "total": 1491.5041922861933, "ok": 1357.6467300167692, "ko": 133.85746226942425 }, "spikes": [ { "datetime": "2022-09-27T23:46:48", "maxResponseTime": 2110 }, { "datetime": "2022-09-27T23:47:31", "maxResponseTime": 36594 }, { "datetime": "2022-09-27T23:47:56", "maxResponseTime": 31448 }, { "datetime": "2022-09-27T23:48:35", "maxResponseTime": 7668 }, { "datetime": "2022-09-27T23:56:03", "maxResponseTime": 34157 }, { "datetime": "2022-09-27T23:59:30", "maxResponseTime": 59249 }, { "datetime": "2022-09-28T00:01:18", "maxResponseTime": 36341 }, { "datetime": "2022-09-28T00:01:43", "maxResponseTime": 29824 }, { "datetime": "2022-09-28T00:05:28", "maxResponseTime": 57884 }, { "datetime": "2022-09-28T00:08:13", "maxResponseTime": 30770 }, { "datetime": "2022-09-28T00:09:21", "maxResponseTime": 30730 }, { "datetime": "2022-09-28T00:10:25", "maxResponseTime": 34768 }, { "datetime": "2022-09-28T00:10:47", "maxResponseTime": 60255 }, { "datetime": "2022-09-28T00:14:39", "maxResponseTime": 33792 }, { "datetime": "2022-09-28T00:17:49", "maxResponseTime": 29870 }, { "datetime": "2022-09-28T00:21:45", "maxResponseTime": 58191 }, { "datetime": "2022-09-28T00:25:31", "maxResponseTime": 57555 }, { "datetime": "2022-09-28T00:31:29", "maxResponseTime": 29853 }, { "datetime": "2022-09-28T00:39:07", "maxResponseTime": 32266 } ] }, { "name": "restLoginUsernamePasswordCallback", "numberOfRequests": { "total": 4852988, "ok": 4466592, "ko": 386396 }, "minResponseTime": { "total": 13, "ok": 29, "ko": 13 }, "maxResponseTime": { "total": 61437, "ok": 61437, "ko": 60463 }, "meanResponseTime": { "total": 5130, "ok": 5251, "ko": 3730 }, "standardDeviation": { "total": 3249, "ok": 2966, "ko": 5362 }, "percentiles1": { "total": 5013, "ok": 5152, "ko": 1048 }, "percentiles2": { "total": 6741, "ok": 6773, "ko": 4353 }, "percentiles3": { "total": 10568, "ok": 10299, "ko": 16020 }, "percentiles4": { "total": 16019, "ok": 14120, "ko": 16308 }, "group1": { "name": "t < 800 ms", "count": 260625, "percentage": 5 }, "group2": { "name": "800 ms < t < 1200 ms", "count": 73136, "percentage": 2 }, "group3": { "name": "t > 1200 ms", "count": 4132831, "percentage": 85 }, "group4": { "name": "failed", "count": 386396, "percentage": 8 }, "meanNumberOfRequestsPerSecond": { "total": 1356.3409726103969, "ok": 1248.3487982112913, "ko": 107.99217439910565 }, "spikes": [ { "datetime": "2022-09-27T23:46:41", "maxResponseTime": 3429 }, { "datetime": "2022-09-27T23:48:43", "maxResponseTime": 35795 }, { "datetime": "2022-09-28T00:13:56", "maxResponseTime": 55966 }, { "datetime": "2022-09-28T00:14:14", "maxResponseTime": 35053 }, { "datetime": "2022-09-28T00:15:30", "maxResponseTime": 31882 }, { "datetime": "2022-09-28T00:16:05", "maxResponseTime": 35122 }, { "datetime": "2022-09-28T00:17:28", "maxResponseTime": 29276 } ] }, { "name": "restloginProgressiveProfileCallback", "numberOfRequests": { "total": 386374, "ok": 0, "ko": 386374 }, "minResponseTime": { "total": 13, "ok": 0, "ko": 13 }, "maxResponseTime": { "total": 60174, "ok": 0, "ko": 60174 }, "meanResponseTime": { "total": 2284, "ok": 0, "ko": 2284 }, "standardDeviation": { "total": 3466, "ok": 0, "ko": 3466 }, "percentiles1": { "total": 186, "ok": 0, "ko": 186 }, "percentiles2": { "total": 4120, "ok": 0, "ko": 4120 }, "percentiles3": { "total": 8470, "ok": 0, "ko": 8470 }, "percentiles4": { "total": 16015, "ok": 0, "ko": 16015 }, "group1": { "name": "t < 800 ms", "count": 0, "percentage": 0 }, "group2": { "name": "800 ms < t < 1200 ms", "count": 0, "percentage": 0 }, "group3": { "name": "t > 1200 ms", "count": 0, "percentage": 0 }, "group4": { "name": "failed", "count": 386374, "percentage": 100 }, "meanNumberOfRequestsPerSecond": { "total": 107.98602571268866, "ok": 0, "ko": 107.98602571268866 }, "spikes": [] } ] } { "concurrency": null, "generic_stats": { "avg_num_of_requests_per_second": 2956, "avg_response_time": 4956, "max_response_time": 61437, "min_response_time": 19, "num_requests": 10575964, "num_requests_pass": 9324252, "num_requests_percent_pass": 88.165 }, "options": "; simulation:com.forgerock.gatling.Loadtest; testCase:idc.login; testMode:open; throughput:1500; rampup-duration:30", "stats": { "details": [ { "group1": { "count": 809498, "name": "t < 800 ms", "percentage": 15 }, "group2": { "count": 202371, "name": "800 ms < t < 1200 ms", "percentage": 4 }, "group3": { "count": 3845791, "name": "t > 1200 ms", "percentage": 72 }, "group4": { "count": 478942, "name": "failed", "percentage": 9 }, "maxResponseTime": { "ko": 60696, "ok": 60422, "total": 60696 }, "meanNumberOfRequestsPerSecond": { "ko": 133.85746226942425, "ok": 1357.6467300167692, "total": 1491.5041922861933 }, "meanResponseTime": { "ko": 8279, "ok": 4667, "total": 4991 }, "minResponseTime": { "ko": 13, "ok": 19, "total": 13 }, "name": "restLoginInitiate", "numberOfRequests": { "ko": 478942, "ok": 4857660, "total": 5336602 }, "percentiles1": { "ko": 540, "ok": 4002, "total": 3973 }, "percentiles2": { "ko": 8455, "ok": 5571, "total": 5620 }, "percentiles3": { "ko": 60003, "ok": 11409, "total": 13725 }, "percentiles4": { "ko": 60178, "ok": 32143, "total": 54764 }, "spikes": [ { "datetime": "2022-09-27T23:46:48", "maxResponseTime": 2110 }, { "datetime": "2022-09-27T23:47:31", "maxResponseTime": 36594 }, { "datetime": "2022-09-27T23:47:56", "maxResponseTime": 31448 }, { "datetime": "2022-09-27T23:48:35", "maxResponseTime": 7668 }, { "datetime": "2022-09-27T23:56:03", "maxResponseTime": 34157 }, { "datetime": "2022-09-27T23:59:30", "maxResponseTime": 59249 }, { "datetime": "2022-09-28T00:01:18", "maxResponseTime": 36341 }, { "datetime": "2022-09-28T00:01:43", "maxResponseTime": 29824 }, { "datetime": "2022-09-28T00:05:28", "maxResponseTime": 57884 }, { "datetime": "2022-09-28T00:08:13", "maxResponseTime": 30770 }, { "datetime": "2022-09-28T00:09:21", "maxResponseTime": 30730 }, { "datetime": "2022-09-28T00:10:25", "maxResponseTime": 34768 }, { "datetime": "2022-09-28T00:10:47", "maxResponseTime": 60255 }, { "datetime": "2022-09-28T00:14:39", "maxResponseTime": 33792 }, { "datetime": "2022-09-28T00:17:49", "maxResponseTime": 29870 }, { "datetime": "2022-09-28T00:21:45", "maxResponseTime": 58191 }, { "datetime": "2022-09-28T00:25:31", "maxResponseTime": 57555 }, { "datetime": "2022-09-28T00:31:29", "maxResponseTime": 29853 }, { "datetime": "2022-09-28T00:39:07", "maxResponseTime": 32266 } ], "standardDeviation": { "ko": 15636, "ok": 5773, "total": 7304 } }, { "group1": { "count": 260625, "name": "t < 800 ms", "percentage": 5 }, "group2": { "count": 73136, "name": "800 ms < t < 1200 ms", "percentage": 2 }, "group3": { "count": 4132831, "name": "t > 1200 ms", "percentage": 85 }, "group4": { "count": 386396, "name": "failed", "percentage": 8 }, "maxResponseTime": { "ko": 60463, "ok": 61437, "total": 61437 }, "meanNumberOfRequestsPerSecond": { "ko": 107.99217439910565, "ok": 1248.3487982112913, "total": 1356.3409726103969 }, "meanResponseTime": { "ko": 3730, "ok": 5251, "total": 5130 }, "minResponseTime": { "ko": 13, "ok": 29, "total": 13 }, "name": "restLoginUsernamePasswordCallback", "numberOfRequests": { "ko": 386396, "ok": 4466592, "total": 4852988 }, "percentiles1": { "ko": 1048, "ok": 5152, "total": 5013 }, "percentiles2": { "ko": 4353, "ok": 6773, "total": 6741 }, "percentiles3": { "ko": 16020, "ok": 10299, "total": 10568 }, "percentiles4": { "ko": 16308, "ok": 14120, "total": 16019 }, "spikes": [ { "datetime": "2022-09-27T23:46:41", "maxResponseTime": 3429 }, { "datetime": "2022-09-27T23:48:43", "maxResponseTime": 35795 }, { "datetime": "2022-09-28T00:13:56", "maxResponseTime": 55966 }, { "datetime": "2022-09-28T00:14:14", "maxResponseTime": 35053 }, { "datetime": "2022-09-28T00:15:30", "maxResponseTime": 31882 }, { "datetime": "2022-09-28T00:16:05", "maxResponseTime": 35122 }, { "datetime": "2022-09-28T00:17:28", "maxResponseTime": 29276 } ], "standardDeviation": { "ko": 5362, "ok": 2966, "total": 3249 } }, { "group1": { "count": 0, "name": "t < 800 ms", "percentage": 0 }, "group2": { "count": 0, "name": "800 ms < t < 1200 ms", "percentage": 0 }, "group3": { "count": 0, "name": "t > 1200 ms", "percentage": 0 }, "group4": { "count": 386374, "name": "failed", "percentage": 100 }, "maxResponseTime": { "ko": 60174, "ok": 0, "total": 60174 }, "meanNumberOfRequestsPerSecond": { "ko": 107.98602571268866, "ok": 0, "total": 107.98602571268866 }, "meanResponseTime": { "ko": 2284, "ok": 0, "total": 2284 }, "minResponseTime": { "ko": 13, "ok": 0, "total": 13 }, "name": "restloginProgressiveProfileCallback", "numberOfRequests": { "ko": 386374, "ok": 0, "total": 386374 }, "percentiles1": { "ko": 186, "ok": 0, "total": 186 }, "percentiles2": { "ko": 4120, "ok": 0, "total": 4120 }, "percentiles3": { "ko": 8470, "ok": 0, "total": 8470 }, "percentiles4": { "ko": 16015, "ok": 0, "total": 16015 }, "spikes": [], "standardDeviation": { "ko": 3466, "ok": 0, "total": 3466 } } ], "global": { "group1": { "count": 1070123, "name": "t < 800 ms", "percentage": 10 }, "group2": { "count": 275507, "name": "800 ms < t < 1200 ms", "percentage": 3 }, "group3": { "count": 7978622, "name": "t > 1200 ms", "percentage": 75 }, "group4": { "count": 1251712, "name": "failed", "percentage": 12 }, "maxResponseTime": { "ko": 60696, "ok": 61437, "total": 61437 }, "meanNumberOfRequestsPerSecond": { "ko": 349.8356623812186, "ok": 2605.9955282280603, "total": 2955.831190609279 }, "meanResponseTime": { "ko": 5024, "ok": 4947, "total": 4956 }, "minResponseTime": { "ko": 13, "ok": 19, "total": 13 }, "name": "Global Information", "numberOfRequests": { "ko": 1251712, "ok": 9324252, "total": 10575964 }, "percentiles1": { "ko": 594, "ok": 4505, "total": 4308 }, "percentiles2": { "ko": 4774, "ok": 6263, "total": 6213 }, "percentiles3": { "ko": 16275, "ok": 10626, "total": 11573 }, "percentiles4": { "ko": 60052, "ok": 27449, "total": 29840 }, "standardDeviation": { "ko": 10631, "ok": 4655, "total": 5699 } } }, "target_hostname": "openam-perf-100m-testing.forgeblocks.com", "tool_name": "gatling" } ________________________________________________________________________________ [28/Sep/2022 00:58:55] Reporting_authn-users-1500 step15 : Remove gatling task's stdout file ________________________________________________________________________________ Deleting gatling stdout file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/idc_am_authn/05_scenario/05_authn-users-1500/stdout.txt Gatling stdout.txt has been deleted ________________________________________________________________________________ [28/Sep/2022 00:58:55] Reporting_authn-users-1500 post : Check output ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped