--Task-- name: Reporting-mixedquery-4000 enabled: True class_name: GatlingResultTask source_name: overseer-0 source_namespace: >default< target_name: overseer-0 target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates below loop: False interval: None dependencies: [] wait_for: ['Logs-parse-mixedquery-1000', 'Logs-parse-mixedquery-2000', 'Logs-parse-mixedquery-4000', 'Logs-parse-mixedquery-6000', 'Logs-parse-mixedquery-8000', 'Logs-parse-mixedquery-10000', 'Reporting-mixedquery-1000', 'Reporting-mixedquery-2000'] preceding_task: None options: {'task_name': 'mixedquery-4000'} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock source (overseer-0) is a component 2025-03-28 01:29:28 - INFO: Timeout for this Task has changed to 3h 30m (12600 seconds) 2025-03-28 01:29:28 - INFO: timeout was set to GatlingResultTask default (half of global_duration or 3600 seconds (whatever is higher)), because it was unset Pod stdout file : /results/orders/Reporting-mixedquery-4000/stdout.txt Pod stderr file : /results/orders/Reporting-mixedquery-4000/stderr.txt Pod log : /results/orders/Reporting-mixedquery-4000 ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-4000 step1 : Write order for overseer to generate the report ________________________________________________________________________________ Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/order.json { "name": "Reporting-mixedquery-4000", "command": " /lodestar/lodestar.py perf run-gatling --reports-only=\"/results/gatling/mixedquery-4000\" --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx8G\" --archive-name=\"mixedquery-4000.tar.gz\"", "out-dir": "/results/orders/Reporting-mixedquery-4000" } ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-4000 step2 : Make sure overseer is ready to accept order (not already busy) ________________________________________________________________________________ 2025-03-28 01:29:28,256 INFO 2025-03-28 01:29:28,256 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 01:29:28,256 INFO [loop_until]: (max_time=120, interval=5, expected_rc=[0] 2025-03-28 01:29:28,568 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:29:28,568 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:28,568 DEBUG --- stdout --- 2025-03-28 01:29:28,568 DEBUG WAITING 2025-03-28 01:29:28,568 DEBUG --- stderr --- 2025-03-28 01:29:28,568 DEBUG % 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 --:--:-- --:--:-- --:--:-- 23 ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-4000 step3 : Send order to overseer ________________________________________________________________________________ 2025-03-28 01:29:28,569 INFO 2025-03-28 01:29:28,569 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2025-03-28 01:29:28,569 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:29:28,848 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:29:28,848 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:28,848 DEBUG --- stdout --- 2025-03-28 01:29:28,848 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:29:28,848 DEBUG --- stderr --- 2025-03-28 01:29:28,848 DEBUG 2025-03-28 01:29:28,849 INFO 2025-03-28 01:29:28,849 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/order.json overseer-0-59c948f569-rgrkv:/results/orders/order.json 2025-03-28 01:29:28,849 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:29:30,232 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:30,232 DEBUG --- stdout --- 2025-03-28 01:29:30,232 DEBUG 2025-03-28 01:29:30,232 DEBUG --- stderr --- 2025-03-28 01:29:30,232 DEBUG Order has been successfully forwarded to overseer ________________________________________________________________________________ [2025-03-28 01:29:30] Reporting-mixedquery-4000 step4 : Wait order is done ________________________________________________________________________________ Workaround for PERF-1966. Sleeping for 5 seconds. 2025-03-28 01:29:35,232 INFO 2025-03-28 01:29:35,233 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 01:29:35,233 INFO [loop_until]: (max_time=12600, interval=5, expected_rc=[0] 2025-03-28 01:29:35,448 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:40,667 INFO [loop_until]: Function succeeded after 5s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:45,882 INFO [loop_until]: Function succeeded after 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:51,097 INFO [loop_until]: Function succeeded after 15s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:56,311 INFO [loop_until]: Function succeeded after 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:01,625 INFO [loop_until]: Function succeeded after 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:06,840 INFO [loop_until]: Function succeeded after 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:12,055 INFO [loop_until]: Function succeeded after 36s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:17,269 INFO [loop_until]: Function succeeded after 42s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:22,485 INFO [loop_until]: Function succeeded after 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:27,699 INFO [loop_until]: Function succeeded after 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:32,958 INFO [loop_until]: Function succeeded after 57s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:38,173 INFO [loop_until]: Function succeeded after 1m 02s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:43,393 INFO [loop_until]: Function succeeded after 1m 08s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:48,678 INFO [loop_until]: Function succeeded after 1m 13s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:53,893 INFO [loop_until]: Function succeeded after 1m 18s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:30:59,110 INFO [loop_until]: Function succeeded after 1m 23s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:04,326 INFO [loop_until]: Function succeeded after 1m 29s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:09,543 INFO [loop_until]: Function succeeded after 1m 34s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:14,812 INFO [loop_until]: Function succeeded after 1m 39s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:20,028 INFO [loop_until]: Function succeeded after 1m 44s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:25,242 INFO [loop_until]: Function succeeded after 1m 50s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:30,457 INFO [loop_until]: Function succeeded after 1m 55s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:35,672 INFO [loop_until]: Function succeeded after 2m (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:40,887 INFO [loop_until]: Function succeeded after 2m 05s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:46,170 INFO [loop_until]: Function succeeded after 2m 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:51,385 INFO [loop_until]: Function succeeded after 2m 16s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:31:56,601 INFO [loop_until]: Function succeeded after 2m 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:01,815 INFO [loop_until]: Function succeeded after 2m 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:07,030 INFO [loop_until]: Function succeeded after 2m 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:12,245 INFO [loop_until]: Function succeeded after 2m 37s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:17,504 INFO [loop_until]: Function succeeded after 2m 42s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:22,719 INFO [loop_until]: Function succeeded after 2m 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:27,934 INFO [loop_until]: Function succeeded after 2m 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:33,149 INFO [loop_until]: Function succeeded after 2m 57s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:38,366 INFO [loop_until]: Function succeeded after 3m 03s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:43,581 INFO [loop_until]: Function succeeded after 3m 08s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:48,801 INFO [loop_until]: Function succeeded after 3m 13s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:54,016 INFO [loop_until]: Function succeeded after 3m 18s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:32:59,230 INFO [loop_until]: Function succeeded after 3m 23s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:04,446 INFO [loop_until]: Function succeeded after 3m 29s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:09,662 INFO [loop_until]: Function succeeded after 3m 34s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:14,876 INFO [loop_until]: Function succeeded after 3m 39s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:20,095 INFO [loop_until]: Function succeeded after 3m 44s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:25,315 INFO [loop_until]: Function succeeded after 3m 50s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:30,628 INFO [loop_until]: Function succeeded after 3m 55s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:35,843 INFO [loop_until]: Function succeeded after 4m (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:41,057 INFO [loop_until]: Function succeeded after 4m 05s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:46,271 INFO [loop_until]: Function succeeded after 4m 11s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:51,486 INFO [loop_until]: Function succeeded after 4m 16s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:33:56,701 INFO [loop_until]: Function succeeded after 4m 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:02,012 INFO [loop_until]: Function succeeded after 4m 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:07,227 INFO [loop_until]: Function succeeded after 4m 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:12,442 INFO [loop_until]: Function succeeded after 4m 37s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:17,656 INFO [loop_until]: Function succeeded after 4m 42s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:22,871 INFO [loop_until]: Function succeeded after 4m 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:28,086 INFO [loop_until]: Function succeeded after 4m 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:33,346 INFO [loop_until]: Function succeeded after 4m 58s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:38,560 INFO [loop_until]: Function succeeded after 5m 03s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:43,776 INFO [loop_until]: Function succeeded after 5m 08s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:48,990 INFO [loop_until]: Function succeeded after 5m 13s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:54,205 INFO [loop_until]: Function succeeded after 5m 18s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:34:59,420 INFO [loop_until]: Function succeeded after 5m 24s (rc=0) - expected pattern found 2025-03-28 01:34:59,420 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:34:59,420 DEBUG --- stdout --- 2025-03-28 01:34:59,420 DEBUG WAITING 2025-03-28 01:34:59,420 DEBUG --- stderr --- 2025-03-28 01:34:59,420 DEBUG % 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 33 0 --:--:-- --:--:-- --:--:-- 33 ________________________________________________________________________________ [2025-03-28 01:34:59] Reporting-mixedquery-4000 step5 : Wait until gatling report is generated on overseer ________________________________________________________________________________ 2025-03-28 01:34:59,421 INFO 2025-03-28 01:34:59,421 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2025-03-28 01:34:59,421 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:34:59,739 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:34:59,739 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:34:59,739 DEBUG --- stdout --- 2025-03-28 01:34:59,739 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:34:59,739 DEBUG --- stderr --- 2025-03-28 01:34:59,739 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:34:59,740 INFO 2025-03-28 01:34:59,740 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- bash -c 'if [ -f "/results/gatling/mixedquery-4000/mixedquery-4000.tar.gz" ]; then echo "/results/gatling/mixedquery-4000/mixedquery-4000.tar.gz file found"; exit 0; else echo "/results/gatling/mixedquery-4000/mixedquery-4000.tar.gz file not found"; exit 1; fi' | grep "/results/gatling/mixedquery-4000/mixedquery-4000.tar.gz file found" 2025-03-28 01:34:59,740 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:35:00,575 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:35:00,575 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:00,575 DEBUG --- stdout --- 2025-03-28 01:35:00,575 DEBUG /results/gatling/mixedquery-4000/mixedquery-4000.tar.gz file found 2025-03-28 01:35:00,575 DEBUG --- stderr --- 2025-03-28 01:35:00,575 DEBUG 2025-03-28 01:35:00,575 INFO 2025-03-28 01:35:00,576 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/gatling/mixedquery-4000/mixedquery-4000.tar.gz 2025-03-28 01:35:01,378 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:35:01,378 DEBUG --- stdout --- 2025-03-28 01:35:01,378 DEBUG 316 /results/gatling/mixedquery-4000/mixedquery-4000.tar.gz 2025-03-28 01:35:01,378 DEBUG --- stderr --- 2025-03-28 01:35:01,378 DEBUG 2025-03-28 01:35:01,378 INFO - Download file (size 316k) source : /results/gatling/mixedquery-4000/mixedquery-4000.tar.gz @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-4000.tar.gz 2025-03-28 01:35:01,379 INFO 2025-03-28 01:35:01,379 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/gatling/mixedquery-4000/mixedquery-4000.tar.gz /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-4000.tar.gz 2025-03-28 01:35:01,379 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:35:02,384 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:02,384 DEBUG --- stdout --- 2025-03-28 01:35:02,384 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:35:02,384 DEBUG --- stderr --- 2025-03-28 01:35:02,384 DEBUG ________________________________________________________________________________ [2025-03-28 01:35:02] Reporting-mixedquery-4000 step6 : Unzip the result ________________________________________________________________________________ 2025-03-28 01:35:02,385 INFO 2025-03-28 01:35:02,385 INFO [run_command]: tar zxf /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-4000.tar.gz -C /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/03_mixedquery-4000/gatling 2025-03-28 01:35:02,400 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:35:02,400 DEBUG --- stdout --- 2025-03-28 01:35:02,400 DEBUG 2025-03-28 01:35:02,400 DEBUG --- stderr --- 2025-03-28 01:35:02,400 DEBUG 2025-03-28 01:35:02,400 INFO ________________________________________________________________________________ [2025-03-28 01:35:02] Reporting-mixedquery-4000 step7 : Print rc order ________________________________________________________________________________ 2025-03-28 01:35:02,401 INFO 2025-03-28 01:35:02,401 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2025-03-28 01:35:02,401 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:35:02,680 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:35:02,681 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:02,681 DEBUG --- stdout --- 2025-03-28 01:35:02,681 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:35:02,681 DEBUG --- stderr --- 2025-03-28 01:35:02,681 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:35:02,682 INFO 2025-03-28 01:35:02,682 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- bash -c 'if [ -f "/results/orders/Reporting-mixedquery-4000/rc.txt" ]; then echo "/results/orders/Reporting-mixedquery-4000/rc.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-4000/rc.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-4000/rc.txt file found" 2025-03-28 01:35:02,682 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:35:03,489 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:35:03,489 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:03,489 DEBUG --- stdout --- 2025-03-28 01:35:03,489 DEBUG /results/orders/Reporting-mixedquery-4000/rc.txt file found 2025-03-28 01:35:03,489 DEBUG --- stderr --- 2025-03-28 01:35:03,489 DEBUG 2025-03-28 01:35:03,489 INFO 2025-03-28 01:35:03,490 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/Reporting-mixedquery-4000/rc.txt 2025-03-28 01:35:04,291 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:35:04,291 DEBUG --- stdout --- 2025-03-28 01:35:04,291 DEBUG 4 /results/orders/Reporting-mixedquery-4000/rc.txt 2025-03-28 01:35:04,291 DEBUG --- stderr --- 2025-03-28 01:35:04,291 DEBUG 2025-03-28 01:35:04,291 INFO - Download file (size 4k) source : /results/orders/Reporting-mixedquery-4000/rc.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/rc.txt 2025-03-28 01:35:04,292 INFO 2025-03-28 01:35:04,292 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/Reporting-mixedquery-4000/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/rc.txt 2025-03-28 01:35:04,292 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:35:05,028 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:05,029 DEBUG --- stdout --- 2025-03-28 01:35:05,029 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:35:05,029 DEBUG --- stderr --- 2025-03-28 01:35:05,029 DEBUG 2025-03-28 01:35:05,029 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/rc.txt is small (1 lines), printing all lines: 2025-03-28 01:35:05,029 INFO ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [2025-03-28 01:35:05] Reporting-mixedquery-4000 step8 : Check rc log ________________________________________________________________________________ CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) PASS: no error found in rc log ________________________________________________________________________________ [2025-03-28 01:35:05] Reporting-mixedquery-4000 step9 : Print stdout order ________________________________________________________________________________ 2025-03-28 01:35:05,320 INFO 2025-03-28 01:35:05,320 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2025-03-28 01:35:05,320 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:35:05,598 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:35:05,598 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:05,598 DEBUG --- stdout --- 2025-03-28 01:35:05,598 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:35:05,598 DEBUG --- stderr --- 2025-03-28 01:35:05,598 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:35:05,599 INFO 2025-03-28 01:35:05,599 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- bash -c 'if [ -f "/results/orders/Reporting-mixedquery-4000/stdout.txt" ]; then echo "/results/orders/Reporting-mixedquery-4000/stdout.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-4000/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-4000/stdout.txt file found" 2025-03-28 01:35:05,599 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:35:06,411 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:35:06,411 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:06,411 DEBUG --- stdout --- 2025-03-28 01:35:06,411 DEBUG /results/orders/Reporting-mixedquery-4000/stdout.txt file found 2025-03-28 01:35:06,411 DEBUG --- stderr --- 2025-03-28 01:35:06,411 DEBUG 2025-03-28 01:35:06,411 INFO 2025-03-28 01:35:06,411 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/Reporting-mixedquery-4000/stdout.txt 2025-03-28 01:35:07,214 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:35:07,214 DEBUG --- stdout --- 2025-03-28 01:35:07,214 DEBUG 8 /results/orders/Reporting-mixedquery-4000/stdout.txt 2025-03-28 01:35:07,214 DEBUG --- stderr --- 2025-03-28 01:35:07,214 DEBUG 2025-03-28 01:35:07,214 INFO - Download file (size 8k) source : /results/orders/Reporting-mixedquery-4000/stdout.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stdout.txt 2025-03-28 01:35:07,215 INFO 2025-03-28 01:35:07,215 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/Reporting-mixedquery-4000/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stdout.txt 2025-03-28 01:35:07,215 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:35:07,936 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:07,936 DEBUG --- stdout --- 2025-03-28 01:35:07,936 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:35:07,936 DEBUG --- stderr --- 2025-03-28 01:35:07,936 DEBUG 2025-03-28 01:35:07,936 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stdout.txt is small (94 lines), printing all lines: 2025-03-28 01:35:07,936 INFO ----- output ----- 2025-03-28 01:29:30,970 INFO pom.xml copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpbw7nudny 2025-03-28 01:29:30,972 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.reportsOnly="/results/gatling/mixedquery-4000/loadtest-20250327232206342" -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx8G" [INFO] Scanning for projects... [INFO] [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- [INFO] Building pyrock-gatling-simulation 3.12.0 [INFO] from pom.xml [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> [INFO] [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- [INFO] skip non existing resourceDirectory /tmp/tmpbw7nudny/src/main/resources [INFO] [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- [INFO] No sources to compile [INFO] [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- [INFO] skip non existing resourceDirectory /tmp/tmpbw7nudny/src/test/resources [INFO] [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- [INFO] No sources to compile [INFO] [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- [INFO] compile in 0.0 s [INFO] No sources to compile [INFO] [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< [INFO] [INFO] [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 01:29:32,822 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.5.8 01:29:32,824 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - No custom configurators were discovered as a service. 01:29:32,824 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator 01:29:32,825 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator 01:29:32,830 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo] 01:29:32,831 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo] 01:29:32,838 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - ch.qos.logback.classic.joran.SerializedModelConfigurator.configure() call lasted 6 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY 01:29:32,838 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator 01:29:32,839 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator 01:29:32,839 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 01:29:32,842 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/home/jenkins/.m2/repository/io/gatling/gatling-maven-plugin/4.9.6/gatling-maven-plugin-4.9.6.jar!/logback.xml] 01:29:32,847 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@240237d2 - URL [jar:file:/home/jenkins/.m2/repository/io/gatling/gatling-maven-plugin/4.9.6/gatling-maven-plugin-4.9.6.jar!/logback.xml] is not of type file 01:29:32,892 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - element is deprecated. Near [level] on line 12 01:29:32,892 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within or elements instead. 01:29:32,933 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE] 01:29:32,933 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 01:29:32,939 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 01:29:32,960 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - ROOT level set to WARN 01:29:32,960 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT] 01:29:32,961 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@25a65b77 - End of configuration. 01:29:32,961 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2ed0fbae - Registering current configuration as safe fallback point 01:29:32,961 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 122 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY Parsing log file(s)... Parsing log file(s) done in 323s. Generating reports... ================================================================================ ---- Global Information -------------------------------------------------------- > request count 7136197 (OK=7136184 KO=13 ) > min response time 39 (OK=39 KO=10000 ) > max response time 60000 (OK=13372 KO=60000 ) > mean response time 46 (OK=46 KO=13847 ) > std deviation 28 (OK=11 KO=13323 ) > response time 50th percentile 46 (OK=46 KO=10001 ) > response time 75th percentile 47 (OK=47 KO=10001 ) > response time 95th percentile 50 (OK=50 KO=30001 ) > response time 99th percentile 54 (OK=54 KO=54000 ) > mean requests/sec 3964.55 (OK=3964.55 KO=0.01 ) ---- Response Time Distribution ------------------------------------------------ > t < 800 ms 7135909 ( 100%) > 800 ms <= t < 1200 ms 257 ( 0%) > t >= 1200 ms 18 ( 0%) > failed 13 ( 0%) ---- Errors -------------------------------------------------------------------- > i.n.h.s.SslHandshakeTimeoutException: handshake timed out afte 9 (69.23%) r 10000ms > i.n.c.ConnectTimeoutException: connection timed out after 1000 3 (23.08%) 0 ms: openam-perf-200m.forgeblocks.com/34.107.203.37:443 > Request timeout to openam-perf-200m.forgeblocks.com/34.107.203 1 ( 7.69%) .37:443 after 60000 ms ================================================================================ Reports generated, please open the following file: file:///results/gatling/mixedquery-4000/loadtest-20250327232206342/index.html [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 05:25 min [INFO] Finished at: 2025-03-28T01:34:57Z [INFO] ------------------------------------------------------------------------ 2025-03-28 01:34:57,737 INFO Gatling simulation run ended successfully 2025-03-28 01:34:57,737 INFO Creating archive mixedquery-4000.tar.gz with report files 2025-03-28 01:34:57,834 INFO Archive /results/gatling/mixedquery-4000/mixedquery-4000.tar.gz successfully created ________________________________________________________________________________ [2025-03-28 01:35:07] Reporting-mixedquery-4000 step10 : Check stdout log and parse its content ________________________________________________________________________________ PASS: no error found in stdout log ________________________________________________________________________________ [2025-03-28 01:35:07] Reporting-mixedquery-4000 step11 : Print stderr order ________________________________________________________________________________ 2025-03-28 01:35:07,937 INFO 2025-03-28 01:35:07,937 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2025-03-28 01:35:07,937 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:35:08,218 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:35:08,218 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:08,218 DEBUG --- stdout --- 2025-03-28 01:35:08,218 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:35:08,218 DEBUG --- stderr --- 2025-03-28 01:35:08,218 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:35:08,219 INFO 2025-03-28 01:35:08,219 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- bash -c 'if [ -f "/results/orders/Reporting-mixedquery-4000/stderr.txt" ]; then echo "/results/orders/Reporting-mixedquery-4000/stderr.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-4000/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-4000/stderr.txt file found" 2025-03-28 01:35:08,219 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:35:09,025 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:35:09,025 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:09,025 DEBUG --- stdout --- 2025-03-28 01:35:09,025 DEBUG /results/orders/Reporting-mixedquery-4000/stderr.txt file found 2025-03-28 01:35:09,025 DEBUG --- stderr --- 2025-03-28 01:35:09,025 DEBUG 2025-03-28 01:35:09,025 INFO 2025-03-28 01:35:09,026 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/Reporting-mixedquery-4000/stderr.txt 2025-03-28 01:35:09,834 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:35:09,834 DEBUG --- stdout --- 2025-03-28 01:35:09,834 DEBUG 0 /results/orders/Reporting-mixedquery-4000/stderr.txt 2025-03-28 01:35:09,834 DEBUG --- stderr --- 2025-03-28 01:35:09,834 DEBUG 2025-03-28 01:35:09,834 INFO - Download file (size 0k) source : /results/orders/Reporting-mixedquery-4000/stderr.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stderr.txt 2025-03-28 01:35:09,835 INFO 2025-03-28 01:35:09,835 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/Reporting-mixedquery-4000/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stderr.txt 2025-03-28 01:35:09,835 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:35:10,579 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:35:10,579 DEBUG --- stdout --- 2025-03-28 01:35:10,579 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:35:10,579 DEBUG --- stderr --- 2025-03-28 01:35:10,579 DEBUG 2025-03-28 01:35:10,579 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stderr.txt is small (0 lines), printing all lines: 2025-03-28 01:35:10,579 INFO ----- output ----- ________________________________________________________________________________ [2025-03-28 01:35:10] Reporting-mixedquery-4000 step12 : Check stderr log ________________________________________________________________________________ PASS: no error found in stderr log ________________________________________________________________________________ [2025-03-28 01:35:10] Reporting-mixedquery-4000 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 Skip 2FA checking simulation request User Authorize PKCE stage checking simulation request User AccessToken PKCE stage checking simulation request ReadManagedUser [warn] responseTimePercentiles was not found in /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/03_mixedquery-4000/gatling/req_readmanageduser--1429285772.html - cannot check for spikes checking simulation request queryFull [warn] responseTimePercentiles was not found in /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/03_mixedquery-4000/gatling/req_queryfull--1807283337.html - cannot check for spikes no spikes found ________________________________________________________________________________ [2025-03-28 01:35:10] Reporting-mixedquery-4000 step14 : Collect Gatling simulation data ________________________________________________________________________________ collected stats : { "global": { "name": "All Requests", "numberOfRequests": { "total": 7136197, "ok": 7136184, "ko": 13 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 10000 }, "maxResponseTime": { "total": 60000, "ok": 13372, "ko": 60000 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 13847 }, "standardDeviation": { "total": 28, "ok": 11, "ko": 13323 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10001 }, "percentiles2": { "total": 47, "ok": 47, "ko": 10001 }, "percentiles3": { "total": 50, "ok": 50, "ko": 30001 }, "percentiles4": { "total": 54, "ok": 54, "ko": 54000 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 7135909, "percentage": 99.99596423697385 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 257, "percentage": 0.003601357978206039 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 18, "percentage": 0.0002522351891350533 }, "group4": { "name": "failed", "htmlName": "failed", "count": 13, "percentage": 0.00018216985881976073 }, "meanNumberOfRequestsPerSecond": { "total": 3964.553888888889, "ok": 3964.5466666666666, "ko": 0.007222222222222222 } }, "details": [ { "name": "restLoginInitiate", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 71, "ok": 71, "ko": 0 }, "maxResponseTime": { "total": 71, "ok": 71, "ko": 0 }, "meanResponseTime": { "total": 71, "ok": 71, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 71, "ok": 71, "ko": 0 }, "percentiles2": { "total": 71, "ok": 71, "ko": 0 }, "percentiles3": { "total": 71, "ok": 71, "ko": 0 }, "percentiles4": { "total": 71, "ok": 71, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1, "percentage": 100.0 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 0, "percentage": 0.0 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 0, "percentage": 0.0 }, "group4": { "name": "failed", "htmlName": "failed", "count": 0, "percentage": 0.0 }, "meanNumberOfRequestsPerSecond": { "total": 0.0005555555555555556, "ok": 0.0005555555555555556, "ko": 0 }, "spikes": [] }, { "name": "restLoginUsernamePasswordCallback", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 120, "ok": 120, "ko": 0 }, "maxResponseTime": { "total": 120, "ok": 120, "ko": 0 }, "meanResponseTime": { "total": 120, "ok": 120, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 120, "ok": 120, "ko": 0 }, "percentiles2": { "total": 120, "ok": 120, "ko": 0 }, "percentiles3": { "total": 120, "ok": 120, "ko": 0 }, "percentiles4": { "total": 120, "ok": 120, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1, "percentage": 100.0 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 0, "percentage": 0.0 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 0, "percentage": 0.0 }, "group4": { "name": "failed", "htmlName": "failed", "count": 0, "percentage": 0.0 }, "meanNumberOfRequestsPerSecond": { "total": 0.0005555555555555556, "ok": 0.0005555555555555556, "ko": 0 }, "spikes": [] }, { "name": "Skip 2FA", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 64, "ok": 64, "ko": 0 }, "maxResponseTime": { "total": 64, "ok": 64, "ko": 0 }, "meanResponseTime": { "total": 64, "ok": 64, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 64, "ok": 64, "ko": 0 }, "percentiles2": { "total": 64, "ok": 64, "ko": 0 }, "percentiles3": { "total": 64, "ok": 64, "ko": 0 }, "percentiles4": { "total": 64, "ok": 64, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1, "percentage": 100.0 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 0, "percentage": 0.0 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 0, "percentage": 0.0 }, "group4": { "name": "failed", "htmlName": "failed", "count": 0, "percentage": 0.0 }, "meanNumberOfRequestsPerSecond": { "total": 0.0005555555555555556, "ok": 0.0005555555555555556, "ko": 0 }, "spikes": [] }, { "name": "User Authorize PKCE stage", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 58, "ok": 58, "ko": 0 }, "maxResponseTime": { "total": 58, "ok": 58, "ko": 0 }, "meanResponseTime": { "total": 58, "ok": 58, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 58, "ok": 58, "ko": 0 }, "percentiles2": { "total": 58, "ok": 58, "ko": 0 }, "percentiles3": { "total": 58, "ok": 58, "ko": 0 }, "percentiles4": { "total": 58, "ok": 58, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1, "percentage": 100.0 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 0, "percentage": 0.0 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 0, "percentage": 0.0 }, "group4": { "name": "failed", "htmlName": "failed", "count": 0, "percentage": 0.0 }, "meanNumberOfRequestsPerSecond": { "total": 0.0005555555555555556, "ok": 0.0005555555555555556, "ko": 0 }, "spikes": [] }, { "name": "User AccessToken PKCE stage", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 64, "ok": 64, "ko": 0 }, "maxResponseTime": { "total": 64, "ok": 64, "ko": 0 }, "meanResponseTime": { "total": 64, "ok": 64, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 64, "ok": 64, "ko": 0 }, "percentiles2": { "total": 64, "ok": 64, "ko": 0 }, "percentiles3": { "total": 64, "ok": 64, "ko": 0 }, "percentiles4": { "total": 64, "ok": 64, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1, "percentage": 100.0 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 0, "percentage": 0.0 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 0, "percentage": 0.0 }, "group4": { "name": "failed", "htmlName": "failed", "count": 0, "percentage": 0.0 }, "meanNumberOfRequestsPerSecond": { "total": 0.0005555555555555556, "ok": 0.0005555555555555556, "ko": 0 }, "spikes": [] }, { "name": "ReadManagedUser", "numberOfRequests": { "total": 3570567, "ok": 3570558, "ko": 9 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 10000 }, "maxResponseTime": { "total": 60000, "ok": 13372, "ko": 60000 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 15556 }, "standardDeviation": { "total": 37, "ok": 13, "ko": 15713 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10001 }, "percentiles2": { "total": 48, "ok": 48, "ko": 10001 }, "percentiles3": { "total": 50, "ok": 50, "ko": 40000 }, "percentiles4": { "total": 54, "ok": 54, "ko": 56000 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 3570407, "percentage": 99.99551891898402 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 138, "percentage": 0.0038649323762864557 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 13, "percentage": 0.00036408783254872405 }, "group4": { "name": "failed", "htmlName": "failed", "count": 9, "percentage": 0.00025206080714911666 }, "meanNumberOfRequestsPerSecond": { "total": 1983.6483333333333, "ok": 1983.6433333333334, "ko": 0.005 }, "spikes": [] }, { "name": "queryFull", "numberOfRequests": { "total": 3565625, "ok": 3565621, "ko": 4 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 10000 }, "maxResponseTime": { "total": 10001, "ok": 7255, "ko": 10001 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 10000 }, "standardDeviation": { "total": 14, "ok": 9, "ko": 0 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10000 }, "percentiles2": { "total": 47, "ok": 47, "ko": 10000 }, "percentiles3": { "total": 49, "ok": 49, "ko": 10001 }, "percentiles4": { "total": 54, "ok": 54, "ko": 10001 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 3565497, "percentage": 99.9964101665206 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 119, "percentage": 0.0033374233128834357 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 5, "percentage": 0.00014022787028922 }, "group4": { "name": "failed", "htmlName": "failed", "count": 4, "percentage": 0.000112182296231376 }, "meanNumberOfRequestsPerSecond": { "total": 1980.9027777777778, "ok": 1980.9005555555555, "ko": 0.0022222222222222222 }, "spikes": [] } ] } { "concurrency": null, "generic_stats": { "avg_num_of_requests_per_second": 3965, "avg_response_time": 46, "max_response_time": 13372, "min_response_time": 39, "num_requests": 7136197, "num_requests_pass": 7136184, "num_requests_percent_pass": 100.0 }, "options": "; testMode:open; testCase:idm.MixedQuery; duration:1800; throughput:4000", "stats": { "details": [ { "group1": { "count": 1, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 100.0 }, "group2": { "count": 0, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0 }, "group3": { "count": 0, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0 }, "group4": { "count": 0, "htmlName": "failed", "name": "failed", "percentage": 0.0 }, "maxResponseTime": { "ko": 0, "ok": 71, "total": 71 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 71, "total": 71 }, "minResponseTime": { "ko": 0, "ok": 71, "total": 71 }, "name": "restLoginInitiate", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 71, "total": 71 }, "percentiles2": { "ko": 0, "ok": 71, "total": 71 }, "percentiles3": { "ko": 0, "ok": 71, "total": 71 }, "percentiles4": { "ko": 0, "ok": 71, "total": 71 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 1, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 100.0 }, "group2": { "count": 0, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0 }, "group3": { "count": 0, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0 }, "group4": { "count": 0, "htmlName": "failed", "name": "failed", "percentage": 0.0 }, "maxResponseTime": { "ko": 0, "ok": 120, "total": 120 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 120, "total": 120 }, "minResponseTime": { "ko": 0, "ok": 120, "total": 120 }, "name": "restLoginUsernamePasswordCallback", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 120, "total": 120 }, "percentiles2": { "ko": 0, "ok": 120, "total": 120 }, "percentiles3": { "ko": 0, "ok": 120, "total": 120 }, "percentiles4": { "ko": 0, "ok": 120, "total": 120 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 1, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 100.0 }, "group2": { "count": 0, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0 }, "group3": { "count": 0, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0 }, "group4": { "count": 0, "htmlName": "failed", "name": "failed", "percentage": 0.0 }, "maxResponseTime": { "ko": 0, "ok": 64, "total": 64 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 64, "total": 64 }, "minResponseTime": { "ko": 0, "ok": 64, "total": 64 }, "name": "Skip 2FA", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 64, "total": 64 }, "percentiles2": { "ko": 0, "ok": 64, "total": 64 }, "percentiles3": { "ko": 0, "ok": 64, "total": 64 }, "percentiles4": { "ko": 0, "ok": 64, "total": 64 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 1, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 100.0 }, "group2": { "count": 0, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0 }, "group3": { "count": 0, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0 }, "group4": { "count": 0, "htmlName": "failed", "name": "failed", "percentage": 0.0 }, "maxResponseTime": { "ko": 0, "ok": 58, "total": 58 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 58, "total": 58 }, "minResponseTime": { "ko": 0, "ok": 58, "total": 58 }, "name": "User Authorize PKCE stage", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 58, "total": 58 }, "percentiles2": { "ko": 0, "ok": 58, "total": 58 }, "percentiles3": { "ko": 0, "ok": 58, "total": 58 }, "percentiles4": { "ko": 0, "ok": 58, "total": 58 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 1, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 100.0 }, "group2": { "count": 0, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0 }, "group3": { "count": 0, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0 }, "group4": { "count": 0, "htmlName": "failed", "name": "failed", "percentage": 0.0 }, "maxResponseTime": { "ko": 0, "ok": 64, "total": 64 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 64, "total": 64 }, "minResponseTime": { "ko": 0, "ok": 64, "total": 64 }, "name": "User AccessToken PKCE stage", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 64, "total": 64 }, "percentiles2": { "ko": 0, "ok": 64, "total": 64 }, "percentiles3": { "ko": 0, "ok": 64, "total": 64 }, "percentiles4": { "ko": 0, "ok": 64, "total": 64 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 3570407, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.99551891898402 }, "group2": { "count": 138, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0038649323762864557 }, "group3": { "count": 13, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.00036408783254872405 }, "group4": { "count": 9, "htmlName": "failed", "name": "failed", "percentage": 0.00025206080714911666 }, "maxResponseTime": { "ko": 60000, "ok": 13372, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.005, "ok": 1983.6433333333334, "total": 1983.6483333333333 }, "meanResponseTime": { "ko": 15556, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 10000, "ok": 39, "total": 39 }, "name": "ReadManagedUser", "numberOfRequests": { "ko": 9, "ok": 3570558, "total": 3570567 }, "percentiles1": { "ko": 10001, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10001, "ok": 48, "total": 48 }, "percentiles3": { "ko": 40000, "ok": 50, "total": 50 }, "percentiles4": { "ko": 56000, "ok": 54, "total": 54 }, "spikes": [], "standardDeviation": { "ko": 15713, "ok": 13, "total": 37 } }, { "group1": { "count": 3565497, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.9964101665206 }, "group2": { "count": 119, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0033374233128834357 }, "group3": { "count": 5, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.00014022787028922 }, "group4": { "count": 4, "htmlName": "failed", "name": "failed", "percentage": 0.000112182296231376 }, "maxResponseTime": { "ko": 10001, "ok": 7255, "total": 10001 }, "meanNumberOfRequestsPerSecond": { "ko": 0.0022222222222222222, "ok": 1980.9005555555555, "total": 1980.9027777777778 }, "meanResponseTime": { "ko": 10000, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 10000, "ok": 39, "total": 39 }, "name": "queryFull", "numberOfRequests": { "ko": 4, "ok": 3565621, "total": 3565625 }, "percentiles1": { "ko": 10000, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10000, "ok": 47, "total": 47 }, "percentiles3": { "ko": 10001, "ok": 49, "total": 49 }, "percentiles4": { "ko": 10001, "ok": 54, "total": 54 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 9, "total": 14 } } ], "global": { "group1": { "count": 7135909, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.99596423697385 }, "group2": { "count": 257, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.003601357978206039 }, "group3": { "count": 18, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0002522351891350533 }, "group4": { "count": 13, "htmlName": "failed", "name": "failed", "percentage": 0.00018216985881976073 }, "maxResponseTime": { "ko": 60000, "ok": 13372, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.007222222222222222, "ok": 3964.5466666666666, "total": 3964.553888888889 }, "meanResponseTime": { "ko": 13847, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 10000, "ok": 39, "total": 39 }, "name": "All Requests", "numberOfRequests": { "ko": 13, "ok": 7136184, "total": 7136197 }, "percentiles1": { "ko": 10001, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10001, "ok": 47, "total": 47 }, "percentiles3": { "ko": 30001, "ok": 50, "total": 50 }, "percentiles4": { "ko": 54000, "ok": 54, "total": 54 }, "standardDeviation": { "ko": 13323, "ok": 11, "total": 28 } } }, "target_hostname": "openam-perf-200m.forgeblocks.com", "tool_name": "gatling" } ________________________________________________________________________________ [2025-03-28 01:35:10] Reporting-mixedquery-4000 step15 : Update run description in the Gatling HTML report ________________________________________________________________________________ ________________________________________________________________________________ [2025-03-28 01:35:10] Reporting-mixedquery-4000 step16 : Remove gatling task's stdout file ________________________________________________________________________________ Cleanup of Gatling stdout file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/10_Reporting-mixedquery-4000/stdout.txt Gatling stdout.txt found, but is small - leave it intact. ________________________________________________________________________________ [2025-03-28 01:35:10] Reporting-mixedquery-4000 post : Check output ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped