--Task-- name: Reporting-mixedquery-1000 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'] preceding_task: None options: {'task_name': 'mixedquery-1000'} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock source (overseer-0) is a component 2025-03-28 01:24:50 - INFO: Timeout for this Task has changed to 3h 30m (12600 seconds) 2025-03-28 01:24:50 - 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-1000/stdout.txt Pod stderr file : /results/orders/Reporting-mixedquery-1000/stderr.txt Pod log : /results/orders/Reporting-mixedquery-1000 ________________________________________________________________________________ [2025-03-28 01:24:50] Reporting-mixedquery-1000 step1 : Write order for overseer to generate the report ________________________________________________________________________________ 2025-03-28 01:24:50 - INFO: Get overseer pod resources requests memory 2025-03-28 01:24:50,940 INFO 2025-03-28 01:24:50,940 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods overseer-0-59c948f569-rgrkv --output jsonpath={.spec.containers[].resources.requests.memory} 2025-03-28 01:24:50,940 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:24:51,217 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:24:51,217 DEBUG --- stdout --- 2025-03-28 01:24:51,217 DEBUG 8Gi 2025-03-28 01:24:51,217 DEBUG --- stderr --- 2025-03-28 01:24:51,217 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/order.json { "name": "Reporting-mixedquery-1000", "command": " /lodestar/lodestar.py perf run-gatling --reports-only=\"/results/gatling/mixedquery-1000\" --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx8G\" --archive-name=\"mixedquery-1000.tar.gz\"", "out-dir": "/results/orders/Reporting-mixedquery-1000" } ________________________________________________________________________________ [2025-03-28 01:24:51] Reporting-mixedquery-1000 step2 : Make sure overseer is ready to accept order (not already busy) ________________________________________________________________________________ 2025-03-28 01:24:51,218 INFO 2025-03-28 01:24:51,218 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 01:24:51,218 INFO [loop_until]: (max_time=120, interval=5, expected_rc=[0] 2025-03-28 01:24:51,433 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:24:51,433 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:24:51,433 DEBUG --- stdout --- 2025-03-28 01:24:51,433 DEBUG WAITING 2025-03-28 01:24:51,433 DEBUG --- stderr --- 2025-03-28 01:24:51,433 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 --:--:-- --:--:-- --:--:-- 34 ________________________________________________________________________________ [2025-03-28 01:24:51] Reporting-mixedquery-1000 step3 : Send order to overseer ________________________________________________________________________________ 2025-03-28 01:24:51,433 INFO 2025-03-28 01:24:51,433 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:24:51,433 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:24:51,720 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:24:51,720 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:24:51,720 DEBUG --- stdout --- 2025-03-28 01:24:51,720 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:24:51,720 DEBUG --- stderr --- 2025-03-28 01:24:51,720 DEBUG 2025-03-28 01:24:51,721 INFO 2025-03-28 01:24:51,721 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/08_Reporting-mixedquery-1000/order.json overseer-0-59c948f569-rgrkv:/results/orders/order.json 2025-03-28 01:24:51,721 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:24:53,077 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:24:53,077 DEBUG --- stdout --- 2025-03-28 01:24:53,077 DEBUG 2025-03-28 01:24:53,077 DEBUG --- stderr --- 2025-03-28 01:24:53,077 DEBUG Order has been successfully forwarded to overseer ________________________________________________________________________________ [2025-03-28 01:24:53] Reporting-mixedquery-1000 step4 : Wait order is done ________________________________________________________________________________ Workaround for PERF-1966. Sleeping for 5 seconds. 2025-03-28 01:24:58,078 INFO 2025-03-28 01:24:58,078 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 01:24:58,078 INFO [loop_until]: (max_time=12600, interval=5, expected_rc=[0] 2025-03-28 01:24:58,296 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:03,514 INFO [loop_until]: Function succeeded after 5s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:08,781 INFO [loop_until]: Function succeeded after 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:13,996 INFO [loop_until]: Function succeeded after 15s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:19,211 INFO [loop_until]: Function succeeded after 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:24,427 INFO [loop_until]: Function succeeded after 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:29,641 INFO [loop_until]: Function succeeded after 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:34,856 INFO [loop_until]: Function succeeded after 36s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:40,076 INFO [loop_until]: Function succeeded after 41s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:45,395 INFO [loop_until]: Function succeeded after 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:50,610 INFO [loop_until]: Function succeeded after 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:25:55,824 INFO [loop_until]: Function succeeded after 57s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:01,039 INFO [loop_until]: Function succeeded after 1m 02s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:06,254 INFO [loop_until]: Function succeeded after 1m 08s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:11,512 INFO [loop_until]: Function succeeded after 1m 13s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:16,727 INFO [loop_until]: Function succeeded after 1m 18s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 01:26:21,942 INFO [loop_until]: Function succeeded after 1m 23s (rc=0) - expected pattern found 2025-03-28 01:26:21,942 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:21,942 DEBUG --- stdout --- 2025-03-28 01:26:21,942 DEBUG WAITING 2025-03-28 01:26:21,942 DEBUG --- stderr --- 2025-03-28 01:26:21,942 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:26:21] Reporting-mixedquery-1000 step5 : Wait until gatling report is generated on overseer ________________________________________________________________________________ 2025-03-28 01:26:21,943 INFO 2025-03-28 01:26:21,943 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:21,943 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:26:22,245 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:26:22,245 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:22,245 DEBUG --- stdout --- 2025-03-28 01:26:22,246 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:26:22,246 DEBUG --- stderr --- 2025-03-28 01:26:22,246 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:26:22,247 INFO 2025-03-28 01:26:22,247 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-1000/mixedquery-1000.tar.gz" ]; then echo "/results/gatling/mixedquery-1000/mixedquery-1000.tar.gz file found"; exit 0; else echo "/results/gatling/mixedquery-1000/mixedquery-1000.tar.gz file not found"; exit 1; fi' | grep "/results/gatling/mixedquery-1000/mixedquery-1000.tar.gz file found" 2025-03-28 01:26:22,247 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:26:23,099 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:26:23,099 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:23,099 DEBUG --- stdout --- 2025-03-28 01:26:23,099 DEBUG /results/gatling/mixedquery-1000/mixedquery-1000.tar.gz file found 2025-03-28 01:26:23,099 DEBUG --- stderr --- 2025-03-28 01:26:23,099 DEBUG 2025-03-28 01:26:23,099 INFO 2025-03-28 01:26:23,099 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-1000/mixedquery-1000.tar.gz 2025-03-28 01:26:23,894 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:26:23,894 DEBUG --- stdout --- 2025-03-28 01:26:23,894 DEBUG 312 /results/gatling/mixedquery-1000/mixedquery-1000.tar.gz 2025-03-28 01:26:23,894 DEBUG --- stderr --- 2025-03-28 01:26:23,894 DEBUG 2025-03-28 01:26:23,894 INFO - Download file (size 312k) source : /results/gatling/mixedquery-1000/mixedquery-1000.tar.gz @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-1000.tar.gz 2025-03-28 01:26:23,895 INFO 2025-03-28 01:26:23,895 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/gatling/mixedquery-1000/mixedquery-1000.tar.gz /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-1000.tar.gz 2025-03-28 01:26:23,895 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:26:24,901 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:24,901 DEBUG --- stdout --- 2025-03-28 01:26:24,901 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:26:24,901 DEBUG --- stderr --- 2025-03-28 01:26:24,901 DEBUG ________________________________________________________________________________ [2025-03-28 01:26:24] Reporting-mixedquery-1000 step6 : Unzip the result ________________________________________________________________________________ 2025-03-28 01:26:24,902 INFO 2025-03-28 01:26:24,902 INFO [run_command]: tar zxf /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/mixedquery-1000.tar.gz -C /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/01_mixedquery-1000/gatling 2025-03-28 01:26:24,917 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:26:24,917 DEBUG --- stdout --- 2025-03-28 01:26:24,917 DEBUG 2025-03-28 01:26:24,917 DEBUG --- stderr --- 2025-03-28 01:26:24,917 DEBUG 2025-03-28 01:26:24,917 INFO ________________________________________________________________________________ [2025-03-28 01:26:24] Reporting-mixedquery-1000 step7 : Print rc order ________________________________________________________________________________ 2025-03-28 01:26:24,918 INFO 2025-03-28 01:26:24,918 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:24,918 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:26:25,228 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:26:25,229 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:25,229 DEBUG --- stdout --- 2025-03-28 01:26:25,229 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:26:25,229 DEBUG --- stderr --- 2025-03-28 01:26:25,229 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:26:25,230 INFO 2025-03-28 01:26:25,230 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-1000/rc.txt" ]; then echo "/results/orders/Reporting-mixedquery-1000/rc.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-1000/rc.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-1000/rc.txt file found" 2025-03-28 01:26:25,230 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:26:26,083 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:26:26,083 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:26,083 DEBUG --- stdout --- 2025-03-28 01:26:26,084 DEBUG /results/orders/Reporting-mixedquery-1000/rc.txt file found 2025-03-28 01:26:26,084 DEBUG --- stderr --- 2025-03-28 01:26:26,084 DEBUG 2025-03-28 01:26:26,084 INFO 2025-03-28 01:26:26,084 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-1000/rc.txt 2025-03-28 01:26:26,882 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:26:26,882 DEBUG --- stdout --- 2025-03-28 01:26:26,882 DEBUG 4 /results/orders/Reporting-mixedquery-1000/rc.txt 2025-03-28 01:26:26,882 DEBUG --- stderr --- 2025-03-28 01:26:26,882 DEBUG 2025-03-28 01:26:26,882 INFO - Download file (size 4k) source : /results/orders/Reporting-mixedquery-1000/rc.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/rc.txt 2025-03-28 01:26:26,883 INFO 2025-03-28 01:26:26,883 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-1000/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/rc.txt 2025-03-28 01:26:26,883 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:26:27,616 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:27,616 DEBUG --- stdout --- 2025-03-28 01:26:27,617 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:26:27,617 DEBUG --- stderr --- 2025-03-28 01:26:27,617 DEBUG 2025-03-28 01:26:27,617 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/rc.txt is small (1 lines), printing all lines: 2025-03-28 01:26:27,617 INFO ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [2025-03-28 01:26:27] Reporting-mixedquery-1000 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:26:27] Reporting-mixedquery-1000 step9 : Print stdout order ________________________________________________________________________________ 2025-03-28 01:26:27,855 INFO 2025-03-28 01:26:27,855 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:27,855 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:26:28,135 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:26:28,135 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:28,135 DEBUG --- stdout --- 2025-03-28 01:26:28,135 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:26:28,135 DEBUG --- stderr --- 2025-03-28 01:26:28,135 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:26:28,137 INFO 2025-03-28 01:26:28,137 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-1000/stdout.txt" ]; then echo "/results/orders/Reporting-mixedquery-1000/stdout.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-1000/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-1000/stdout.txt file found" 2025-03-28 01:26:28,137 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:26:28,950 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:26:28,950 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:28,950 DEBUG --- stdout --- 2025-03-28 01:26:28,950 DEBUG /results/orders/Reporting-mixedquery-1000/stdout.txt file found 2025-03-28 01:26:28,950 DEBUG --- stderr --- 2025-03-28 01:26:28,950 DEBUG 2025-03-28 01:26:28,950 INFO 2025-03-28 01:26:28,951 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-1000/stdout.txt 2025-03-28 01:26:29,750 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:26:29,750 DEBUG --- stdout --- 2025-03-28 01:26:29,750 DEBUG 8 /results/orders/Reporting-mixedquery-1000/stdout.txt 2025-03-28 01:26:29,750 DEBUG --- stderr --- 2025-03-28 01:26:29,750 DEBUG 2025-03-28 01:26:29,750 INFO - Download file (size 8k) source : /results/orders/Reporting-mixedquery-1000/stdout.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/stdout.txt 2025-03-28 01:26:29,751 INFO 2025-03-28 01:26:29,751 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-1000/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/stdout.txt 2025-03-28 01:26:29,751 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:26:30,482 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:30,482 DEBUG --- stdout --- 2025-03-28 01:26:30,482 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:26:30,482 DEBUG --- stderr --- 2025-03-28 01:26:30,482 DEBUG 2025-03-28 01:26:30,482 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/stdout.txt is small (94 lines), printing all lines: 2025-03-28 01:26:30,482 INFO ----- output ----- 2025-03-28 01:24:53,898 INFO pom.xml copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp87rsytf0 2025-03-28 01:24:53,900 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.reportsOnly="/results/gatling/mixedquery-1000/loadtest-20250327222058851" -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/tmp87rsytf0/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/tmp87rsytf0/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:24:55,741 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.5.8 01:24:55,742 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - No custom configurators were discovered as a service. 01:24:55,742 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator 01:24:55,743 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator 01:24:55,749 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo] 01:24:55,749 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo] 01:24:55,756 |-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:24:55,756 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator 01:24:55,757 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator 01:24:55,757 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 01:24:55,760 |-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:24:55,764 |-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:24:55,809 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - element is deprecated. Near [level] on line 12 01:24:55,809 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within or elements instead. 01:24:55,849 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE] 01:24:55,849 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 01:24:55,855 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 01:24:55,877 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - ROOT level set to WARN 01:24:55,877 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT] 01:24:55,877 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@25a65b77 - End of configuration. 01:24:55,878 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2ed0fbae - Registering current configuration as safe fallback point 01:24:55,878 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 121 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY Parsing log file(s)... Parsing log file(s) done in 80s. Generating reports... ================================================================================ ---- Global Information -------------------------------------------------------- > request count 1785414 (OK=1785406 KO=8 ) > min response time 39 (OK=39 KO=203 ) > max response time 60000 (OK=6422 KO=60000 ) > mean response time 46 (OK=46 KO=21317 ) > std deviation 67 (OK=11 KO=22560 ) > response time 50th percentile 46 (OK=46 KO=10013 ) > response time 75th percentile 47 (OK=47 KO=22730 ) > response time 95th percentile 50 (OK=50 KO=60000 ) > response time 99th percentile 53 (OK=53 KO=60000 ) > mean requests/sec 991.9 (OK=991.89 KO=0 ) ---- Response Time Distribution ------------------------------------------------ > t < 800 ms 1785352 ( 100%) > 800 ms <= t < 1200 ms 40 ( 0%) > t >= 1200 ms 14 ( 0%) > failed 8 ( 0%) ---- Errors -------------------------------------------------------------------- > i.n.h.s.SslHandshakeTimeoutException: handshake timed out afte 4 (50.00%) r 10000ms > Request timeout to openam-perf-200m.forgeblocks.com/34.107.203 2 (25.00%) .37:443 after 60000 ms > status.find.in(200,304), but actually found 503 1 (12.50%) > j.i.IOException: Premature close 1 (12.50%) ================================================================================ Reports generated, please open the following file: file:///results/gatling/mixedquery-1000/loadtest-20250327222058851/index.html [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 01:23 min [INFO] Finished at: 2025-03-28T01:26:17Z [INFO] ------------------------------------------------------------------------ 2025-03-28 01:26:17,924 INFO Gatling simulation run ended successfully 2025-03-28 01:26:17,924 INFO Creating archive mixedquery-1000.tar.gz with report files 2025-03-28 01:26:18,019 INFO Archive /results/gatling/mixedquery-1000/mixedquery-1000.tar.gz successfully created ________________________________________________________________________________ [2025-03-28 01:26:30] Reporting-mixedquery-1000 step10 : Check stdout log and parse its content ________________________________________________________________________________ PASS: no error found in stdout log ________________________________________________________________________________ [2025-03-28 01:26:30] Reporting-mixedquery-1000 step11 : Print stderr order ________________________________________________________________________________ 2025-03-28 01:26:30,483 INFO 2025-03-28 01:26:30,483 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:30,483 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 01:26:30,761 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 01:26:30,761 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:30,761 DEBUG --- stdout --- 2025-03-28 01:26:30,761 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 01:26:30,761 DEBUG --- stderr --- 2025-03-28 01:26:30,761 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 01:26:30,762 INFO 2025-03-28 01:26:30,762 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-1000/stderr.txt" ]; then echo "/results/orders/Reporting-mixedquery-1000/stderr.txt file found"; exit 0; else echo "/results/orders/Reporting-mixedquery-1000/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-mixedquery-1000/stderr.txt file found" 2025-03-28 01:26:30,762 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 01:26:31,562 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 01:26:31,563 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:31,563 DEBUG --- stdout --- 2025-03-28 01:26:31,563 DEBUG /results/orders/Reporting-mixedquery-1000/stderr.txt file found 2025-03-28 01:26:31,563 DEBUG --- stderr --- 2025-03-28 01:26:31,563 DEBUG 2025-03-28 01:26:31,563 INFO 2025-03-28 01:26:31,563 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-1000/stderr.txt 2025-03-28 01:26:32,364 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 01:26:32,364 DEBUG --- stdout --- 2025-03-28 01:26:32,364 DEBUG 0 /results/orders/Reporting-mixedquery-1000/stderr.txt 2025-03-28 01:26:32,364 DEBUG --- stderr --- 2025-03-28 01:26:32,364 DEBUG 2025-03-28 01:26:32,364 INFO - Download file (size 0k) source : /results/orders/Reporting-mixedquery-1000/stderr.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/stderr.txt 2025-03-28 01:26:32,365 INFO 2025-03-28 01:26:32,365 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-1000/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/stderr.txt 2025-03-28 01:26:32,365 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 01:26:33,085 INFO [loop_until]: OK (rc = 0) 2025-03-28 01:26:33,085 DEBUG --- stdout --- 2025-03-28 01:26:33,085 DEBUG tar: Removing leading `/' from member names 2025-03-28 01:26:33,085 DEBUG --- stderr --- 2025-03-28 01:26:33,085 DEBUG 2025-03-28 01:26:33,085 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/08_Reporting-mixedquery-1000/stderr.txt is small (0 lines), printing all lines: 2025-03-28 01:26:33,085 INFO ----- output ----- ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-1000 step12 : Check stderr log ________________________________________________________________________________ PASS: no error found in stderr log ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-1000 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/01_mixedquery-1000/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/01_mixedquery-1000/gatling/req_readmanageduser--1429285772.html - cannot check for spikes no spikes found ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-1000 step14 : Collect Gatling simulation data ________________________________________________________________________________ collected stats : { "global": { "name": "All Requests", "numberOfRequests": { "total": 1785414, "ok": 1785406, "ko": 8 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 203 }, "maxResponseTime": { "total": 60000, "ok": 6422, "ko": 60000 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 21317 }, "standardDeviation": { "total": 67, "ok": 11, "ko": 22560 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10013 }, "percentiles2": { "total": 47, "ok": 47, "ko": 22730 }, "percentiles3": { "total": 50, "ok": 50, "ko": 60000 }, "percentiles4": { "total": 53, "ok": 53, "ko": 60000 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 1785352, "percentage": 99.99652741605028 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 40, "percentage": 0.002240376741752893 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 14, "percentage": 0.0007841318596135125 }, "group4": { "name": "failed", "htmlName": "failed", "count": 8, "percentage": 0.00044807534835057867 }, "meanNumberOfRequestsPerSecond": { "total": 991.8966666666666, "ok": 991.8922222222222, "ko": 0.0044444444444444444 } }, "details": [ { "name": "restLoginInitiate", "numberOfRequests": { "total": 1, "ok": 1, "ko": 0 }, "minResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "maxResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "meanResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 68, "ok": 68, "ko": 0 }, "percentiles2": { "total": 68, "ok": 68, "ko": 0 }, "percentiles3": { "total": 68, "ok": 68, "ko": 0 }, "percentiles4": { "total": 68, "ok": 68, "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": 68, "ok": 68, "ko": 0 }, "maxResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "meanResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 68, "ok": 68, "ko": 0 }, "percentiles2": { "total": 68, "ok": 68, "ko": 0 }, "percentiles3": { "total": 68, "ok": 68, "ko": 0 }, "percentiles4": { "total": 68, "ok": 68, "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": 59, "ok": 59, "ko": 0 }, "maxResponseTime": { "total": 59, "ok": 59, "ko": 0 }, "meanResponseTime": { "total": 59, "ok": 59, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 59, "ok": 59, "ko": 0 }, "percentiles2": { "total": 59, "ok": 59, "ko": 0 }, "percentiles3": { "total": 59, "ok": 59, "ko": 0 }, "percentiles4": { "total": 59, "ok": 59, "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": 62, "ok": 62, "ko": 0 }, "maxResponseTime": { "total": 62, "ok": 62, "ko": 0 }, "meanResponseTime": { "total": 62, "ok": 62, "ko": 0 }, "standardDeviation": { "total": 0, "ok": 0, "ko": 0 }, "percentiles1": { "total": 62, "ok": 62, "ko": 0 }, "percentiles2": { "total": 62, "ok": 62, "ko": 0 }, "percentiles3": { "total": 62, "ok": 62, "ko": 0 }, "percentiles4": { "total": 62, "ok": 62, "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": 894094, "ok": 894091, "ko": 3 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 10001 }, "maxResponseTime": { "total": 60000, "ok": 3206, "ko": 60000 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 26675 }, "standardDeviation": { "total": 66, "ok": 9, "ko": 23564 }, "percentiles1": { "total": 45, "ok": 45, "ko": 10024 }, "percentiles2": { "total": 47, "ok": 47, "ko": 35012 }, "percentiles3": { "total": 49, "ok": 49, "ko": 55002 }, "percentiles4": { "total": 53, "ok": 53, "ko": 59000 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 894065, "percentage": 99.99675649316515 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 20, "percentage": 0.0022369012654150458 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 6, "percentage": 0.0006710703796245137 }, "group4": { "name": "failed", "htmlName": "failed", "count": 3, "percentage": 0.0003355351898122569 }, "meanNumberOfRequestsPerSecond": { "total": 496.7188888888889, "ok": 496.71722222222223, "ko": 0.0016666666666666668 }, "spikes": [] }, { "name": "ReadManagedUser", "numberOfRequests": { "total": 891315, "ok": 891310, "ko": 5 }, "minResponseTime": { "total": 39, "ok": 39, "ko": 203 }, "maxResponseTime": { "total": 60000, "ok": 6422, "ko": 60000 }, "meanResponseTime": { "total": 46, "ok": 46, "ko": 18102 }, "standardDeviation": { "total": 67, "ok": 13, "ko": 21297 }, "percentiles1": { "total": 46, "ok": 46, "ko": 10001 }, "percentiles2": { "total": 47, "ok": 47, "ko": 10307 }, "percentiles3": { "total": 50, "ok": 50, "ko": 50061 }, "percentiles4": { "total": 53, "ok": 53, "ko": 58012 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 891282, "percentage": 99.99629760522375 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 20, "percentage": 0.002243875621974274 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 8, "percentage": 0.0008975502487897096 }, "group4": { "name": "failed", "htmlName": "failed", "count": 5, "percentage": 0.0005609689054935685 }, "meanNumberOfRequestsPerSecond": { "total": 495.175, "ok": 495.1722222222222, "ko": 0.002777777777777778 }, "spikes": [] } ] } { "concurrency": null, "generic_stats": { "avg_num_of_requests_per_second": 992, "avg_response_time": 46, "max_response_time": 6422, "min_response_time": 39, "num_requests": 1785414, "num_requests_pass": 1785406, "num_requests_percent_pass": 100.0 }, "options": "; testMode:open; testCase:idm.MixedQuery; duration:1800; throughput:1000", "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": 68, "total": 68 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 68, "total": 68 }, "minResponseTime": { "ko": 0, "ok": 68, "total": 68 }, "name": "restLoginInitiate", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 68, "total": 68 }, "percentiles2": { "ko": 0, "ok": 68, "total": 68 }, "percentiles3": { "ko": 0, "ok": 68, "total": 68 }, "percentiles4": { "ko": 0, "ok": 68, "total": 68 }, "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": 68, "total": 68 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 68, "total": 68 }, "minResponseTime": { "ko": 0, "ok": 68, "total": 68 }, "name": "Skip 2FA", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 68, "total": 68 }, "percentiles2": { "ko": 0, "ok": 68, "total": 68 }, "percentiles3": { "ko": 0, "ok": 68, "total": 68 }, "percentiles4": { "ko": 0, "ok": 68, "total": 68 }, "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": 59, "total": 59 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 59, "total": 59 }, "minResponseTime": { "ko": 0, "ok": 59, "total": 59 }, "name": "User Authorize PKCE stage", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 59, "total": 59 }, "percentiles2": { "ko": 0, "ok": 59, "total": 59 }, "percentiles3": { "ko": 0, "ok": 59, "total": 59 }, "percentiles4": { "ko": 0, "ok": 59, "total": 59 }, "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": 62, "total": 62 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 62, "total": 62 }, "minResponseTime": { "ko": 0, "ok": 62, "total": 62 }, "name": "User AccessToken PKCE stage", "numberOfRequests": { "ko": 0, "ok": 1, "total": 1 }, "percentiles1": { "ko": 0, "ok": 62, "total": 62 }, "percentiles2": { "ko": 0, "ok": 62, "total": 62 }, "percentiles3": { "ko": 0, "ok": 62, "total": 62 }, "percentiles4": { "ko": 0, "ok": 62, "total": 62 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 0, "total": 0 } }, { "group1": { "count": 894065, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.99675649316515 }, "group2": { "count": 20, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.0022369012654150458 }, "group3": { "count": 6, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0006710703796245137 }, "group4": { "count": 3, "htmlName": "failed", "name": "failed", "percentage": 0.0003355351898122569 }, "maxResponseTime": { "ko": 60000, "ok": 3206, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.0016666666666666668, "ok": 496.71722222222223, "total": 496.7188888888889 }, "meanResponseTime": { "ko": 26675, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 10001, "ok": 39, "total": 39 }, "name": "queryFull", "numberOfRequests": { "ko": 3, "ok": 894091, "total": 894094 }, "percentiles1": { "ko": 10024, "ok": 45, "total": 45 }, "percentiles2": { "ko": 35012, "ok": 47, "total": 47 }, "percentiles3": { "ko": 55002, "ok": 49, "total": 49 }, "percentiles4": { "ko": 59000, "ok": 53, "total": 53 }, "spikes": [], "standardDeviation": { "ko": 23564, "ok": 9, "total": 66 } }, { "group1": { "count": 891282, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.99629760522375 }, "group2": { "count": 20, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.002243875621974274 }, "group3": { "count": 8, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0008975502487897096 }, "group4": { "count": 5, "htmlName": "failed", "name": "failed", "percentage": 0.0005609689054935685 }, "maxResponseTime": { "ko": 60000, "ok": 6422, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.002777777777777778, "ok": 495.1722222222222, "total": 495.175 }, "meanResponseTime": { "ko": 18102, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 203, "ok": 39, "total": 39 }, "name": "ReadManagedUser", "numberOfRequests": { "ko": 5, "ok": 891310, "total": 891315 }, "percentiles1": { "ko": 10001, "ok": 46, "total": 46 }, "percentiles2": { "ko": 10307, "ok": 47, "total": 47 }, "percentiles3": { "ko": 50061, "ok": 50, "total": 50 }, "percentiles4": { "ko": 58012, "ok": 53, "total": 53 }, "spikes": [], "standardDeviation": { "ko": 21297, "ok": 13, "total": 67 } } ], "global": { "group1": { "count": 1785352, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.99652741605028 }, "group2": { "count": 40, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.002240376741752893 }, "group3": { "count": 14, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.0007841318596135125 }, "group4": { "count": 8, "htmlName": "failed", "name": "failed", "percentage": 0.00044807534835057867 }, "maxResponseTime": { "ko": 60000, "ok": 6422, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.0044444444444444444, "ok": 991.8922222222222, "total": 991.8966666666666 }, "meanResponseTime": { "ko": 21317, "ok": 46, "total": 46 }, "minResponseTime": { "ko": 203, "ok": 39, "total": 39 }, "name": "All Requests", "numberOfRequests": { "ko": 8, "ok": 1785406, "total": 1785414 }, "percentiles1": { "ko": 10013, "ok": 46, "total": 46 }, "percentiles2": { "ko": 22730, "ok": 47, "total": 47 }, "percentiles3": { "ko": 60000, "ok": 50, "total": 50 }, "percentiles4": { "ko": 60000, "ok": 53, "total": 53 }, "standardDeviation": { "ko": 22560, "ok": 11, "total": 67 } } }, "target_hostname": "openam-perf-200m.forgeblocks.com", "tool_name": "gatling" } ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-1000 step15 : Update run description in the Gatling HTML report ________________________________________________________________________________ ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-1000 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/08_Reporting-mixedquery-1000/stdout.txt Gatling stdout.txt found, but is small - leave it intact. ________________________________________________________________________________ [2025-03-28 01:26:33] Reporting-mixedquery-1000 post : Check output ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped