--Task-- name: Reporting-mixedquery-2000 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'] preceding_task: None options: {'task_name': 'mixedquery-2000'} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock source (overseer-0) is a component 2025-03-28 01:26:33 - INFO: Timeout for this Task has changed to 3h 30m (12600 seconds) 2025-03-28 01:26:33 - 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-2000/stdout.txt Pod stderr file : /results/orders/Reporting-mixedquery-2000/stderr.txt Pod log : /results/orders/Reporting-mixedquery-2000 ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-2000 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/09_Reporting-mixedquery-2000/order.json { "name": "Reporting-mixedquery-2000", "command": " /lodestar/lodestar.py perf run-gatling --reports-only=\"/results/gatling/mixedquery-2000\" --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx8G\" --archive-name=\"mixedquery-2000.tar.gz\"", "out-dir": "/results/orders/Reporting-mixedquery-2000" } ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-2000 step2 : Make sure overseer is ready to accept order (not already busy) ________________________________________________________________________________ 2025-03-28 01:26:33,096 INFO 2025-03-28 01:26:33,096 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 01:26:33,096 INFO [loop_until]: (max_time=120, interval=5, expected_rc=[0] 2025-03-28 01:26:33,311 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:26:33,311 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:33,311 DEBUG --- stdout --- 2025-03-28 01:26:33,311 DEBUG WAITING 2025-03-28 01:26:33,311 DEBUG --- stderr --- 2025-03-28 01:26:33,311 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 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 33 0 --:--:-- --:--:-- --:--:-- 33 ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-2000 step3 : Send order to overseer ________________________________________________________________________________ 2025-03-28 01:26:33,312 INFO 2025-03-28 01:26:33,312 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:26:33,312 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:26:33,598 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:26:33,598 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:33,598 DEBUG --- stdout --- 2025-03-28 01:26:33,598 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:26:33,599 DEBUG --- stderr --- 2025-03-28 01:26:33,599 DEBUG 2025-03-28 01:26:33,599 INFO 2025-03-28 01:26:33,599 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/09_Reporting-mixedquery-2000/order.json overseer-0-59c948f569-rgrkv:/results/orders/order.json 2025-03-28 01:26:33,599 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:26:34,976 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:34,976 DEBUG --- stdout --- 2025-03-28 01:26:34,976 DEBUG 2025-03-28 01:26:34,976 DEBUG --- stderr --- 2025-03-28 01:26:34,976 DEBUG Order has been successfully forwarded to overseer ________________________________________________________________________________ [2025-03-28 01:26:34] Reporting-mixedquery-2000 step4 : Wait order is done ________________________________________________________________________________ Workaround for PERF-1966. Sleeping for 5 seconds. 2025-03-28 01:26:39,977 INFO 2025-03-28 01:26:39,977 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 01:26:39,977 INFO [loop_until]: (max_time=12600, interval=5, expected_rc=[0] 2025-03-28 01:26:40,197 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:45,414 INFO [loop_until]: Function succeeded after 5s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:50,724 INFO [loop_until]: Function succeeded after 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:55,939 INFO [loop_until]: Function succeeded after 15s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:01,154 INFO [loop_until]: Function succeeded after 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:06,370 INFO [loop_until]: Function succeeded after 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:11,586 INFO [loop_until]: Function succeeded after 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:16,801 INFO [loop_until]: Function succeeded after 36s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:22,060 INFO [loop_until]: Function succeeded after 42s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:27,275 INFO [loop_until]: Function succeeded after 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:32,490 INFO [loop_until]: Function succeeded after 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:37,707 INFO [loop_until]: Function succeeded after 57s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:42,921 INFO [loop_until]: Function succeeded after 1m 02s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:48,136 INFO [loop_until]: Function succeeded after 1m 08s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:53,395 INFO [loop_until]: Function succeeded after 1m 13s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:27:58,610 INFO [loop_until]: Function succeeded after 1m 18s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:03,826 INFO [loop_until]: Function succeeded after 1m 23s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:09,041 INFO [loop_until]: Function succeeded after 1m 29s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:14,256 INFO [loop_until]: Function succeeded after 1m 34s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:19,470 INFO [loop_until]: Function succeeded after 1m 39s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:24,729 INFO [loop_until]: Function succeeded after 1m 44s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:29,944 INFO [loop_until]: Function succeeded after 1m 49s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:35,162 INFO [loop_until]: Function succeeded after 1m 55s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:40,378 INFO [loop_until]: Function succeeded after 2m (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:45,593 INFO [loop_until]: Function succeeded after 2m 05s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:50,808 INFO [loop_until]: Function succeeded after 2m 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:28:56,076 INFO [loop_until]: Function succeeded after 2m 16s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:01,291 INFO [loop_until]: Function succeeded after 2m 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:06,506 INFO [loop_until]: Function succeeded after 2m 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:11,721 INFO [loop_until]: Function succeeded after 2m 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:29:16,936 INFO [loop_until]: Function succeeded after 2m 36s (rc=0) - expected pattern found 2025-03-28 01:29:16,936 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:16,936 DEBUG --- stdout --- 2025-03-28 01:29:16,936 DEBUG WAITING 2025-03-28 01:29:16,936 DEBUG --- stderr --- 2025-03-28 01:29:16,936 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:29:16] Reporting-mixedquery-2000 step5 : Wait until gatling report is generated on overseer ________________________________________________________________________________ 2025-03-28 01:29:16,936 INFO 2025-03-28 01:29:16,936 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:16,936 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:29:17,243 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:29:17,243 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:17,243 DEBUG --- stdout --- 2025-03-28 01:29:17,243 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:29:17,243 DEBUG --- stderr --- 2025-03-28 01:29:17,243 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:29:17,244 INFO 2025-03-28 01:29:17,244 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-2000/mixedquery-2000.tar.gz" ]; then echo "/results/gatling/mixedquery-2000/mixedquery-2000.tar.gz file found"; exit 0; else echo "/results/gatling/mixedquery-2000/mixedquery-2000.tar.gz file not found"; exit 1; fi' | grep "/results/gatling/mixedquery-2000/mixedquery-2000.tar.gz file found" 2025-03-28 01:29:17,244 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:29:18,103 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:29:18,103 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:18,103 DEBUG --- stdout --- 2025-03-28 01:29:18,103 DEBUG /results/gatling/mixedquery-2000/mixedquery-2000.tar.gz file found 2025-03-28 01:29:18,103 DEBUG --- stderr --- 2025-03-28 01:29:18,103 DEBUG 2025-03-28 01:29:18,103 INFO 2025-03-28 01:29:18,104 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-2000/mixedquery-2000.tar.gz 2025-03-28 01:29:18,907 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:29:18,907 DEBUG --- stdout --- 2025-03-28 01:29:18,907 DEBUG 312 /results/gatling/mixedquery-2000/mixedquery-2000.tar.gz 2025-03-28 01:29:18,907 DEBUG --- stderr --- 2025-03-28 01:29:18,907 DEBUG 2025-03-28 01:29:18,907 INFO - Download file (size 312k) source : /results/gatling/mixedquery-2000/mixedquery-2000.tar.gz @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-2000.tar.gz 2025-03-28 01:29:18,908 INFO 2025-03-28 01:29:18,908 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/gatling/mixedquery-2000/mixedquery-2000.tar.gz /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-2000.tar.gz 2025-03-28 01:29:18,908 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:29:19,913 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:19,913 DEBUG --- stdout --- 2025-03-28 01:29:19,913 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:29:19,913 DEBUG --- stderr --- 2025-03-28 01:29:19,913 DEBUG ________________________________________________________________________________ [2025-03-28 01:29:19] Reporting-mixedquery-2000 step6 : Unzip the result ________________________________________________________________________________ 2025-03-28 01:29:19,913 INFO 2025-03-28 01:29:19,913 INFO [run_command]: tar zxf /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-2000.tar.gz -C /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/02_mixedquery-2000/gatling 2025-03-28 01:29:19,929 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:29:19,929 DEBUG --- stdout --- 2025-03-28 01:29:19,929 DEBUG 2025-03-28 01:29:19,929 DEBUG --- stderr --- 2025-03-28 01:29:19,929 DEBUG 2025-03-28 01:29:19,929 INFO ________________________________________________________________________________ [2025-03-28 01:29:19] Reporting-mixedquery-2000 step7 : Print rc order ________________________________________________________________________________ 2025-03-28 01:29:19,930 INFO 2025-03-28 01:29:19,930 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:19,930 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:29:20,210 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:29:20,210 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:20,210 DEBUG --- stdout --- 2025-03-28 01:29:20,210 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:29:20,210 DEBUG --- stderr --- 2025-03-28 01:29:20,210 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:29:20,211 INFO 2025-03-28 01:29:20,212 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-2000/rc.txt" ]; then echo "/results/orders/Reporting-mixedquery-2000/rc.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-2000/rc.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-2000/rc.txt file found" 2025-03-28 01:29:20,212 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:29:21,008 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:29:21,009 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:21,009 DEBUG --- stdout --- 2025-03-28 01:29:21,009 DEBUG /results/orders/Reporting-mixedquery-2000/rc.txt file found 2025-03-28 01:29:21,009 DEBUG --- stderr --- 2025-03-28 01:29:21,009 DEBUG 2025-03-28 01:29:21,009 INFO 2025-03-28 01:29:21,009 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-2000/rc.txt 2025-03-28 01:29:21,827 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:29:21,827 DEBUG --- stdout --- 2025-03-28 01:29:21,827 DEBUG 4 /results/orders/Reporting-mixedquery-2000/rc.txt 2025-03-28 01:29:21,827 DEBUG --- stderr --- 2025-03-28 01:29:21,827 DEBUG 2025-03-28 01:29:21,827 INFO - Download file (size 4k) source : /results/orders/Reporting-mixedquery-2000/rc.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/rc.txt 2025-03-28 01:29:21,828 INFO 2025-03-28 01:29:21,828 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-2000/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/rc.txt 2025-03-28 01:29:21,828 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:29:22,589 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:22,589 DEBUG --- stdout --- 2025-03-28 01:29:22,590 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:29:22,590 DEBUG --- stderr --- 2025-03-28 01:29:22,590 DEBUG 2025-03-28 01:29:22,590 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/rc.txt is small (1 lines), printing all lines: 2025-03-28 01:29:22,590 INFO ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [2025-03-28 01:29:22] Reporting-mixedquery-2000 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:29:22] Reporting-mixedquery-2000 step9 : Print stdout order ________________________________________________________________________________ 2025-03-28 01:29:22,829 INFO 2025-03-28 01:29:22,829 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:22,829 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:29:23,107 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:29:23,107 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:23,107 DEBUG --- stdout --- 2025-03-28 01:29:23,107 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:29:23,107 DEBUG --- stderr --- 2025-03-28 01:29:23,107 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:29:23,108 INFO 2025-03-28 01:29:23,108 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-2000/stdout.txt" ]; then echo "/results/orders/Reporting-mixedquery-2000/stdout.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-2000/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-2000/stdout.txt file found" 2025-03-28 01:29:23,108 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:29:23,908 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:29:23,908 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:23,908 DEBUG --- stdout --- 2025-03-28 01:29:23,908 DEBUG /results/orders/Reporting-mixedquery-2000/stdout.txt file found 2025-03-28 01:29:23,908 DEBUG --- stderr --- 2025-03-28 01:29:23,908 DEBUG 2025-03-28 01:29:23,908 INFO 2025-03-28 01:29:23,908 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-2000/stdout.txt 2025-03-28 01:29:24,718 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:29:24,718 DEBUG --- stdout --- 2025-03-28 01:29:24,719 DEBUG 8 /results/orders/Reporting-mixedquery-2000/stdout.txt 2025-03-28 01:29:24,719 DEBUG --- stderr --- 2025-03-28 01:29:24,719 DEBUG 2025-03-28 01:29:24,719 INFO - Download file (size 8k) source : /results/orders/Reporting-mixedquery-2000/stdout.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/stdout.txt 2025-03-28 01:29:24,719 INFO 2025-03-28 01:29:24,719 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-2000/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/stdout.txt 2025-03-28 01:29:24,719 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:29:25,622 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:25,622 DEBUG --- stdout --- 2025-03-28 01:29:25,622 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:29:25,622 DEBUG --- stderr --- 2025-03-28 01:29:25,622 DEBUG 2025-03-28 01:29:25,622 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/stdout.txt is small (93 lines), printing all lines: 2025-03-28 01:29:25,622 INFO ----- output ----- 2025-03-28 01:26:35,919 INFO pom.xml copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpo7ae1j1m 2025-03-28 01:26:35,921 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.reportsOnly="/results/gatling/mixedquery-2000/loadtest-20250327225132789" -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/tmpo7ae1j1m/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/tmpo7ae1j1m/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:26:37,757 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.5.8 01:26:37,758 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - No custom configurators were discovered as a service. 01:26:37,758 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator 01:26:37,759 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator 01:26:37,765 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo] 01:26:37,765 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo] 01:26:37,772 |-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:26:37,772 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator 01:26:37,773 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator 01:26:37,773 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 01:26:37,776 |-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:26:37,781 |-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:26:37,827 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - element is deprecated. Near [level] on line 12 01:26:37,827 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within or elements instead. 01:26:37,867 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE] 01:26:37,867 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 01:26:37,873 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 01:26:37,895 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - ROOT level set to WARN 01:26:37,895 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT] 01:26:37,896 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@25a65b77 - End of configuration. 01:26:37,896 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2ed0fbae - Registering current configuration as safe fallback point 01:26:37,896 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 123 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY Parsing log file(s)... Parsing log file(s) done in 155s. Generating reports... ================================================================================ ---- Global Information -------------------------------------------------------- > request count 3569276 (OK=3569272 KO=4 ) > min response time 38 (OK=38 KO=205 ) > max response time 52439 (OK=52439 KO=10001 ) > mean response time 46 (OK=46 KO=7552 ) > std deviation 35 (OK=34 KO=4242 ) > 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=10001 ) > response time 99th percentile 53 (OK=53 KO=10001 ) > mean requests/sec 1982.93 (OK=1982.93 KO=0 ) ---- Response Time Distribution ------------------------------------------------ > t < 800 ms 3569125 ( 100%) > 800 ms <= t < 1200 ms 125 ( 0%) > t >= 1200 ms 22 ( 0%) > failed 4 ( 0%) ---- Errors -------------------------------------------------------------------- > i.n.h.s.SslHandshakeTimeoutException: handshake timed out afte 2 (50.00%) r 10000ms > status.find.in(200), but actually found 503 1 (25.00%) > i.n.c.ConnectTimeoutException: connection timed out after 1000 1 (25.00%) 0 ms: openam-perf-200m.forgeblocks.com/34.107.203.37:443 ================================================================================ Reports generated, please open the following file: file:///results/gatling/mixedquery-2000/loadtest-20250327225132789/index.html [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 02:37 min [INFO] Finished at: 2025-03-28T01:29:14Z [INFO] ------------------------------------------------------------------------ 2025-03-28 01:29:14,359 INFO Gatling simulation run ended successfully 2025-03-28 01:29:14,359 INFO Creating archive mixedquery-2000.tar.gz with report files 2025-03-28 01:29:14,458 INFO Archive /results/gatling/mixedquery-2000/mixedquery-2000.tar.gz successfully created ________________________________________________________________________________ [2025-03-28 01:29:25] Reporting-mixedquery-2000 step10 : Check stdout log and parse its content ________________________________________________________________________________ PASS: no error found in stdout log ________________________________________________________________________________ [2025-03-28 01:29:25] Reporting-mixedquery-2000 step11 : Print stderr order ________________________________________________________________________________ 2025-03-28 01:29:25,623 INFO 2025-03-28 01:29:25,623 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:25,623 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:29:25,902 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:29:25,902 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:25,902 DEBUG --- stdout --- 2025-03-28 01:29:25,902 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:29:25,902 DEBUG --- stderr --- 2025-03-28 01:29:25,902 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:29:25,903 INFO 2025-03-28 01:29:25,903 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-2000/stderr.txt" ]; then echo "/results/orders/Reporting-mixedquery-2000/stderr.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-2000/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-2000/stderr.txt file found" 2025-03-28 01:29:25,903 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:29:26,698 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:29:26,698 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:26,698 DEBUG --- stdout --- 2025-03-28 01:29:26,698 DEBUG /results/orders/Reporting-mixedquery-2000/stderr.txt file found 2025-03-28 01:29:26,698 DEBUG --- stderr --- 2025-03-28 01:29:26,699 DEBUG 2025-03-28 01:29:26,699 INFO 2025-03-28 01:29:26,699 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-2000/stderr.txt 2025-03-28 01:29:27,497 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:29:27,497 DEBUG --- stdout --- 2025-03-28 01:29:27,497 DEBUG 0 /results/orders/Reporting-mixedquery-2000/stderr.txt 2025-03-28 01:29:27,497 DEBUG --- stderr --- 2025-03-28 01:29:27,497 DEBUG 2025-03-28 01:29:27,497 INFO - Download file (size 0k) source : /results/orders/Reporting-mixedquery-2000/stderr.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/stderr.txt 2025-03-28 01:29:27,498 INFO 2025-03-28 01:29:27,498 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-2000/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/stderr.txt 2025-03-28 01:29:27,498 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:29:28,245 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:29:28,245 DEBUG --- stdout --- 2025-03-28 01:29:28,245 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:29:28,245 DEBUG --- stderr --- 2025-03-28 01:29:28,245 DEBUG 2025-03-28 01:29:28,245 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/09_Reporting-mixedquery-2000/stderr.txt is small (0 lines), printing all lines: 2025-03-28 01:29:28,245 INFO ----- output ----- ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-2000 step12 : Check stderr log ________________________________________________________________________________ PASS: no error found in stderr log ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-2000 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 queryFull [warn] responseTimePercentiles was not found in /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/02_mixedquery-2000/gatling/req_queryfull--1807283337.html - cannot check for spikes 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/02_mixedquery-2000/gatling/req_readmanageduser--1429285772.html - cannot check for spikes no spikes found ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-2000 step14 : Collect Gatling simulation data ________________________________________________________________________________ collected stats : { "global": { "name": "All Requests", "numberOfRequests": { "total": 3569276, "ok": 3569272, "ko": 4 }, "minResponseTime": { "total": 38, "ok": 38, "ko": 205 }, "maxResponseTime": { "total": 52439, "ok": 52439, "ko": 10001 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 7552 }, "standardDeviation": { "total": 35, "ok": 34, "ko": 4242 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10001 }, "percentiles2": { "total": 47, "ok": 47, "ko": 10001 }, "percentiles3": { "total": 50, "ok": 50, "ko": 10001 }, "percentiles4": { "total": 53, "ok": 53, "ko": 10001 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 3569125, "percentage": 99.995769450163 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 125, "percentage": 0.003502110792216685 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 22, "percentage": 0.0006163714994301365 }, "group4": { "name": "failed", "htmlName": "failed", "count": 4, "percentage": 0.00011206754535093392 }, "meanNumberOfRequestsPerSecond": { "total": 1982.931111111111, "ok": 1982.9288888888889, "ko": 0.0022222222222222222 } }, "details": [ { "name": "restLoginInitiate", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 72, "ok": 72, "ko": 0 }, "maxResponseTime": { "total": 72, "ok": 72, "ko": 0 }, "meanResponseTime": { "total": 72, "ok": 72, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 72, "ok": 72, "ko": 0 }, "percentiles2": { "total": 72, "ok": 72, "ko": 0 }, "percentiles3": { "total": 72, "ok": 72, "ko": 0 }, "percentiles4": { "total": 72, "ok": 72, "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": 140, "ok": 140, "ko": 0 }, "maxResponseTime": { "total": 140, "ok": 140, "ko": 0 }, "meanResponseTime": { "total": 140, "ok": 140, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 140, "ok": 140, "ko": 0 }, "percentiles2": { "total": 140, "ok": 140, "ko": 0 }, "percentiles3": { "total": 140, "ok": 140, "ko": 0 }, "percentiles4": { "total": 140, "ok": 140, "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": 78, "ok": 78, "ko": 0 }, "maxResponseTime": { "total": 78, "ok": 78, "ko": 0 }, "meanResponseTime": { "total": 78, "ok": 78, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 78, "ok": 78, "ko": 0 }, "percentiles2": { "total": 78, "ok": 78, "ko": 0 }, "percentiles3": { "total": 78, "ok": 78, "ko": 0 }, "percentiles4": { "total": 78, "ok": 78, "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": 66, "ok": 66, "ko": 0 }, "maxResponseTime": { "total": 66, "ok": 66, "ko": 0 }, "meanResponseTime": { "total": 66, "ok": 66, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 66, "ok": 66, "ko": 0 }, "percentiles2": { "total": 66, "ok": 66, "ko": 0 }, "percentiles3": { "total": 66, "ok": 66, "ko": 0 }, "percentiles4": { "total": 66, "ok": 66, "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": 60, "ok": 60, "ko": 0 }, "maxResponseTime": { "total": 60, "ok": 60, "ko": 0 }, "meanResponseTime": { "total": 60, "ok": 60, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 60, "ok": 60, "ko": 0 }, "percentiles2": { "total": 60, "ok": 60, "ko": 0 }, "percentiles3": { "total": 60, "ok": 60, "ko": 0 }, "percentiles4": { "total": 60, "ok": 60, "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": "queryFull", "numberOfRequests": { "total": 1783460, "ok": 1783457, "ko": 3 }, "minResponseTime": { "total": 38, "ok": 38, "ko": 205 }, "maxResponseTime": { "total": 12928, "ok": 12928, "ko": 10001 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 6735 }, "standardDeviation": { "total": 19, "ok": 16, "ko": 4618 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10000 }, "percentiles2": { "total": 47, "ok": 47, "ko": 10001 }, "percentiles3": { "total": 49, "ok": 49, "ko": 10001 }, "percentiles4": { "total": 53, "ok": 53, "ko": 10001 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1783387, "percentage": 99.9959068327857 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 61, "percentage": 0.003420317809202337 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 9, "percentage": 0.0005046370538167382 }, "group4": { "name": "failed", "htmlName": "failed", "count": 3, "percentage": 0.00016821235127224607 }, "meanNumberOfRequestsPerSecond": { "total": 990.8111111111111, "ok": 990.8094444444445, "ko": 0.0016666666666666668 }, "spikes": [] }, { "name": "ReadManagedUser", "numberOfRequests": { "total": 1785811, "ok": 1785810, "ko": 1 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 10001 }, "maxResponseTime": { "total": 52439, "ok": 52439, "ko": 10001 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 10001 }, "standardDeviation": { "total": 46, "ok": 45, "ko": 0 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10001 }, "percentiles2": { "total": 48, "ok": 48, "ko": 10001 }, "percentiles3": { "total": 50, "ok": 50, "ko": 10001 }, "percentiles4": { "total": 54, "ok": 54, "ko": 10001 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1785733, "percentage": 99.99563223655807 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 64, "percentage": 0.003583805901072398 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 13, "percentage": 0.0007279605736553309 }, "group4": { "name": "failed", "htmlName": "failed", "count": 1, "percentage": 5.599696720425622e-05 }, "meanNumberOfRequestsPerSecond": { "total": 992.1172222222223, "ok": 992.1166666666667, "ko": 0.0005555555555555556 }, "spikes": [] } ] } { "concurrency": null, "generic_stats": { "avg_num_of_requests_per_second": 1983, "avg_response_time": 46, "max_response_time": 52439, "min_response_time": 38, "num_requests": 3569276, "num_requests_pass": 3569272, "num_requests_percent_pass": 100.0 }, "options": "; testMode:open; testCase:idm.MixedQuery; duration:1800; throughput:2000", "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": 72, "total": 72 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 72, "total": 72 }, "minResponseTime": { "ko": 0, "ok": 72, "total": 72 }, "name": "restLoginInitiate", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 72, "total": 72 }, "percentiles2": { "ko": 0, "ok": 72, "total": 72 }, "percentiles3": { "ko": 0, "ok": 72, "total": 72 }, "percentiles4": { "ko": 0, "ok": 72, "total": 72 }, "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": 140, "total": 140 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 140, "total": 140 }, "minResponseTime": { "ko": 0, "ok": 140, "total": 140 }, "name": "restLoginUsernamePasswordCallback", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 140, "total": 140 }, "percentiles2": { "ko": 0, "ok": 140, "total": 140 }, "percentiles3": { "ko": 0, "ok": 140, "total": 140 }, "percentiles4": { "ko": 0, "ok": 140, "total": 140 }, "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": 78, "total": 78 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 78, "total": 78 }, "minResponseTime": { "ko": 0, "ok": 78, "total": 78 }, "name": "Skip 2FA", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 78, "total": 78 }, "percentiles2": { "ko": 0, "ok": 78, "total": 78 }, "percentiles3": { "ko": 0, "ok": 78, "total": 78 }, "percentiles4": { "ko": 0, "ok": 78, "total": 78 }, "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": 66, "total": 66 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 66, "total": 66 }, "minResponseTime": { "ko": 0, "ok": 66, "total": 66 }, "name": "User Authorize PKCE stage", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 66, "total": 66 }, "percentiles2": { "ko": 0, "ok": 66, "total": 66 }, "percentiles3": { "ko": 0, "ok": 66, "total": 66 }, "percentiles4": { "ko": 0, "ok": 66, "total": 66 }, "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": 60, "total": 60 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 60, "total": 60 }, "minResponseTime": { "ko": 0, "ok": 60, "total": 60 }, "name": "User AccessToken PKCE stage", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 60, "total": 60 }, "percentiles2": { "ko": 0, "ok": 60, "total": 60 }, "percentiles3": { "ko": 0, "ok": 60, "total": 60 }, "percentiles4": { "ko": 0, "ok": 60, "total": 60 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 1783387, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.9959068327857 }, "group2": { "count": 61, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.003420317809202337 }, "group3": { "count": 9, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0005046370538167382 }, "group4": { "count": 3, "htmlName": "failed", "name": "failed", "percentage": 0.00016821235127224607 }, "maxResponseTime": { "ko": 10001, "ok": 12928, "total": 12928 }, "meanNumberOfRequestsPerSecond": { "ko": 0.0016666666666666668, "ok": 990.8094444444445, "total": 990.8111111111111 }, "meanResponseTime": { "ko": 6735, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 205, "ok": 38, "total": 38 }, "name": "queryFull", "numberOfRequests": { "ko": 3, "ok": 1783457, "total": 1783460 }, "percentiles1": { "ko": 10000, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10001, "ok": 47, "total": 47 }, "percentiles3": { "ko": 10001, "ok": 49, "total": 49 }, "percentiles4": { "ko": 10001, "ok": 53, "total": 53 }, "spikes": [], "standardDeviation": { "ko": 4618, "ok": 16, "total": 19 } }, { "group1": { "count": 1785733, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.99563223655807 }, "group2": { "count": 64, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.003583805901072398 }, "group3": { "count": 13, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0007279605736553309 }, "group4": { "count": 1, "htmlName": "failed", "name": "failed", "percentage": 5.599696720425622e-05 }, "maxResponseTime": { "ko": 10001, "ok": 52439, "total": 52439 }, "meanNumberOfRequestsPerSecond": { "ko": 0.0005555555555555556, "ok": 992.1166666666667, "total": 992.1172222222223 }, "meanResponseTime": { "ko": 10001, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 10001, "ok": 39, "total": 39 }, "name": "ReadManagedUser", "numberOfRequests": { "ko": 1, "ok": 1785810, "total": 1785811 }, "percentiles1": { "ko": 10001, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10001, "ok": 48, "total": 48 }, "percentiles3": { "ko": 10001, "ok": 50, "total": 50 }, "percentiles4": { "ko": 10001, "ok": 54, "total": 54 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 45, "total": 46 } } ], "global": { "group1": { "count": 3569125, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.995769450163 }, "group2": { "count": 125, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.003502110792216685 }, "group3": { "count": 22, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0006163714994301365 }, "group4": { "count": 4, "htmlName": "failed", "name": "failed", "percentage": 0.00011206754535093392 }, "maxResponseTime": { "ko": 10001, "ok": 52439, "total": 52439 }, "meanNumberOfRequestsPerSecond": { "ko": 0.0022222222222222222, "ok": 1982.9288888888889, "total": 1982.931111111111 }, "meanResponseTime": { "ko": 7552, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 205, "ok": 38, "total": 38 }, "name": "All Requests", "numberOfRequests": { "ko": 4, "ok": 3569272, "total": 3569276 }, "percentiles1": { "ko": 10001, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10001, "ok": 47, "total": 47 }, "percentiles3": { "ko": 10001, "ok": 50, "total": 50 }, "percentiles4": { "ko": 10001, "ok": 53, "total": 53 }, "standardDeviation": { "ko": 4242, "ok": 34, "total": 35 } } }, "target_hostname": "openam-perf-200m.forgeblocks.com", "tool_name": "gatling" } ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-2000 step15 : Update run description in the Gatling HTML report ________________________________________________________________________________ ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-2000 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/09_Reporting-mixedquery-2000/stdout.txt Gatling stdout.txt found, but is small - leave it intact. ________________________________________________________________________________ [2025-03-28 01:29:28] Reporting-mixedquery-2000 post : Check output ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped