--Task-- name: login-tree-100 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: {'testCase': 'idc.login', 'throughput': 100, 'duration': 3600, 'testMode': 'open', 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Dlogin_tree=Login'} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock 2025-03-15 18:16:27,960 INFO 2025-03-15 18:16:27,960 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-15 18:16:27,960 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 18:16:28,295 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 18:16:28,295 INFO [loop_until]: OK (rc = 0) 2025-03-15 18:16:28,295 DEBUG --- stdout --- 2025-03-15 18:16:28,295 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 18:16:28,295 DEBUG --- stderr --- 2025-03-15 18:16:28,295 DEBUG 2025-03-15 18:16:28,295 INFO Lodestar assumed that full stack is deployed so will set all products host URLs in Gatling system properties 2025-03-15 18:16:28 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2025-03-15 18:16:28 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/login-tree-100/stdout.txt Pod log : /results/orders/login-tree-100 2025-03-15 18:16:29 - INFO: Get overseer pod resources requests memory 2025-03-15 18:16:29,206 INFO 2025-03-15 18:16:29,206 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-15 18:16:29,206 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 18:16:29,501 INFO [loop_until]: OK (rc = 0) 2025-03-15 18:16:29,501 DEBUG --- stdout --- 2025-03-15 18:16:29,501 DEBUG 8Gi 2025-03-15 18:16:29,501 DEBUG --- stderr --- 2025-03-15 18:16:29,501 DEBUG ________________________________________________________________________________ [2025-03-15 18:16:29] login-tree-100 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ /lodestar/lodestar.py perf run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.login@perf-200m" --results-folder="/results/gatling/login-tree-100" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx8G" --simulation-system-properties="-Dam_host=openam-perf-200m.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-perf-200m.forgeblocks.com -Dlogin_cookie=15892ffd844ef80 -Dlogin_tree=Login -Dnum_users=50000000 -Doauth2_client_id=idmAdminClient -Doauth2_redirect_uri=/platform/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.login -DtestMode=open -Dthroughput=100 -Duser_password=**** ________________________________________________________________________________ [2025-03-15 18:16:29] login-tree-100 create_order : Create order for overseer with the command to run ________________________________________________________________________________ Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/order.json { "name": "login-tree-100", "command": " /lodestar/lodestar.py perf run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.login@perf-200m\" --results-folder=\"/results/gatling/login-tree-100\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx8G\" --simulation-system-properties=\"-Dam_host=openam-perf-200m.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-perf-200m.forgeblocks.com -Dlogin_cookie=15892ffd844ef80 -Dlogin_tree=Login -Dnum_users=50000000 -Doauth2_client_id=idmAdminClient -Doauth2_redirect_uri=/platform/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.login -DtestMode=open -Dthroughput=100 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/login-tree-100" } ________________________________________________________________________________ [2025-03-15 18:16:29] login-tree-100 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-03-15 18:16:29,509 INFO 2025-03-15 18:16:29,509 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2025-03-15 18:16:29,509 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2025-03-15 18:16:29,831 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-15 18:16:29,831 INFO [loop_until]: OK (rc = 0) 2025-03-15 18:16:29,831 DEBUG --- stdout --- 2025-03-15 18:16:29,831 DEBUG WAITING 2025-03-15 18:16:29,831 DEBUG --- stderr --- 2025-03-15 18:16:29,832 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 23 0 --:--:-- --:--:-- --:--:-- 23 ________________________________________________________________________________ [2025-03-15 18:16:29] login-tree-100 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2025-03-15 18:16:29,834 INFO 2025-03-15 18:16:29,835 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-15 18:16:29,835 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 18:16:30,112 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 18:16:30,112 INFO [loop_until]: OK (rc = 0) 2025-03-15 18:16:30,112 DEBUG --- stdout --- 2025-03-15 18:16:30,112 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 18:16:30,112 DEBUG --- stderr --- 2025-03-15 18:16:30,112 DEBUG 2025-03-15 18:16:30,113 INFO 2025-03-15 18:16:30,113 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/order.json overseer-0-59c948f569-rgrkv:/results/orders/order.json 2025-03-15 18:16:30,113 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 18:16:31,486 INFO [loop_until]: OK (rc = 0) 2025-03-15 18:16:31,486 DEBUG --- stdout --- 2025-03-15 18:16:31,486 DEBUG 2025-03-15 18:16:31,486 DEBUG --- stderr --- 2025-03-15 18:16:31,486 DEBUG Order has been successfully forwarded to overseer 2025-03-15 18:16:31 - INFO: Check if Gatling simulation started successfully 2025-03-15 18:16:31,487 INFO 2025-03-15 18:16:31,487 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv -- head --lines 5000 /results/orders/login-tree-100/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2025-03-15 18:16:31,487 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2025-03-15 18:16:32,220 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-03-15 18:16:37,965 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-03-15 18:16:43,692 INFO [loop_until]: Function succeeded after 12s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2025-03-15 18:16:49,422 INFO [loop_until]: Function succeeded after 17s (rc=0) - expected pattern found 2025-03-15 18:16:49,422 INFO [loop_until]: OK (rc = 0) 2025-03-15 18:16:49,422 DEBUG --- stdout --- 2025-03-15 18:16:49,422 DEBUG 2025-03-15 18:16:32,313 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpj75ypsz9 2025-03-15 18:16:32,316 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/login-tree-100" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx8G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-200m.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-perf-200m.forgeblocks.com -Dlogin_cookie=15892ffd844ef80 -Dlogin_tree=Login -Dnum_users=50000000 -Doauth2_client_id=idmAdminClient -Doauth2_redirect_uri=/platform/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.login -DtestMode=open -Dthroughput=100 -Duser_password=**** [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/tmpj75ypsz9/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] Copying 2 resources from src/test/resources to target/test-classes [INFO] [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- [INFO] Nothing to compile - all classes are up to date. [INFO] [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- [INFO] compiling 38 Scala sources to /tmp/tmpj75ypsz9/target/test-classes ... [INFO] compile in 9.0 s [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 --- [INFO] Running simulation com.forgerock.pyrock.Loadtest. 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-03-15 18:16:49,422 DEBUG --- stderr --- 2025-03-15 18:16:49,422 DEBUG ________________________________________________________________________________ [2025-03-15 18:16:49] login-tree-100 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 04s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 06s, 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 08s, retry Order is running since 54m 08s, retry Order is running since 56m 08s, retry Order is running since 58m 09s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2025-03-15 19:16:58] login-tree-100 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2025-03-15 19:16:58,758 INFO 2025-03-15 19:16:58,758 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-15 19:16:58,758 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 19:16:59,064 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 19:16:59,064 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:16:59,064 DEBUG --- stdout --- 2025-03-15 19:16:59,064 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 19:16:59,064 DEBUG --- stderr --- 2025-03-15 19:16:59,064 DEBUG 2025-03-15 19:16:59,064 INFO 2025-03-15 19:16:59,064 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv -- rm -f /results/orders/order.json 2025-03-15 19:16:59,064 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 19:16:59,845 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:16:59,845 DEBUG --- stdout --- 2025-03-15 19:16:59,846 DEBUG 2025-03-15 19:16:59,846 DEBUG --- stderr --- 2025-03-15 19:16:59,846 DEBUG Order ran during 1h ________________________________________________________________________________ [2025-03-15 19:16:59] login-tree-100 download_logs : Download individual order files ________________________________________________________________________________ 2025-03-15 19:16:59 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/order.json 2025-03-15 19:16:59,846 INFO 2025-03-15 19:16:59,846 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-15 19:16:59,846 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 19:17:00,126 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 19:17:00,126 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:00,126 DEBUG --- stdout --- 2025-03-15 19:17:00,126 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 19:17:00,126 DEBUG --- stderr --- 2025-03-15 19:17:00,126 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-15 19:17:00,127 INFO 2025-03-15 19:17:00,127 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/login-tree-100/rc.txt" ]; then echo "/results/orders/login-tree-100/rc.txt file found"; exit 0; else echo "/results/orders/login-tree-100/rc.txt file not found"; exit 1; fi' | grep "/results/orders/login-tree-100/rc.txt file found" 2025-03-15 19:17:00,127 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 19:17:00,930 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-15 19:17:00,930 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:00,930 DEBUG --- stdout --- 2025-03-15 19:17:00,931 DEBUG /results/orders/login-tree-100/rc.txt file found 2025-03-15 19:17:00,931 DEBUG --- stderr --- 2025-03-15 19:17:00,931 DEBUG 2025-03-15 19:17:00,931 INFO 2025-03-15 19:17:00,931 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/login-tree-100/rc.txt 2025-03-15 19:17:01,745 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-15 19:17:01,745 DEBUG --- stdout --- 2025-03-15 19:17:01,745 DEBUG 4 /results/orders/login-tree-100/rc.txt 2025-03-15 19:17:01,745 DEBUG --- stderr --- 2025-03-15 19:17:01,745 DEBUG 2025-03-15 19:17:01,745 INFO - Download file (size 4k) source : /results/orders/login-tree-100/rc.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/rc.txt 2025-03-15 19:17:01,746 INFO 2025-03-15 19:17:01,746 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/login-tree-100/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/rc.txt 2025-03-15 19:17:01,746 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-15 19:17:02,516 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:02,517 DEBUG --- stdout --- 2025-03-15 19:17:02,517 DEBUG tar: Removing leading `/' from member names 2025-03-15 19:17:02,517 DEBUG --- stderr --- 2025-03-15 19:17:02,517 DEBUG 2025-03-15 19:17:02,517 INFO 2025-03-15 19:17:02,517 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-15 19:17:02,517 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 19:17:02,801 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 19:17:02,801 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:02,801 DEBUG --- stdout --- 2025-03-15 19:17:02,801 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 19:17:02,801 DEBUG --- stderr --- 2025-03-15 19:17:02,801 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-15 19:17:02,802 INFO 2025-03-15 19:17:02,802 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/login-tree-100/stderr.txt" ]; then echo "/results/orders/login-tree-100/stderr.txt file found"; exit 0; else echo "/results/orders/login-tree-100/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/login-tree-100/stderr.txt file found" 2025-03-15 19:17:02,802 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 19:17:03,596 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-15 19:17:03,596 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:03,596 DEBUG --- stdout --- 2025-03-15 19:17:03,596 DEBUG /results/orders/login-tree-100/stderr.txt file found 2025-03-15 19:17:03,596 DEBUG --- stderr --- 2025-03-15 19:17:03,596 DEBUG 2025-03-15 19:17:03,596 INFO 2025-03-15 19:17:03,597 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/login-tree-100/stderr.txt 2025-03-15 19:17:04,400 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-15 19:17:04,400 DEBUG --- stdout --- 2025-03-15 19:17:04,400 DEBUG 0 /results/orders/login-tree-100/stderr.txt 2025-03-15 19:17:04,401 DEBUG --- stderr --- 2025-03-15 19:17:04,401 DEBUG 2025-03-15 19:17:04,401 INFO - Download file (size 0k) source : /results/orders/login-tree-100/stderr.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/stderr.txt 2025-03-15 19:17:04,401 INFO 2025-03-15 19:17:04,401 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/login-tree-100/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/stderr.txt 2025-03-15 19:17:04,401 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-15 19:17:05,125 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:05,125 DEBUG --- stdout --- 2025-03-15 19:17:05,125 DEBUG tar: Removing leading `/' from member names 2025-03-15 19:17:05,125 DEBUG --- stderr --- 2025-03-15 19:17:05,125 DEBUG 2025-03-15 19:17:05,125 INFO 2025-03-15 19:17:05,125 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-15 19:17:05,125 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 19:17:05,405 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 19:17:05,405 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:05,405 DEBUG --- stdout --- 2025-03-15 19:17:05,405 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 19:17:05,405 DEBUG --- stderr --- 2025-03-15 19:17:05,405 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-15 19:17:05,406 INFO 2025-03-15 19:17:05,406 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/login-tree-100/stdout.txt" ]; then echo "/results/orders/login-tree-100/stdout.txt file found"; exit 0; else echo "/results/orders/login-tree-100/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/login-tree-100/stdout.txt file found" 2025-03-15 19:17:05,406 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 19:17:06,209 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-15 19:17:06,209 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:06,209 DEBUG --- stdout --- 2025-03-15 19:17:06,209 DEBUG /results/orders/login-tree-100/stdout.txt file found 2025-03-15 19:17:06,209 DEBUG --- stderr --- 2025-03-15 19:17:06,209 DEBUG 2025-03-15 19:17:06,209 INFO 2025-03-15 19:17:06,210 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/login-tree-100/stdout.txt 2025-03-15 19:17:06,996 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-15 19:17:06,996 DEBUG --- stdout --- 2025-03-15 19:17:06,996 DEBUG 752 /results/orders/login-tree-100/stdout.txt 2025-03-15 19:17:06,996 DEBUG --- stderr --- 2025-03-15 19:17:06,996 DEBUG 2025-03-15 19:17:06,996 INFO - Download file (size 752k) source : /results/orders/login-tree-100/stdout.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/stdout.txt 2025-03-15 19:17:06,997 INFO 2025-03-15 19:17:06,997 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/login-tree-100/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/stdout.txt 2025-03-15 19:17:06,997 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-15 19:17:08,065 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:08,065 DEBUG --- stdout --- 2025-03-15 19:17:08,065 DEBUG tar: Removing leading `/' from member names 2025-03-15 19:17:08,065 DEBUG --- stderr --- 2025-03-15 19:17:08,065 DEBUG ________________________________________________________________________________ [2025-03-15 19:17:08] login-tree-100 show_cmd : Display order command ________________________________________________________________________________ 2025-03-15 19:17:08,066 INFO 2025-03-15 19:17:08,066 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-15 19:17:08,066 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2025-03-15 19:17:08,349 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2025-03-15 19:17:08,349 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:08,349 DEBUG --- stdout --- 2025-03-15 19:17:08,349 DEBUG overseer-0-59c948f569-rgrkv 2025-03-15 19:17:08,349 DEBUG --- stderr --- 2025-03-15 19:17:08,349 DEBUG Checking pod: overseer-0-59c948f569-rgrkv for file exists, if not wait. 2025-03-15 19:17:08,350 INFO 2025-03-15 19:17:08,350 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/login-tree-100/cmd.txt" ]; then echo "/results/orders/login-tree-100/cmd.txt file found"; exit 0; else echo "/results/orders/login-tree-100/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/login-tree-100/cmd.txt file found" 2025-03-15 19:17:08,350 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2025-03-15 19:17:09,164 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2025-03-15 19:17:09,164 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:09,164 DEBUG --- stdout --- 2025-03-15 19:17:09,164 DEBUG /results/orders/login-tree-100/cmd.txt file found 2025-03-15 19:17:09,164 DEBUG --- stderr --- 2025-03-15 19:17:09,164 DEBUG 2025-03-15 19:17:09,164 INFO 2025-03-15 19:17:09,165 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-59c948f569-rgrkv --stdin -- du -k /results/orders/login-tree-100/cmd.txt 2025-03-15 19:17:09,962 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2025-03-15 19:17:09,963 DEBUG --- stdout --- 2025-03-15 19:17:09,963 DEBUG 4 /results/orders/login-tree-100/cmd.txt 2025-03-15 19:17:09,963 DEBUG --- stderr --- 2025-03-15 19:17:09,963 DEBUG 2025-03-15 19:17:09,963 INFO - Download file (size 4k) source : /results/orders/login-tree-100/cmd.txt @ overseer-0-59c948f569-rgrkv destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/cmd.txt 2025-03-15 19:17:09,963 INFO 2025-03-15 19:17:09,963 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-59c948f569-rgrkv:/results/orders/login-tree-100/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/cmd.txt 2025-03-15 19:17:09,963 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2025-03-15 19:17:10,738 INFO [loop_until]: OK (rc = 0) 2025-03-15 19:17:10,738 DEBUG --- stdout --- 2025-03-15 19:17:10,738 DEBUG tar: Removing leading `/' from member names 2025-03-15 19:17:10,738 DEBUG --- stderr --- 2025-03-15 19:17:10,738 DEBUG 2025-03-15 19:17:10,738 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/cmd.txt is small (1 lines), printing all lines: 2025-03-15 19:17:10,739 INFO ----- output ----- /lodestar/lodestar.py perf run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.login@perf-200m" --results-folder="/results/gatling/login-tree-100" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx8G" --simulation-system-properties="-Dam_host=openam-perf-200m.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-perf-200m.forgeblocks.com -Dlogin_cookie=15892ffd844ef80 -Dlogin_tree=Login -Dnum_users=50000000 -Doauth2_client_id=idmAdminClient -Doauth2_redirect_uri=/platform/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.login -DtestMode=open -Dthroughput=100 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2025-03-15 19:17:10] login-tree-100 show_rc : Display rc order ________________________________________________________________________________ 2025-03-15 19:17:10,739 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/rc.txt is small (1 lines), printing all lines: 2025-03-15 19:17:10,739 INFO ----- output ----- CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) ________________________________________________________________________________ [2025-03-15 19:17:10] login-tree-100 show_stdout : Display stdout order ________________________________________________________________________________ 2025-03-15 19:17:10,740 DEBUG [print_head_tail]: Print head (100 lines) and tail (100 lines) of input file (/mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/stdout.txt is 11888 lines): 2025-03-15 19:17:10,742 INFO ----- output ----- 2025-03-15 18:16:32,313 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpj75ypsz9 2025-03-15 18:16:32,316 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/login-tree-100" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx8G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-200m.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Didm_host=openam-perf-200m.forgeblocks.com -Dlogin_cookie=15892ffd844ef80 -Dlogin_tree=Login -Dnum_users=50000000 -Doauth2_client_id=idmAdminClient -Doauth2_redirect_uri=/platform/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.login -DtestMode=open -Dthroughput=100 -Duser_password=**** [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/tmpj75ypsz9/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] Copying 2 resources from src/test/resources to target/test-classes [INFO] [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- [INFO] Nothing to compile - all classes are up to date. [INFO] [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- [INFO] compiling 38 Scala sources to /tmp/tmpj75ypsz9/target/test-classes ... [INFO] compile in 9.0 s [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 --- [INFO] Running simulation com.forgerock.pyrock.Loadtest. 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-03-15 18:16:50 GMT 5s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=79 KO=0 ) > restLoginInitiate (OK=40 KO=0 ) > restLoginUsernamePasswordCallback (OK=39 KO=0 ) ---- idc.login ----------------------------------------------------------------- [- ] 0% waiting: 362728 / active: 2 / done: 39 ================================================================================ ================================================================================ 2025-03-15 18:16:55 GMT 10s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=327 KO=0 ) > restLoginInitiate (OK=165 KO=0 ) > restLoginUsernamePasswordCallback (OK=162 KO=0 ) ---- idc.login ----------------------------------------------------------------- [- ] 0% waiting: 362603 / active: 4 / done: 162 ================================================================================ ================================================================================ 2025-03-15 18:17:00 GMT 15s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=740 KO=0 ) > restLoginInitiate (OK=372 KO=0 ) > restLoginUsernamePasswordCallback (OK=368 KO=0 ) ---- idc.login ----------------------------------------------------------------- [- ] 0% waiting: 362394 / active: 7 / done: 368 ================================================================================ ================================================================================ 2025-03-15 18:17:05 GMT 20s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=1321 KO=0 ) > restLoginInitiate (OK=663 KO=0 ) > restLoginUsernamePasswordCallback (OK=658 KO=0 ) ---- idc.login ----------------------------------------------------------------- [- ] 0% waiting: 362103 / active: 8 / done: 658 ================================================================================ ================================================================================ 2025-03-15 18:17:10 GMT 25s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=2067 KO=0 ) > restLoginInitiate (OK=1037 KO=0 ) > restLoginUsernamePasswordCallback (OK=1030 KO=0 ) ---- idc.login ----------------------------------------------------------------- [- ] 0% waiting: 361728 / active: 11 / done: 1030 ================================================================================ [...] > restLoginInitiate (OK=358740 KO=5 ) > restLoginUsernamePasswordCallback (OK=358728 KO=6 ) ---- Errors -------------------------------------------------------------------- > status.find.is(200), but actually found 502 10 (90.91%) > Request timeout to openam-perf-200m.forgeblocks.com/34.107.203 1 ( 9.09%) .37:443 after 60000 ms ---- idc.login ----------------------------------------------------------------- [#########################################################################-] 98% waiting: 4018 / active: 12 / done: 358739 ================================================================================ ================================================================================ 2025-03-15 19:16:40 GMT 3595s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=718460 KO=11 ) > restLoginInitiate (OK=359235 KO=5 ) > restLoginUsernamePasswordCallback (OK=359225 KO=6 ) ---- Errors -------------------------------------------------------------------- > status.find.is(200), but actually found 502 10 (90.91%) > Request timeout to openam-perf-200m.forgeblocks.com/34.107.203 1 ( 9.09%) .37:443 after 60000 ms ---- idc.login ----------------------------------------------------------------- [#########################################################################-] 99% waiting: 3525 / active: 8 / done: 359236 ================================================================================ ================================================================================ 2025-03-15 19:16:45 GMT 3600s elapsed ---- Requests ------------------------------------------------------------------ > Global (OK=719459 KO=11 ) > restLoginInitiate (OK=359737 KO=5 ) > restLoginUsernamePasswordCallback (OK=359722 KO=6 ) ---- Errors -------------------------------------------------------------------- > status.find.is(200), but actually found 502 10 (90.91%) > Request timeout to openam-perf-200m.forgeblocks.com/34.107.203 1 ( 9.09%) .37:443 after 60000 ms ---- idc.login ----------------------------------------------------------------- [#########################################################################-] 99% waiting: 3025 / active: 11 / done: 359733 ================================================================================ 19:16:45.914 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 359743: j.i.IOException: Premature close 19:16:45.914 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 359744: j.i.IOException: Premature close 19:16:45.914 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - >>>>>>>>>>>>>>>>>>>>>>>>>> Request: restLoginInitiate: KO j.i.IOException: Premature close ========================= Session: Session(idc.login,359743,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-200m.forgeblocks.com:443, username -> user.6390308, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@73e9e0f3, fake-user-agent -> Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36, password -> Pa_ssw0rd, fake-ip -> 86.165.184.130, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@3216ae1e),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$773/0x00007800e867dde8@23a2be34,io.netty.channel.epoll.EpollEventLoop@4e28bdd1) ========================= HTTP request: POST https://openam-perf-200m.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate?authIndexType=service&authIndexValue=Login headers: content-type: application/json Accept-API-Version: resource=2.0, protocol=1.0 accept: application/json X-Forwarded-For: 86.165.184.130 User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36 host: openam-perf-200m.forgeblocks.com content-length: 0 body:StringChunksRequestBody{charset=UTF-8, content=} ========================= HTTP response: <<<<<<<<<<<<<<<<<<<<<<<<< 19:16:45.915 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - >>>>>>>>>>>>>>>>>>>>>>>>>> Request: restLoginInitiate: KO j.i.IOException: Premature close ========================= Session: Session(idc.login,359744,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-200m.forgeblocks.com:443, username -> user.31626496, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1cf95413, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.3, password -> Pa_ssw0rd, fake-ip -> 92.41.53.184, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@25fd8b5e),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$773/0x00007800e867dde8@23a2be34,io.netty.channel.epoll.EpollEventLoop@636e8cc) ========================= HTTP request: POST https://openam-perf-200m.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate?authIndexType=service&authIndexValue=Login headers: content-type: application/json Accept-API-Version: resource=2.0, protocol=1.0 accept: application/json X-Forwarded-For: 92.41.53.184 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.3 host: openam-perf-200m.forgeblocks.com content-length: 0 body:StringChunksRequestBody{charset=UTF-8, content=} ========================= HTTP response: <<<<<<<<<<<<<<<<<<<<<<<<< [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 01:00 h [INFO] Finished at: 2025-03-15T19:16:45Z [INFO] ------------------------------------------------------------------------ 2025-03-15 19:16:45,975 INFO Gatling simulation run ended successfully 2025-03-15 19:16:45,976 DEBUG No archive name provided. No archive will be created ________________________________________________________________________________ [2025-03-15 19:17:10] login-tree-100 show_stderr : Display stderr order ________________________________________________________________________________ 2025-03-15 19:17:10,742 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_login_tree/07_Scenario_scenario/01_login-tree-100/stderr.txt is small (0 lines), printing all lines: 2025-03-15 19:17:10,742 INFO ----- output ----- ________________________________________________________________________________ [2025-03-15 19:17:10] login-tree-100 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-03-15 19:17:11] login-tree-100 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2025-03-15 19:17:11] login-tree-100 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped