--Task-- name: Reporting-update-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-update-500', 'Logs-parse-update-1000', 'Logs-parse-update-1500', 'Logs-parse-update-1600', 'Logs-parse-update-1700', 'Logs-parse-patch-500', 'Logs-parse-patch-1000', 'Logs-parse-patch-1500', 'Logs-parse-patch-1700', 'Logs-parse-patch-1800', 'Reporting-update-500'] preceding_task: None options: {'task_name': 'update-1000'} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock source (overseer-0) is a component 2025-03-28 15:52:51 - INFO: Timeout for this Task has changed to 5h 30m (19800 seconds) 2025-03-28 15:52:51 - 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-update-1000/stdout.txt Pod stderr file : /results/orders/Reporting-update-1000/stderr.txt Pod log : /results/orders/Reporting-update-1000 ________________________________________________________________________________ [2025-03-28 15:52:51] Reporting-update-1000 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/13_Reporting-update-1000/order.json { "name": "Reporting-update-1000", "command": " /lodestar/lodestar.py perf run-gatling --reports-only=\"/results/gatling/update-1000\" --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx8G\" --archive-name=\"update-1000.tar.gz\"", "out-dir": "/results/orders/Reporting-update-1000" } ________________________________________________________________________________ [2025-03-28 15:52:51] Reporting-update-1000 step2 : Make sure overseer is ready to accept order (not already busy) ________________________________________________________________________________ 2025-03-28 15:52:51,377 INFO 2025-03-28 15:52:51,377 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 15:52:51,377 INFO [loop_until]: (max_time=120, interval=5, expected_rc=[0] 2025-03-28 15:52:51,592 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 15:52:51,592 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:52:51,592 DEBUG --- stdout --- 2025-03-28 15:52:51,593 DEBUG WAITING 2025-03-28 15:52:51,593 DEBUG --- stderr --- 2025-03-28 15:52:51,593 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 15:52:51] Reporting-update-1000 step3 : Send order to overseer ________________________________________________________________________________ 2025-03-28 15:52:51,593 INFO 2025-03-28 15:52:51,593 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 15:52:51,593 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 15:52:51,870 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 15:52:51,870 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:52:51,870 DEBUG --- stdout --- 2025-03-28 15:52:51,870 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 15:52:51,870 DEBUG --- stderr --- 2025-03-28 15:52:51,870 DEBUG 2025-03-28 15:52:51,871 INFO 2025-03-28 15:52:51,871 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/13_Reporting-update-1000/order.json overseer-0-59c948f569-rgrkv:/results/orders/order.json 2025-03-28 15:52:51,871 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 15:52:53,244 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:52:53,244 DEBUG --- stdout --- 2025-03-28 15:52:53,244 DEBUG 2025-03-28 15:52:53,244 DEBUG --- stderr --- 2025-03-28 15:52:53,244 DEBUG Order has been successfully forwarded to overseer ________________________________________________________________________________ [2025-03-28 15:52:53] Reporting-update-1000 step4 : Wait order is done ________________________________________________________________________________ Workaround for PERF-1966. Sleeping for 5 seconds. 2025-03-28 15:52:58,245 INFO 2025-03-28 15:52:58,245 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-28 15:52:58,245 INFO [loop_until]: (max_time=19800, interval=5, expected_rc=[0] 2025-03-28 15:52:58,460 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:03,676 INFO [loop_until]: Function succeeded after 5s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:08,986 INFO [loop_until]: Function succeeded after 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:14,202 INFO [loop_until]: Function succeeded after 15s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:19,417 INFO [loop_until]: Function succeeded after 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:24,632 INFO [loop_until]: Function succeeded after 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:29,847 INFO [loop_until]: Function succeeded after 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:35,062 INFO [loop_until]: Function succeeded after 36s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:40,330 INFO [loop_until]: Function succeeded after 42s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:45,545 INFO [loop_until]: Function succeeded after 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:50,760 INFO [loop_until]: Function succeeded after 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:53:55,975 INFO [loop_until]: Function succeeded after 57s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:01,190 INFO [loop_until]: Function succeeded after 1m 02s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:06,405 INFO [loop_until]: Function succeeded after 1m 08s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:11,673 INFO [loop_until]: Function succeeded after 1m 13s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:16,888 INFO [loop_until]: Function succeeded after 1m 18s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:22,103 INFO [loop_until]: Function succeeded after 1m 23s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:27,318 INFO [loop_until]: Function succeeded after 1m 29s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:32,533 INFO [loop_until]: Function succeeded after 1m 34s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:37,748 INFO [loop_until]: Function succeeded after 1m 39s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:43,014 INFO [loop_until]: Function succeeded after 1m 44s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:48,230 INFO [loop_until]: Function succeeded after 1m 49s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:53,444 INFO [loop_until]: Function succeeded after 1m 55s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:54:58,661 INFO [loop_until]: Function succeeded after 2m (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:03,876 INFO [loop_until]: Function succeeded after 2m 05s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:09,090 INFO [loop_until]: Function succeeded after 2m 10s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:14,308 INFO [loop_until]: Function succeeded after 2m 16s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:19,576 INFO [loop_until]: Function succeeded after 2m 21s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:24,791 INFO [loop_until]: Function succeeded after 2m 26s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:30,005 INFO [loop_until]: Function succeeded after 2m 31s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:35,220 INFO [loop_until]: Function succeeded after 2m 36s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:40,435 INFO [loop_until]: Function succeeded after 2m 42s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:45,650 INFO [loop_until]: Function succeeded after 2m 47s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:50,960 INFO [loop_until]: Function succeeded after 2m 52s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:55:56,175 INFO [loop_until]: Function succeeded after 2m 57s (rc=0) - failed to find expected output: WAITING - retry 2025-03-28 15:56:01,390 INFO [loop_until]: Function succeeded after 3m 03s (rc=0) - expected pattern found 2025-03-28 15:56:01,390 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:01,391 DEBUG --- stdout --- 2025-03-28 15:56:01,391 DEBUG WAITING 2025-03-28 15:56:01,391 DEBUG --- stderr --- 2025-03-28 15:56:01,391 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 15:56:01] Reporting-update-1000 step5 : Wait until gatling report is generated on overseer ________________________________________________________________________________ 2025-03-28 15:56:01,392 INFO 2025-03-28 15:56:01,392 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 15:56:01,392 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 15:56:01,692 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 15:56:01,692 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:01,692 DEBUG --- stdout --- 2025-03-28 15:56:01,692 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 15:56:01,692 DEBUG --- stderr --- 2025-03-28 15:56:01,692 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 15:56:01,693 INFO 2025-03-28 15:56:01,693 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/update-1000/update-1000.tar.gz" ]; then echo "/results/gatling/update-1000/update-1000.tar.gz file found"; exit 0; else echo "/results/gatling/update-1000/update-1000.tar.gz file not found"; exit 1; fi' | grep "/results/gatling/update-1000/update-1000.tar.gz file found" 2025-03-28 15:56:01,693 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 15:56:02,535 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 15:56:02,535 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:02,535 DEBUG --- stdout --- 2025-03-28 15:56:02,535 DEBUG /results/gatling/update-1000/update-1000.tar.gz file found 2025-03-28 15:56:02,536 DEBUG --- stderr --- 2025-03-28 15:56:02,536 DEBUG 2025-03-28 15:56:02,536 INFO 2025-03-28 15:56:02,536 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/gatling/update-1000/update-1000.tar.gz 2025-03-28 15:56:03,335 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 15:56:03,335 DEBUG --- stdout --- 2025-03-28 15:56:03,335 DEBUG 300 /results/gatling/update-1000/update-1000.tar.gz 2025-03-28 15:56:03,335 DEBUG --- stderr --- 2025-03-28 15:56:03,335 DEBUG 2025-03-28 15:56:03,335 INFO - Download file (size 300k) source : /results/gatling/update-1000/update-1000.tar.gz @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/update-1000.tar.gz 2025-03-28 15:56:03,336 INFO 2025-03-28 15:56:03,336 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/gatling/update-1000/update-1000.tar.gz /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/update-1000.tar.gz 2025-03-28 15:56:03,336 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 15:56:04,336 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:04,336 DEBUG --- stdout --- 2025-03-28 15:56:04,336 DEBUG tar: Removing leading `/' from member names 2025-03-28 15:56:04,336 DEBUG --- stderr --- 2025-03-28 15:56:04,336 DEBUG ________________________________________________________________________________ [2025-03-28 15:56:04] Reporting-update-1000 step6 : Unzip the result ________________________________________________________________________________ 2025-03-28 15:56:04,336 INFO 2025-03-28 15:56:04,336 INFO [run_command]: tar zxf /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/shared/update-1000.tar.gz -C /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/02_update-1000/gatling 2025-03-28 15:56:04,351 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 15:56:04,351 DEBUG --- stdout --- 2025-03-28 15:56:04,351 DEBUG 2025-03-28 15:56:04,351 DEBUG --- stderr --- 2025-03-28 15:56:04,351 DEBUG 2025-03-28 15:56:04,351 INFO ________________________________________________________________________________ [2025-03-28 15:56:04] Reporting-update-1000 step7 : Print rc order ________________________________________________________________________________ 2025-03-28 15:56:04,352 INFO 2025-03-28 15:56:04,352 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 15:56:04,352 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 15:56:04,632 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 15:56:04,632 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:04,632 DEBUG --- stdout --- 2025-03-28 15:56:04,632 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 15:56:04,633 DEBUG --- stderr --- 2025-03-28 15:56:04,633 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 15:56:04,633 INFO 2025-03-28 15:56:04,634 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-update-1000/rc.txt" ]; then echo "/results/orders/Reporting-update-1000/rc.txt file found"; exit 0; else echo "/results/orders/Reporting-update-1000/rc.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-update-1000/rc.txt file found" 2025-03-28 15:56:04,634 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 15:56:05,432 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 15:56:05,432 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:05,433 DEBUG --- stdout --- 2025-03-28 15:56:05,433 DEBUG /results/orders/Reporting-update-1000/rc.txt file found 2025-03-28 15:56:05,433 DEBUG --- stderr --- 2025-03-28 15:56:05,433 DEBUG 2025-03-28 15:56:05,433 INFO 2025-03-28 15:56:05,433 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-update-1000/rc.txt 2025-03-28 15:56:06,236 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 15:56:06,237 DEBUG --- stdout --- 2025-03-28 15:56:06,237 DEBUG 4 /results/orders/Reporting-update-1000/rc.txt 2025-03-28 15:56:06,237 DEBUG --- stderr --- 2025-03-28 15:56:06,237 DEBUG 2025-03-28 15:56:06,237 INFO - Download file (size 4k) source : /results/orders/Reporting-update-1000/rc.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/rc.txt 2025-03-28 15:56:06,237 INFO 2025-03-28 15:56:06,237 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/Reporting-update-1000/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/rc.txt 2025-03-28 15:56:06,237 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 15:56:06,961 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:06,961 DEBUG --- stdout --- 2025-03-28 15:56:06,961 DEBUG tar: Removing leading `/' from member names 2025-03-28 15:56:06,961 DEBUG --- stderr --- 2025-03-28 15:56:06,962 DEBUG 2025-03-28 15:56:06,962 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/rc.txt is small (1 lines), printing all lines: 2025-03-28 15:56:06,962 INFO ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [2025-03-28 15:56:06] Reporting-update-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 15:56:07] Reporting-update-1000 step9 : Print stdout order ________________________________________________________________________________ 2025-03-28 15:56:07,202 INFO 2025-03-28 15:56:07,202 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 15:56:07,202 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 15:56:07,514 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 15:56:07,514 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:07,514 DEBUG --- stdout --- 2025-03-28 15:56:07,515 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 15:56:07,515 DEBUG --- stderr --- 2025-03-28 15:56:07,515 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 15:56:07,516 INFO 2025-03-28 15:56:07,516 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-update-1000/stdout.txt" ]; then echo "/results/orders/Reporting-update-1000/stdout.txt file found"; exit 0; else echo "/results/orders/Reporting-update-1000/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-update-1000/stdout.txt file found" 2025-03-28 15:56:07,516 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 15:56:08,324 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 15:56:08,324 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:08,324 DEBUG --- stdout --- 2025-03-28 15:56:08,324 DEBUG /results/orders/Reporting-update-1000/stdout.txt file found 2025-03-28 15:56:08,325 DEBUG --- stderr --- 2025-03-28 15:56:08,325 DEBUG 2025-03-28 15:56:08,325 INFO 2025-03-28 15:56:08,325 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-update-1000/stdout.txt 2025-03-28 15:56:09,135 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 15:56:09,135 DEBUG --- stdout --- 2025-03-28 15:56:09,135 DEBUG 8 /results/orders/Reporting-update-1000/stdout.txt 2025-03-28 15:56:09,135 DEBUG --- stderr --- 2025-03-28 15:56:09,135 DEBUG 2025-03-28 15:56:09,135 INFO - Download file (size 8k) source : /results/orders/Reporting-update-1000/stdout.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/stdout.txt 2025-03-28 15:56:09,136 INFO 2025-03-28 15:56:09,136 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/Reporting-update-1000/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/stdout.txt 2025-03-28 15:56:09,136 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 15:56:09,898 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:09,898 DEBUG --- stdout --- 2025-03-28 15:56:09,898 DEBUG tar: Removing leading `/' from member names 2025-03-28 15:56:09,898 DEBUG --- stderr --- 2025-03-28 15:56:09,898 DEBUG 2025-03-28 15:56:09,899 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/stdout.txt is small (96 lines), printing all lines: 2025-03-28 15:56:09,899 INFO ----- output ----- 2025-03-28 15:52:54,277 INFO pom.xml copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpnbd1ordi 2025-03-28 15:52:54,279 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.reportsOnly="/results/gatling/update-1000/loadtest-20250328064343794" -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/tmpnbd1ordi/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/tmpnbd1ordi/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 --- 15:52:56,109 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.5.8 15:52:56,111 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - No custom configurators were discovered as a service. 15:52:56,111 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator 15:52:56,112 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator 15:52:56,117 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo] 15:52:56,117 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo] 15:52:56,124 |-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 15:52:56,125 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator 15:52:56,125 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator 15:52:56,125 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 15:52:56,128 |-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] 15:52:56,133 |-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 15:52:56,176 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - element is deprecated. Near [level] on line 12 15:52:56,176 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within or elements instead. 15:52:56,215 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE] 15:52:56,215 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 15:52:56,221 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 15:52:56,242 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - ROOT level set to WARN 15:52:56,242 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT] 15:52:56,242 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@25a65b77 - End of configuration. 15:52:56,243 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2ed0fbae - Registering current configuration as safe fallback point 15:52:56,243 |-INFO in ch.qos.logback.classic.util.ContextInitializer@12d3a4e9 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 118 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY Parsing log file(s)... Parsing log file(s) done in 183s. Generating reports... ================================================================================ ---- Global Information -------------------------------------------------------- > request count 3584673 (OK=3584644 KO=29 ) > min response time 38 (OK=59 KO=38 ) > max response time 60000 (OK=52477 KO=60000 ) > mean response time 93 (OK=93 KO=11058 ) > std deviation 149 (OK=137 KO=17279 ) > response time 50th percentile 83 (OK=83 KO=10000 ) > response time 75th percentile 95 (OK=95 KO=10001 ) > response time 95th percentile 111 (OK=111 KO=60000 ) > response time 99th percentile 171 (OK=171 KO=60000 ) > mean requests/sec 995.74 (OK=995.73 KO=0.01 ) ---- Response Time Distribution ------------------------------------------------ > t < 800 ms 3578586 ( 99.83%) > 800 ms <= t < 1200 ms 574 ( 0.02%) > t >= 1200 ms 5484 ( 0.15%) > failed 29 ( 0%) ---- Errors -------------------------------------------------------------------- > status.find.in(200), but actually found 502 12 (41.38%) > i.n.h.s.SslHandshakeTimeoutException: handshake timed out afte 9 (31.03%) r 10000ms > j.i.IOException: Premature close 4 (13.79%) > Request timeout to openam-perf-200m.forgeblocks.com/34.107.203 3 (10.34%) .37:443 after 60000 ms > i.n.c.ConnectTimeoutException: connection timed out after 1000 1 ( 3.45%) 0 ms: openam-perf-200m.forgeblocks.com/34.107.203.37:443 ================================================================================ Reports generated, please open the following file: file:///results/gatling/update-1000/loadtest-20250328064343794/index.html [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 03:05 min [INFO] Finished at: 2025-03-28T15:56:00Z [INFO] ------------------------------------------------------------------------ 2025-03-28 15:56:00,823 INFO Gatling simulation run ended successfully 2025-03-28 15:56:00,823 INFO Creating archive update-1000.tar.gz with report files 2025-03-28 15:56:00,923 INFO Archive /results/gatling/update-1000/update-1000.tar.gz successfully created ________________________________________________________________________________ [2025-03-28 15:56:09] Reporting-update-1000 step10 : Check stdout log and parse its content ________________________________________________________________________________ PASS: no error found in stdout log ________________________________________________________________________________ [2025-03-28 15:56:09] Reporting-update-1000 step11 : Print stderr order ________________________________________________________________________________ 2025-03-28 15:56:09,899 INFO 2025-03-28 15:56:09,900 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 15:56:09,900 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-28 15:56:10,178 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-28 15:56:10,178 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:10,178 DEBUG --- stdout --- 2025-03-28 15:56:10,178 DEBUG overseer-0-59c948f569-rgrkv 2025-03-28 15:56:10,178 DEBUG --- stderr --- 2025-03-28 15:56:10,178 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-28 15:56:10,179 INFO 2025-03-28 15:56:10,179 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-update-1000/stderr.txt" ]; then echo "/results/orders/Reporting-update-1000/stderr.txt file found"; exit 0; else echo "/results/orders/Reporting-update-1000/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/Reporting-update-1000/stderr.txt file found" 2025-03-28 15:56:10,179 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-28 15:56:11,045 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-28 15:56:11,045 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:11,045 DEBUG --- stdout --- 2025-03-28 15:56:11,045 DEBUG /results/orders/Reporting-update-1000/stderr.txt file found 2025-03-28 15:56:11,045 DEBUG --- stderr --- 2025-03-28 15:56:11,045 DEBUG 2025-03-28 15:56:11,045 INFO 2025-03-28 15:56:11,045 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-update-1000/stderr.txt 2025-03-28 15:56:11,870 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-28 15:56:11,870 DEBUG --- stdout --- 2025-03-28 15:56:11,870 DEBUG 0 /results/orders/Reporting-update-1000/stderr.txt 2025-03-28 15:56:11,870 DEBUG --- stderr --- 2025-03-28 15:56:11,870 DEBUG 2025-03-28 15:56:11,870 INFO - Download file (size 0k) source : /results/orders/Reporting-update-1000/stderr.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/stderr.txt 2025-03-28 15:56:11,871 INFO 2025-03-28 15:56:11,871 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/Reporting-update-1000/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/stderr.txt 2025-03-28 15:56:11,871 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-28 15:56:12,602 INFO [loop_until]: OK (rc = 0) 2025-03-28 15:56:12,605 DEBUG --- stdout --- 2025-03-28 15:56:12,605 DEBUG tar: Removing leading `/' from member names 2025-03-28 15:56:12,605 DEBUG --- stderr --- 2025-03-28 15:56:12,605 DEBUG 2025-03-28 15:56:12,605 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/08_Verification/13_Reporting-update-1000/stderr.txt is small (0 lines), printing all lines: 2025-03-28 15:56:12,605 INFO ----- output ----- ________________________________________________________________________________ [2025-03-28 15:56:12] Reporting-update-1000 step12 : Check stderr log ________________________________________________________________________________ PASS: no error found in stderr log ________________________________________________________________________________ [2025-03-28 15:56:12] Reporting-update-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 UpdateManagedUser [warn] responseTimePercentiles was not found in /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_simple_managed_users/07_Scenario_scenario/02_update-1000/gatling/req_updatemanagedus--1469575327.html - cannot check for spikes no spikes found ________________________________________________________________________________ [2025-03-28 15:56:12] Reporting-update-1000 step14 : Collect Gatling simulation data ________________________________________________________________________________ collected stats : { "global": { "name": "All Requests", "numberOfRequests": { "total": 3584673, "ok": 3584644, "ko": 29 }, "minResponseTime": { "total": 38, "ok": 59, "ko": 38 }, "maxResponseTime": { "total": 60000, "ok": 52477, "ko": 60000 }, "meanResponseTime": { "total": 93, "ok": 93, "ko": 11058 }, "standardDeviation": { "total": 149, "ok": 137, "ko": 17279 }, "percentiles1": { "total": 83, "ok": 83, "ko": 10000 }, "percentiles2": { "total": 95, "ok": 95, "ko": 10001 }, "percentiles3": { "total": 111, "ok": 111, "ko": 60000 }, "percentiles4": { "total": 171, "ok": 171, "ko": 60000 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 3578586, "percentage": 99.8301937164143 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 574, "percentage": 0.016012618166287414 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 5484, "percentage": 0.15298466554689924 }, "group4": { "name": "failed", "htmlName": "failed", "count": 29, "percentage": 0.0008089998725127787 }, "meanNumberOfRequestsPerSecond": { "total": 995.7425, "ok": 995.7344444444444, "ko": 0.008055555555555555 } }, "details": [ { "name": "restLoginInitiate", "numberOfRequests": { "total": 2, "ok": 2, "ko": 0 }, "minResponseTime": { "total": 61, "ok": 61, "ko": 0 }, "maxResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "meanResponseTime": { "total": 65, "ok": 65, "ko": 0 }, "standardDeviation": { "total": 4, "ok": 4, "ko": 0 }, "percentiles1": { "total": 65, "ok": 65, "ko": 0 }, "percentiles2": { "total": 66, "ok": 66, "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": 2, "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": 2, "ok": 2, "ko": 0 }, "minResponseTime": { "total": 85, "ok": 85, "ko": 0 }, "maxResponseTime": { "total": 117, "ok": 117, "ko": 0 }, "meanResponseTime": { "total": 101, "ok": 101, "ko": 0 }, "standardDeviation": { "total": 16, "ok": 16, "ko": 0 }, "percentiles1": { "total": 101, "ok": 101, "ko": 0 }, "percentiles2": { "total": 109, "ok": 109, "ko": 0 }, "percentiles3": { "total": 115, "ok": 115, "ko": 0 }, "percentiles4": { "total": 117, "ok": 117, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 2, "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": 2, "ok": 2, "ko": 0 }, "minResponseTime": { "total": 70, "ok": 70, "ko": 0 }, "maxResponseTime": { "total": 87, "ok": 87, "ko": 0 }, "meanResponseTime": { "total": 79, "ok": 79, "ko": 0 }, "standardDeviation": { "total": 9, "ok": 9, "ko": 0 }, "percentiles1": { "total": 79, "ok": 79, "ko": 0 }, "percentiles2": { "total": 83, "ok": 83, "ko": 0 }, "percentiles3": { "total": 86, "ok": 86, "ko": 0 }, "percentiles4": { "total": 87, "ok": 87, "ko": 0 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 2, "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": 2, "ok": 2, "ko": 0 }, "minResponseTime": { "total": 61, "ok": 61, "ko": 0 }, "maxResponseTime": { "total": 68, "ok": 68, "ko": 0 }, "meanResponseTime": { "total": 65, "ok": 65, "ko": 0 }, "standardDeviation": { "total": 4, "ok": 4, "ko": 0 }, "percentiles1": { "total": 65, "ok": 65, "ko": 0 }, "percentiles2": { "total": 66, "ok": 66, "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": 2, "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": 2, "ok": 2, "ko": 0 }, "minResponseTime": { "total": 59, "ok": 59, "ko": 0 }, "maxResponseTime": { "total": 66, "ok": 66, "ko": 0 }, "meanResponseTime": { "total": 63, "ok": 63, "ko": 0 }, "standardDeviation": { "total": 4, "ok": 4, "ko": 0 }, "percentiles1": { "total": 63, "ok": 63, "ko": 0 }, "percentiles2": { "total": 64, "ok": 64, "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": 2, "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": "UpdateManagedUser", "numberOfRequests": { "total": 3584663, "ok": 3584634, "ko": 29 }, "minResponseTime": { "total": 38, "ok": 66, "ko": 38 }, "maxResponseTime": { "total": 60000, "ok": 52477, "ko": 60000 }, "meanResponseTime": { "total": 93, "ok": 93, "ko": 11058 }, "standardDeviation": { "total": 149, "ok": 137, "ko": 17279 }, "percentiles1": { "total": 83, "ok": 83, "ko": 10000 }, "percentiles2": { "total": 95, "ok": 95, "ko": 10001 }, "percentiles3": { "total": 111, "ok": 111, "ko": 60000 }, "percentiles4": { "total": 171, "ok": 171, "ko": 60000 }, "group1": { "name": "t < 800 ms", "htmlName": "t < 800 ms", "count": 3578576, "percentage": 99.83019324271207 }, "group2": { "name": "800 ms <= t < 1200 ms", "htmlName": "t >= 800 ms
t < 1200 ms", "count": 574, "percentage": 0.016012662836088078 }, "group3": { "name": "t >= 1200 ms", "htmlName": "t >= 1200 ms", "count": 5484, "percentage": 0.1529850923224861 }, "group4": { "name": "failed", "htmlName": "failed", "count": 29, "percentage": 0.0008090021293493977 }, "meanNumberOfRequestsPerSecond": { "total": 995.7397222222222, "ok": 995.7316666666667, "ko": 0.008055555555555555 }, "spikes": [] } ] } { "concurrency": null, "generic_stats": { "avg_num_of_requests_per_second": 996, "avg_response_time": 93, "max_response_time": 52477, "min_response_time": 59, "num_requests": 3584673, "num_requests_pass": 3584644, "num_requests_percent_pass": 99.999 }, "options": "; testMode:open; testCase:idm.ManagedUsersUpdate; duration:3600; throughput:1000", "stats": { "details": [ { "group1": { "count": 2, "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": 65, "total": 65 }, "minResponseTime": { "ko": 0, "ok": 61, "total": 61 }, "name": "restLoginInitiate", "numberOfRequests": { "ko": 0, "ok": 2, "total": 2 }, "percentiles1": { "ko": 0, "ok": 65, "total": 65 }, "percentiles2": { "ko": 0, "ok": 66, "total": 66 }, "percentiles3": { "ko": 0, "ok": 68, "total": 68 }, "percentiles4": { "ko": 0, "ok": 68, "total": 68 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 4, "total": 4 } }, { "group1": { "count": 2, "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": 117, "total": 117 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 101, "total": 101 }, "minResponseTime": { "ko": 0, "ok": 85, "total": 85 }, "name": "restLoginUsernamePasswordCallback", "numberOfRequests": { "ko": 0, "ok": 2, "total": 2 }, "percentiles1": { "ko": 0, "ok": 101, "total": 101 }, "percentiles2": { "ko": 0, "ok": 109, "total": 109 }, "percentiles3": { "ko": 0, "ok": 115, "total": 115 }, "percentiles4": { "ko": 0, "ok": 117, "total": 117 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 16, "total": 16 } }, { "group1": { "count": 2, "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": 87, "total": 87 }, "meanNumberOfRequestsPerSecond": { "ko": 0, "ok": 0.0005555555555555556, "total": 0.0005555555555555556 }, "meanResponseTime": { "ko": 0, "ok": 79, "total": 79 }, "minResponseTime": { "ko": 0, "ok": 70, "total": 70 }, "name": "Skip 2FA", "numberOfRequests": { "ko": 0, "ok": 2, "total": 2 }, "percentiles1": { "ko": 0, "ok": 79, "total": 79 }, "percentiles2": { "ko": 0, "ok": 83, "total": 83 }, "percentiles3": { "ko": 0, "ok": 86, "total": 86 }, "percentiles4": { "ko": 0, "ok": 87, "total": 87 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 9, "total": 9 } }, { "group1": { "count": 2, "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": 65, "total": 65 }, "minResponseTime": { "ko": 0, "ok": 61, "total": 61 }, "name": "User Authorize PKCE stage", "numberOfRequests": { "ko": 0, "ok": 2, "total": 2 }, "percentiles1": { "ko": 0, "ok": 65, "total": 65 }, "percentiles2": { "ko": 0, "ok": 66, "total": 66 }, "percentiles3": { "ko": 0, "ok": 68, "total": 68 }, "percentiles4": { "ko": 0, "ok": 68, "total": 68 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 4, "total": 4 } }, { "group1": { "count": 2, "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": 63, "total": 63 }, "minResponseTime": { "ko": 0, "ok": 59, "total": 59 }, "name": "User AccessToken PKCE stage", "numberOfRequests": { "ko": 0, "ok": 2, "total": 2 }, "percentiles1": { "ko": 0, "ok": 63, "total": 63 }, "percentiles2": { "ko": 0, "ok": 64, "total": 64 }, "percentiles3": { "ko": 0, "ok": 66, "total": 66 }, "percentiles4": { "ko": 0, "ok": 66, "total": 66 }, "spikes": [], "standardDeviation": { "ko": 0, "ok": 4, "total": 4 } }, { "group1": { "count": 3578576, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.83019324271207 }, "group2": { "count": 574, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.016012662836088078 }, "group3": { "count": 5484, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.1529850923224861 }, "group4": { "count": 29, "htmlName": "failed", "name": "failed", "percentage": 0.0008090021293493977 }, "maxResponseTime": { "ko": 60000, "ok": 52477, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.008055555555555555, "ok": 995.7316666666667, "total": 995.7397222222222 }, "meanResponseTime": { "ko": 11058, "ok": 93, "total": 93 }, "minResponseTime": { "ko": 38, "ok": 66, "total": 38 }, "name": "UpdateManagedUser", "numberOfRequests": { "ko": 29, "ok": 3584634, "total": 3584663 }, "percentiles1": { "ko": 10000, "ok": 83, "total": 83 }, "percentiles2": { "ko": 10001, "ok": 95, "total": 95 }, "percentiles3": { "ko": 60000, "ok": 111, "total": 111 }, "percentiles4": { "ko": 60000, "ok": 171, "total": 171 }, "spikes": [], "standardDeviation": { "ko": 17279, "ok": 137, "total": 149 } } ], "global": { "group1": { "count": 3578586, "htmlName": "t < 800 ms", "name": "t < 800 ms", "percentage": 99.8301937164143 }, "group2": { "count": 574, "htmlName": "t >= 800 ms
t < 1200 ms", "name": "800 ms <= t < 1200 ms", "percentage": 0.016012618166287414 }, "group3": { "count": 5484, "htmlName": "t >= 1200 ms", "name": "t >= 1200 ms", "percentage": 0.15298466554689924 }, "group4": { "count": 29, "htmlName": "failed", "name": "failed", "percentage": 0.0008089998725127787 }, "maxResponseTime": { "ko": 60000, "ok": 52477, "total": 60000 }, "meanNumberOfRequestsPerSecond": { "ko": 0.008055555555555555, "ok": 995.7344444444444, "total": 995.7425 }, "meanResponseTime": { "ko": 11058, "ok": 93, "total": 93 }, "minResponseTime": { "ko": 38, "ok": 59, "total": 38 }, "name": "All Requests", "numberOfRequests": { "ko": 29, "ok": 3584644, "total": 3584673 }, "percentiles1": { "ko": 10000, "ok": 83, "total": 83 }, "percentiles2": { "ko": 10001, "ok": 95, "total": 95 }, "percentiles3": { "ko": 60000, "ok": 111, "total": 111 }, "percentiles4": { "ko": 60000, "ok": 171, "total": 171 }, "standardDeviation": { "ko": 17279, "ok": 137, "total": 149 } } }, "target_hostname": "openam-perf-200m.forgeblocks.com", "tool_name": "gatling" } ________________________________________________________________________________ [2025-03-28 15:56:12] Reporting-update-1000 step15 : Update run description in the Gatling HTML report ________________________________________________________________________________ ________________________________________________________________________________ [2025-03-28 15:56:12] Reporting-update-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/13_Reporting-update-1000/stdout.txt Gatling stdout.txt found, but is small - leave it intact. ________________________________________________________________________________ [2025-03-28 15:56:12] Reporting-update-1000 post : Check output ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped