--Task-- name: benchmark-10 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am 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: [] preceding_task: None options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 10} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock 2025-06-13 21:02:18,753 INFO 2025-06-13 21:02:18,753 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-06-13 21:02:18,753 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 21:02:19,060 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 21:02:19,060 INFO [loop_until]: OK (rc = 0) 2025-06-13 21:02:19,060 DEBUG --- stdout --- 2025-06-13 21:02:19,060 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 21:02:19,060 DEBUG --- stderr --- 2025-06-13 21:02:19,060 DEBUG 2025-06-13 21:02:19,060 INFO Lodestar assumed that full stack is deployed so will set all products host URLs in Gatling system properties 2025-06-13 21:02:19 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2025-06-13 21:02:19 - INFO: timeout was calculated based on simulation duration parameter 2025-06-13 21:02:19 - INFO: Interval for this Task has changed to 2m (120 seconds) 2025-06-13 21:02:19 - INFO: interval was set to Task default because it was unset, based on self.timeout value because task is allowed to stop by itself Pod log file : /results/orders/benchmark-10/stdout.txt Pod log : /results/orders/benchmark-10 2025-06-13 21:02:19 - INFO: Get overseer pod resources requests memory 2025-06-13 21:02:19,956 INFO 2025-06-13 21:02:19,956 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods overseer-0-898c87646-bjhnj --output jsonpath={.spec.containers[].resources.requests.memory} 2025-06-13 21:02:19,956 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 21:02:20,258 INFO [loop_until]: OK (rc = 0) 2025-06-13 21:02:20,258 DEBUG --- stdout --- 2025-06-13 21:02:20,258 DEBUG 4Gi 2025-06-13 21:02:20,258 DEBUG --- stderr --- 2025-06-13 21:02:20,258 DEBUG ________________________________________________________________________________ [2025-06-13 21:02:20] benchmark-10 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ /lodestar/lodestar.py perf run-gatling --mvn-quiet --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@tof-10" --results-folder="/results/gatling/benchmark-10" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-tof-10.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-tof-10.forgeblocks.com -Dlogin_cookie=7573b68ed0f3690 -Dnum_users=10000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=10 -Duser_password=**** ________________________________________________________________________________ [2025-06-13 21:02:20] benchmark-10 create_order : Create order for overseer with the command to run ________________________________________________________________________________ Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/order.json { "name": "benchmark-10", "command": " /lodestar/lodestar.py perf run-gatling --mvn-quiet --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@tof-10\" --results-folder=\"/results/gatling/benchmark-10\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-tof-10.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-tof-10.forgeblocks.com -Dlogin_cookie=7573b68ed0f3690 -Dnum_users=10000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=10 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-10" } ________________________________________________________________________________ [2025-06-13 21:02:20] benchmark-10 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2025-06-13 21:02:20,266 INFO 2025-06-13 21:02:20,266 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-06-13 21:02:20,266 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2025-06-13 21:02:20,530 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 21:02:20,531 INFO [loop_until]: OK (rc = 0) 2025-06-13 21:02:20,531 DEBUG --- stdout --- 2025-06-13 21:02:20,531 DEBUG WAITING 2025-06-13 21:02:20,531 DEBUG --- stderr --- 2025-06-13 21:02:20,531 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 27 0 --:--:-- --:--:-- --:--:-- 27 ________________________________________________________________________________ [2025-06-13 21:02:20] benchmark-10 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2025-06-13 21:02:20,531 INFO 2025-06-13 21:02:20,531 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-06-13 21:02:20,531 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 21:02:20,810 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 21:02:20,810 INFO [loop_until]: OK (rc = 0) 2025-06-13 21:02:20,810 DEBUG --- stdout --- 2025-06-13 21:02:20,810 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 21:02:20,810 DEBUG --- stderr --- 2025-06-13 21:02:20,810 DEBUG 2025-06-13 21:02:20,810 INFO 2025-06-13 21:02:20,810 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/order.json overseer-0-898c87646-bjhnj:/results/orders/order.json 2025-06-13 21:02:20,810 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 21:02:22,228 INFO [loop_until]: OK (rc = 0) 2025-06-13 21:02:22,228 DEBUG --- stdout --- 2025-06-13 21:02:22,228 DEBUG 2025-06-13 21:02:22,228 DEBUG --- stderr --- 2025-06-13 21:02:22,228 DEBUG Order has been successfully forwarded to overseer 2025-06-13 21:02:22 - INFO: Check if Gatling simulation started successfully 2025-06-13 21:02:22,228 INFO 2025-06-13 21:02:22,229 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj -- head --lines 5000 /results/orders/benchmark-10/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2025-06-13 21:02:22,229 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2025-06-13 21:02:22,973 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-06-13 21:02:28,723 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-06-13 21:02:34,512 INFO [loop_until]: Function succeeded after 12s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-06-13 21:02:40,274 INFO [loop_until]: Function succeeded after 18s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-06-13 21:02:46,068 INFO [loop_until]: Function succeeded after 23s (rc=0) - expected pattern found 2025-06-13 21:02:46,068 INFO [loop_until]: OK (rc = 0) 2025-06-13 21:02:46,068 DEBUG --- stdout --- 2025-06-13 21:02:46,068 DEBUG 2025-06-13 22:02:24,250 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp0ml_mksv 2025-06-13 22:02:24,254 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode --quiet -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-10" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-tof-10.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-tof-10.forgeblocks.com -Dlogin_cookie=7573b68ed0f3690 -Dnum_users=10000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=10 -Duser_password=**** Gatling 3.13.5 is available! (you're using 3.12.0) System property think_time_multiplier not set. No think time emulation will be done in the simulation. Simulation com.forgerock.pyrock.Loadtest started... 2025-06-13 21:02:46,068 DEBUG --- stderr --- 2025-06-13 21:02:46,068 DEBUG ________________________________________________________________________________ [2025-06-13 21:02:46] benchmark-10 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 03s, retry Order is running since 22m 03s, retry Order is running since 24m 03s, retry Order is running since 26m 03s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 04s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 05s, retry Order is running since 40m 06s, retry Order is running since 42m 06s, retry Order is running since 44m 06s, retry Order is running since 46m 07s, retry Order is running since 48m 07s, retry Order is running since 50m 07s, retry Order is running since 52m 07s, retry Order is running since 54m 08s, retry Order is running since 56m 08s, retry Order is running since 58m 08s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2025-06-13 22:02:55] benchmark-10 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2025-06-13 22:02:55,395 INFO 2025-06-13 22:02:55,395 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-06-13 22:02:55,395 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 22:02:55,692 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 22:02:55,692 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:55,692 DEBUG --- stdout --- 2025-06-13 22:02:55,692 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 22:02:55,692 DEBUG --- stderr --- 2025-06-13 22:02:55,692 DEBUG 2025-06-13 22:02:55,692 INFO 2025-06-13 22:02:55,692 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj -- rm -f /results/orders/order.json 2025-06-13 22:02:55,692 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 22:02:56,510 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:56,510 DEBUG --- stdout --- 2025-06-13 22:02:56,510 DEBUG 2025-06-13 22:02:56,510 DEBUG --- stderr --- 2025-06-13 22:02:56,510 DEBUG Order ran during 1h ________________________________________________________________________________ [2025-06-13 22:02:56] benchmark-10 download_logs : Download individual order files ________________________________________________________________________________ 2025-06-13 22:02:56 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/order.json 2025-06-13 22:02:56,511 INFO 2025-06-13 22:02:56,511 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-06-13 22:02:56,511 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 22:02:56,787 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 22:02:56,787 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:56,787 DEBUG --- stdout --- 2025-06-13 22:02:56,787 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 22:02:56,787 DEBUG --- stderr --- 2025-06-13 22:02:56,787 DEBUG Checking if file exists on pod 'overseer-0-898c87646-bjhnj', wait max 3 minutes if not. 2025-06-13 22:02:56,788 INFO 2025-06-13 22:02:56,788 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- bash -c 'if [ -f "/results/orders/benchmark-10/rc.txt" ]; then echo "/results/orders/benchmark-10/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-10/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/rc.txt file found" 2025-06-13 22:02:56,788 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 22:02:57,610 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:02:57,610 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:57,611 DEBUG --- stdout --- 2025-06-13 22:02:57,611 DEBUG /results/orders/benchmark-10/rc.txt file found 2025-06-13 22:02:57,611 DEBUG --- stderr --- 2025-06-13 22:02:57,611 DEBUG 2025-06-13 22:02:57,612 INFO 2025-06-13 22:02:57,612 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- du -k /results/orders/benchmark-10/rc.txt | grep "^\d+ .+$" 2025-06-13 22:02:57,612 INFO [loop_until]: (max_time=240, interval=10, expected_rc=[0] 2025-06-13 22:02:58,419 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:02:58,419 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:58,419 DEBUG --- stdout --- 2025-06-13 22:02:58,419 DEBUG 4 /results/orders/benchmark-10/rc.txt 2025-06-13 22:02:58,419 DEBUG --- stderr --- 2025-06-13 22:02:58,419 DEBUG - Download file (size 4kB) source : /results/orders/benchmark-10/rc.txt @ overseer-0-898c87646-bjhnj destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/rc.txt 2025-06-13 22:02:58,420 INFO 2025-06-13 22:02:58,420 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-898c87646-bjhnj:/results/orders/benchmark-10/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/rc.txt 2025-06-13 22:02:58,420 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-06-13 22:02:59,208 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:59,209 DEBUG --- stdout --- 2025-06-13 22:02:59,209 DEBUG tar: Removing leading `/' from member names 2025-06-13 22:02:59,209 DEBUG --- stderr --- 2025-06-13 22:02:59,209 DEBUG 2025-06-13 22:02:59,209 INFO 2025-06-13 22:02:59,209 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-06-13 22:02:59,209 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 22:02:59,490 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 22:02:59,490 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:02:59,490 DEBUG --- stdout --- 2025-06-13 22:02:59,490 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 22:02:59,490 DEBUG --- stderr --- 2025-06-13 22:02:59,490 DEBUG Checking if file exists on pod 'overseer-0-898c87646-bjhnj', wait max 3 minutes if not. 2025-06-13 22:02:59,491 INFO 2025-06-13 22:02:59,491 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- bash -c 'if [ -f "/results/orders/benchmark-10/stderr.txt" ]; then echo "/results/orders/benchmark-10/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-10/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/stderr.txt file found" 2025-06-13 22:02:59,491 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 22:03:00,368 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:03:00,368 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:00,368 DEBUG --- stdout --- 2025-06-13 22:03:00,368 DEBUG /results/orders/benchmark-10/stderr.txt file found 2025-06-13 22:03:00,368 DEBUG --- stderr --- 2025-06-13 22:03:00,368 DEBUG 2025-06-13 22:03:00,369 INFO 2025-06-13 22:03:00,369 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- du -k /results/orders/benchmark-10/stderr.txt | grep "^\d+ .+$" 2025-06-13 22:03:00,369 INFO [loop_until]: (max_time=240, interval=10, expected_rc=[0] 2025-06-13 22:03:01,256 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:03:01,256 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:01,256 DEBUG --- stdout --- 2025-06-13 22:03:01,256 DEBUG 0 /results/orders/benchmark-10/stderr.txt 2025-06-13 22:03:01,256 DEBUG --- stderr --- 2025-06-13 22:03:01,256 DEBUG - Download file (size 0B) source : /results/orders/benchmark-10/stderr.txt @ overseer-0-898c87646-bjhnj destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/stderr.txt 2025-06-13 22:03:01,257 INFO 2025-06-13 22:03:01,257 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-898c87646-bjhnj:/results/orders/benchmark-10/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/stderr.txt 2025-06-13 22:03:01,257 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-06-13 22:03:01,993 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:01,993 DEBUG --- stdout --- 2025-06-13 22:03:01,993 DEBUG tar: Removing leading `/' from member names 2025-06-13 22:03:01,993 DEBUG --- stderr --- 2025-06-13 22:03:01,993 DEBUG 2025-06-13 22:03:01,993 INFO 2025-06-13 22:03:01,993 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-06-13 22:03:01,994 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 22:03:02,271 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 22:03:02,271 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:02,271 DEBUG --- stdout --- 2025-06-13 22:03:02,271 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 22:03:02,271 DEBUG --- stderr --- 2025-06-13 22:03:02,271 DEBUG Checking if file exists on pod 'overseer-0-898c87646-bjhnj', wait max 3 minutes if not. 2025-06-13 22:03:02,272 INFO 2025-06-13 22:03:02,272 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- bash -c 'if [ -f "/results/orders/benchmark-10/stdout.txt" ]; then echo "/results/orders/benchmark-10/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-10/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/stdout.txt file found" 2025-06-13 22:03:02,272 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 22:03:03,085 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:03:03,085 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:03,085 DEBUG --- stdout --- 2025-06-13 22:03:03,085 DEBUG /results/orders/benchmark-10/stdout.txt file found 2025-06-13 22:03:03,085 DEBUG --- stderr --- 2025-06-13 22:03:03,085 DEBUG 2025-06-13 22:03:03,086 INFO 2025-06-13 22:03:03,086 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- du -k /results/orders/benchmark-10/stdout.txt | grep "^\d+ .+$" 2025-06-13 22:03:03,086 INFO [loop_until]: (max_time=240, interval=10, expected_rc=[0] 2025-06-13 22:03:03,890 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:03:03,890 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:03,890 DEBUG --- stdout --- 2025-06-13 22:03:03,890 DEBUG 4292 /results/orders/benchmark-10/stdout.txt 2025-06-13 22:03:03,890 DEBUG --- stderr --- 2025-06-13 22:03:03,890 DEBUG - Download file (size 4.292MB) source : /results/orders/benchmark-10/stdout.txt @ overseer-0-898c87646-bjhnj destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/stdout.txt 2025-06-13 22:03:03,891 INFO 2025-06-13 22:03:03,891 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-898c87646-bjhnj:/results/orders/benchmark-10/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/stdout.txt 2025-06-13 22:03:03,891 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-06-13 22:03:05,139 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:05,139 DEBUG --- stdout --- 2025-06-13 22:03:05,139 DEBUG tar: Removing leading `/' from member names 2025-06-13 22:03:05,139 DEBUG --- stderr --- 2025-06-13 22:03:05,139 DEBUG ________________________________________________________________________________ [2025-06-13 22:03:05] benchmark-10 show_cmd : Display order command ________________________________________________________________________________ 2025-06-13 22:03:05,140 INFO 2025-06-13 22:03:05,140 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-06-13 22:03:05,140 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-06-13 22:03:05,458 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-06-13 22:03:05,458 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:05,458 DEBUG --- stdout --- 2025-06-13 22:03:05,458 DEBUG overseer-0-898c87646-bjhnj 2025-06-13 22:03:05,458 DEBUG --- stderr --- 2025-06-13 22:03:05,458 DEBUG Checking if file exists on pod 'overseer-0-898c87646-bjhnj', wait max 3 minutes if not. 2025-06-13 22:03:05,459 INFO 2025-06-13 22:03:05,459 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- bash -c 'if [ -f "/results/orders/benchmark-10/cmd.txt" ]; then echo "/results/orders/benchmark-10/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-10/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/cmd.txt file found" 2025-06-13 22:03:05,459 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-06-13 22:03:06,272 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:03:06,272 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:06,272 DEBUG --- stdout --- 2025-06-13 22:03:06,272 DEBUG /results/orders/benchmark-10/cmd.txt file found 2025-06-13 22:03:06,272 DEBUG --- stderr --- 2025-06-13 22:03:06,272 DEBUG 2025-06-13 22:03:06,272 INFO 2025-06-13 22:03:06,272 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-898c87646-bjhnj --stdin -- du -k /results/orders/benchmark-10/cmd.txt | grep "^\d+ .+$" 2025-06-13 22:03:06,273 INFO [loop_until]: (max_time=240, interval=10, expected_rc=[0] 2025-06-13 22:03:07,080 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-06-13 22:03:07,080 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:07,080 DEBUG --- stdout --- 2025-06-13 22:03:07,080 DEBUG 4 /results/orders/benchmark-10/cmd.txt 2025-06-13 22:03:07,080 DEBUG --- stderr --- 2025-06-13 22:03:07,080 DEBUG - Download file (size 4kB) source : /results/orders/benchmark-10/cmd.txt @ overseer-0-898c87646-bjhnj destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/cmd.txt 2025-06-13 22:03:07,081 INFO 2025-06-13 22:03:07,081 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-898c87646-bjhnj:/results/orders/benchmark-10/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/cmd.txt 2025-06-13 22:03:07,081 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-06-13 22:03:07,845 INFO [loop_until]: OK (rc = 0) 2025-06-13 22:03:07,845 DEBUG --- stdout --- 2025-06-13 22:03:07,845 DEBUG tar: Removing leading `/' from member names 2025-06-13 22:03:07,845 DEBUG --- stderr --- 2025-06-13 22:03:07,845 DEBUG 2025-06-13 22:03:07,845 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/cmd.txt is small (1 lines), printing all lines: 2025-06-13 22:03:07,845 INFO ----- output ----- /lodestar/lodestar.py perf run-gatling --mvn-quiet --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@tof-10" --results-folder="/results/gatling/benchmark-10" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-tof-10.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-tof-10.forgeblocks.com -Dlogin_cookie=7573b68ed0f3690 -Dnum_users=10000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=10 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2025-06-13 22:03:07] benchmark-10 show_rc : Display rc order ________________________________________________________________________________ 2025-06-13 22:03:07,845 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/rc.txt is small (1 lines), printing all lines: 2025-06-13 22:03:07,845 INFO ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [2025-06-13 22:03:07] benchmark-10 show_stdout : Display stdout order ________________________________________________________________________________ 2025-06-13 22:03:07,852 DEBUG [print_head_tail]: Print head (100 lines) and tail (100 lines) of input file (/mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/stdout.txt is 65206 lines): 2025-06-13 22:03:07,861 INFO ----- output ----- 2025-06-13 22:02:24,250 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp0ml_mksv 2025-06-13 22:02:24,254 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode --quiet -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-10" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-tof-10.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-tof-10.forgeblocks.com -Dlogin_cookie=7573b68ed0f3690 -Dnum_users=10000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=10 -Duser_password=**** Gatling 3.13.5 is available! (you're using 3.12.0) System property think_time_multiplier not set. No think time emulation will be done in the simulation. Simulation com.forgerock.pyrock.Loadtest started... ================================================================================ 2025-06-13 21:02:46 GMT 5s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=12 KO=0 ) > authAsPolicyAdmin (OK=1 KO=0 ) > restLoginInitiate (OK=3 KO=0 ) > restLoginUsernamePasswordCallback (OK=2 KO=0 ) > Skip 2FA (OK=1 KO=0 ) > User Authorize PKCE stage (OK=1 KO=0 ) > User AccessToken PKCE stage (OK=1 KO=0 ) > RootUserinfo (OK=1 KO=0 ) > userRestlogin (OK=1 KO=0 ) > EvalPolicy (OK=1 KO=0 ) ---- getToken ------------------------------------------------------------------ [--------------------------------------------------------------------------] 0% waiting: 0 / active: 1 / done: 0 ---- idc.benchmark.Mix2024 ----------------------------------------------------- [- ] 0% waiting: 36119 / active: 3 / done: 1 ================================================================================ ================================================================================ 2025-06-13 21:02:51 GMT 10s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=152 KO=0 ) > authAsPolicyAdmin (OK=1 KO=0 ) > restLoginInitiate (OK=8 KO=0 ) > restLoginUsernamePasswordCallback (OK=8 KO=0 ) > Skip 2FA (OK=1 KO=0 ) > User Authorize PKCE stage (OK=12 KO=0 ) > User AccessToken PKCE stage (OK=12 KO=0 ) > RootUserinfo (OK=5 KO=0 ) > userRestlogin (OK=8 KO=0 ) > EvalPolicy (OK=8 KO=0 ) > UI-Post-Login - stage 1 (OK=4 KO=0 ) > UI-Post-Login - stage 1 Redirect 1 (OK=4 KO=0 ) > tokenUserinfo (OK=3 KO=0 ) > UI AM idFromSession (OK=4 KO=0 ) > UI AM validateGoto (OK=4 KO=0 ) > UI-Post-Login - stage 2 (OK=4 KO=0 ) > UI-Post-Login - stage 2 Redirect 1 (OK=4 KO=0 ) > UI Enduser appAuthHelper2 (OK=4 KO=0 ) > UI Enduser appAuthHelper1 (OK=4 KO=0 ) > UI-Post-Login - stage 3 (OK=3 KO=0 ) > UI-Post-Login - stage 3 Redirect 1 (OK=3 KO=0 ) > UI Enduser sessioncheck (OK=3 KO=0 ) > UI IDM uiconfig (OK=3 KO=0 ) > UI IDM version (OK=3 KO=0 ) > UI IDM features (OK=3 KO=0 ) > UI IDM login (OK=3 KO=0 ) > UI IDM privilege (OK=3 KO=0 ) > UI IDM dashboard (OK=3 KO=0 ) > UI IDM user (OK=3 KO=0 ) > UI IDM managed user schema (OK=3 KO=0 ) > UI IDM oidcToken (OK=3 KO=0 ) > userinfo (OK=3 KO=0 ) > UI-Logout (OK=3 KO=0 ) > UI-Logout Redirect 1 (OK=3 KO=0 ) > UI AM revoke2 (OK=3 KO=0 ) > UI AM revoke1 (OK=3 KO=0 ) > UI AM endsession (OK=3 KO=0 ) ---- getToken ------------------------------------------------------------------ [--------------------------------------------------------------------------] 0% waiting: 0 / active: 1 / done: 0 ---- idc.benchmark.Mix2024 ----------------------------------------------------- [- ] 0% waiting: 36107 / active: 2 / done: 14 ================================================================================ ================================================================================ 2025-06-13 21:02:56 GMT 15s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=368 KO=0 ) > authAsPolicyAdmin (OK=1 KO=0 ) > restLoginInitiate (OK=25 KO=0 ) > restLoginUsernamePasswordCallback (OK=25 KO=0 ) > Skip 2FA (OK=7 KO=0 ) > User Authorize PKCE stage (OK=31 KO=0 ) > User AccessToken PKCE stage (OK=30 KO=0 ) > RootUserinfo (OK=16 KO=0 ) > userRestlogin (OK=12 KO=0 ) > EvalPolicy (OK=11 KO=0 ) > UI-Post-Login - stage 1 (OK=10 KO=0 ) > UI-Post-Login - stage 1 Redirect 1 (OK=9 KO=0 ) > tokenUserinfo (OK=8 KO=0 ) > UI AM idFromSession (OK=9 KO=0 ) > UI AM validateGoto (OK=9 KO=0 ) > UI-Post-Login - stage 2 (OK=9 KO=0 ) > UI-Post-Login - stage 2 Redirect 1 (OK=9 KO=0 ) > UI Enduser appAuthHelper2 (OK=8 KO=0 ) [...] content-length: 323 body:StringChunksRequestBody{charset=UTF-8, content={ "resources":[ "http://www.example.com:80/index.html", "http://www.example.com:80/do?action=run" ], "application":"TestPolicySet", "subject": { "ssoToken": "A58Xet3xRBImLMavE6554ojIIY8.*AAJTSQACMDIAAlNLABxVRnRmckxWM0ZMbW51cTNNbXVlZ05GclBxa2c9AAR0eXBlAANDVFMAAlMxAAIwMQ..*" } } } ========================= HTTP response: version: HTTP/1.1 status: 401 Unauthorized headers: x-frame-options: SAMEORIGIN content-security-policy-report-only: frame-ancestors 'self'; script-src 'self' 'unsafe-eval' 'unsafe-inline' x-content-type-options: nosniff cache-control: private content-security-policy: default-src 'none';frame-ancestors 'none';sandbox cross-origin-opener-policy: same-origin cross-origin-resource-policy: same-origin expires: 0 pragma: no-cache content-type: application/json;charset=UTF-8 Content-Length: 62 date: Fri, 13 Jun 2025 22:02:41 GMT x-forgerock-transactionid: 95bcc276-1aa7-40d8-9f16-e3dc7b8903af strict-transport-security: max-age=31536000; includeSubDomains; preload; x-robots-tag: none Via: 1.1 google Alt-Svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000 body: {"code":401,"reason":"Unauthorized","message":"Access Denied"} <<<<<<<<<<<<<<<<<<<<<<<<< 23:02:41.629 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'EvalPolicy' failed for user 35782: status.find.in([200, 209], 304), found 401 23:02:41.630 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - >>>>>>>>>>>>>>>>>>>>>>>>>> Request: EvalPolicy: KO status.find.in([200, 209], 304), found 401 ========================= Session: Session(idc.benchmark.Mix2024,35782,HashMap(gatling.http.cache.baseUrl -> https://openam-tof-10.forgeblocks.com:443, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@8fbdb26, username -> user.1013468, tokenIdCookieName -> amlbcookie, policyEvalTokenId -> , gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@13656320, userTokenId -> jZI3yDSxv1c8ibDl_ZkRuHZ9zTs.*AAJTSQACMDIAAlNLABxmNC8wNTBza1FJK3RIMkVjTU9CYlY2amJZWGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, password -> Pa_ssw0rd),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$821/0x00007c7bb86983d0@2c99f81a,io.netty.channel.epoll.EpollEventLoop@5b057c8c) ========================= HTTP request: POST https://openam-tof-10.forgeblocks.com/am/json/realms/root/realms/alpha/policies?_action=evaluate headers: user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 12_5_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36 Content-Type: application/json Accept-API-Version: resource=2.0, protocol=1.0 Cookie: amlbcookie= accept: */* host: openam-tof-10.forgeblocks.com content-length: 323 body:StringChunksRequestBody{charset=UTF-8, content={ "resources":[ "http://www.example.com:80/index.html", "http://www.example.com:80/do?action=run" ], "application":"TestPolicySet", "subject": { "ssoToken": "jZI3yDSxv1c8ibDl_ZkRuHZ9zTs.*AAJTSQACMDIAAlNLABxmNC8wNTBza1FJK3RIMkVjTU9CYlY2amJZWGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*" } } } ========================= HTTP response: version: HTTP/1.1 status: 401 Unauthorized headers: x-frame-options: SAMEORIGIN content-security-policy-report-only: frame-ancestors 'self'; script-src 'self' 'unsafe-eval' 'unsafe-inline' x-content-type-options: nosniff cache-control: private content-security-policy: default-src 'none';frame-ancestors 'none';sandbox cross-origin-opener-policy: same-origin cross-origin-resource-policy: same-origin expires: 0 pragma: no-cache content-type: application/json;charset=UTF-8 Content-Length: 62 date: Fri, 13 Jun 2025 22:02:41 GMT x-forgerock-transactionid: 858721df-91b7-447a-b02f-62481c7e271e strict-transport-security: max-age=31536000; includeSubDomains; preload; x-robots-tag: none Via: 1.1 google Alt-Svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000 body: {"code":401,"reason":"Unauthorized","message":"Access Denied"} <<<<<<<<<<<<<<<<<<<<<<<<< 2025-06-13 23:02:41,722 INFO Gatling simulation run ended successfully 2025-06-13 23:02:41,722 DEBUG No archive name provided. No archive will be created ________________________________________________________________________________ [2025-06-13 22:03:07] benchmark-10 show_stderr : Display stderr order ________________________________________________________________________________ 2025-06-13 22:03:07,861 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/01_benchmark-10/stderr.txt is small (0 lines), printing all lines: 2025-06-13 22:03:07,861 INFO ----- output ----- ________________________________________________________________________________ [2025-06-13 22:03:07] benchmark-10 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2025-06-13 22:03:08] benchmark-10 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2025-06-13 22:03:08] benchmark-10 post : Post method ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped