--Task-- name: benchmark-30 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: ['benchmark-10'] preceding_task: benchmark-10 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 30} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-14 02:27:18] benchmark-30 pre : N/A ________________________________________________________________________________ 2024-11-14 02:27:18 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-14 02:27:18 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-30/stdout.txt Pod log : /results/orders/benchmark-30 2024-11-14 02:27:18,229 INFO 2024-11-14 02:27:18,229 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 2024-11-14 02:27:18,229 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 02:27:18,507 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 02:27:18,507 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:18,507 DEBUG --- stdout --- 2024-11-14 02:27:18,507 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 02:27:18,507 DEBUG --- stderr --- 2024-11-14 02:27:18,507 DEBUG ________________________________________________________________________________ [2024-11-14 02:27:18] benchmark-30 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-14 02:27:18,507 INFO 2024-11-14 02:27:18,507 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 2024-11-14 02:27:18,507 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 02:27:18,787 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 02:27:18,787 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:18,787 DEBUG --- stdout --- 2024-11-14 02:27:18,787 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 02:27:18,787 DEBUG --- stderr --- 2024-11-14 02:27:18,787 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-30" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=30 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-14 02:27:18] benchmark-30 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-14 02:27:18,787 INFO 2024-11-14 02:27:18,787 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 2024-11-14 02:27:18,787 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 02:27:19,062 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 02:27:19,062 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:19,062 DEBUG --- stdout --- 2024-11-14 02:27:19,062 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 02:27:19,062 DEBUG --- stderr --- 2024-11-14 02:27:19,062 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/order.json { "name": "benchmark-30", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-30\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=30 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-30" } ________________________________________________________________________________ [2024-11-14 02:27:19] benchmark-30 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: ________________________________________________________________________________ 2024-11-14 02:27:19,065 INFO 2024-11-14 02:27:19,065 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-14 02:27:19,065 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-14 02:27:19,283 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 02:27:19,283 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:19,283 DEBUG --- stdout --- 2024-11-14 02:27:19,283 DEBUG WAITING 2024-11-14 02:27:19,283 DEBUG --- stderr --- 2024-11-14 02:27:19,283 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 ________________________________________________________________________________ [2024-11-14 02:27:19] benchmark-30 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-14 02:27:19,283 INFO 2024-11-14 02:27:19,283 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 2024-11-14 02:27:19,283 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 02:27:19,559 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 02:27:19,559 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:19,559 DEBUG --- stdout --- 2024-11-14 02:27:19,559 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 02:27:19,559 DEBUG --- stderr --- 2024-11-14 02:27:19,559 DEBUG 2024-11-14 02:27:19,560 INFO 2024-11-14 02:27:19,560 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/02_benchmark-30/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-14 02:27:19,560 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 02:27:20,927 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:20,927 DEBUG --- stdout --- 2024-11-14 02:27:20,927 DEBUG 2024-11-14 02:27:20,927 DEBUG --- stderr --- 2024-11-14 02:27:20,927 DEBUG Order has been successfully forwarded to overseer 2024-11-14 02:27:20 - INFO: Check if Gatling simulation started successfully 2024-11-14 02:27:20,928 INFO 2024-11-14 02:27:20,928 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 2024-11-14 02:27:20,928 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 02:27:21,203 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 02:27:21,203 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:21,203 DEBUG --- stdout --- 2024-11-14 02:27:21,204 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 02:27:21,204 DEBUG --- stderr --- 2024-11-14 02:27:21,204 DEBUG 2024-11-14 02:27:21,204 INFO 2024-11-14 02:27:21,204 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- head --lines 5000 /results/orders/benchmark-30/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-14 02:27:21,204 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-14 02:27:21,939 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-14 02:27:27,674 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-14 02:27:33,447 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-14 02:27:33,448 INFO [loop_until]: OK (rc = 0) 2024-11-14 02:27:33,448 DEBUG --- stdout --- 2024-11-14 02:27:33,448 DEBUG 2024-11-14 02:27:21,761 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp6dds2dan 2024-11-14 02:27:21,763 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-30" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=30 -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/tmp6dds2dan/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/tmp6dds2dan/target/test-classes ... [INFO] compile in 6.9 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.1 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... 2024-11-14 02:27:33,448 DEBUG --- stderr --- 2024-11-14 02:27:33,448 DEBUG ________________________________________________________________________________ [2024-11-14 02:27:33] benchmark-30 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 06s, 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) ________________________________________________________________________________ [2024-11-14 03:27:42] benchmark-30 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-14 03:27:42,509 INFO 2024-11-14 03:27:42,509 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 2024-11-14 03:27:42,509 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:42,807 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:42,807 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:42,807 DEBUG --- stdout --- 2024-11-14 03:27:42,807 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:42,807 DEBUG --- stderr --- 2024-11-14 03:27:42,807 DEBUG 2024-11-14 03:27:42,807 INFO 2024-11-14 03:27:42,807 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- rm -f /results/orders/order.json 2024-11-14 03:27:42,807 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 03:27:43,592 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:43,592 DEBUG --- stdout --- 2024-11-14 03:27:43,592 DEBUG 2024-11-14 03:27:43,592 DEBUG --- stderr --- 2024-11-14 03:27:43,592 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-14 03:27:43] benchmark-30 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-14 03:27:43 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/order.json 2024-11-14 03:27:43,592 INFO 2024-11-14 03:27:43,592 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 2024-11-14 03:27:43,592 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:43,868 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:43,868 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:43,868 DEBUG --- stdout --- 2024-11-14 03:27:43,868 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:43,868 DEBUG --- stderr --- 2024-11-14 03:27:43,868 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 03:27:43,868 INFO 2024-11-14 03:27:43,868 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 2024-11-14 03:27:43,868 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:44,147 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:44,147 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:44,147 DEBUG --- stdout --- 2024-11-14 03:27:44,147 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:44,147 DEBUG --- stderr --- 2024-11-14 03:27:44,147 DEBUG 2024-11-14 03:27:44,147 INFO 2024-11-14 03:27:44,148 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/rc.txt" ]; then echo "/results/orders/benchmark-30/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-30/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/rc.txt file found" 2024-11-14 03:27:44,148 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 03:27:44,945 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 03:27:44,945 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:44,945 DEBUG --- stdout --- 2024-11-14 03:27:44,945 DEBUG /results/orders/benchmark-30/rc.txt file found 2024-11-14 03:27:44,945 DEBUG --- stderr --- 2024-11-14 03:27:44,945 DEBUG 2024-11-14 03:27:44,945 INFO 2024-11-14 03:27:44,945 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 2024-11-14 03:27:44,946 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:45,222 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:45,222 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:45,223 DEBUG --- stdout --- 2024-11-14 03:27:45,223 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:45,223 DEBUG --- stderr --- 2024-11-14 03:27:45,223 DEBUG 2024-11-14 03:27:45,223 INFO 2024-11-14 03:27:45,223 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-30/rc.txt 2024-11-14 03:27:46,026 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 03:27:46,026 DEBUG --- stdout --- 2024-11-14 03:27:46,026 DEBUG 4 /results/orders/benchmark-30/rc.txt 2024-11-14 03:27:46,026 DEBUG --- stderr --- 2024-11-14 03:27:46,026 DEBUG 2024-11-14 03:27:46,026 INFO - Download file (size 4k) 2024-11-14 03:27:46,026 INFO 2024-11-14 03:27:46,026 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 2024-11-14 03:27:46,026 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:46,301 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:46,301 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:46,301 DEBUG --- stdout --- 2024-11-14 03:27:46,302 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:46,302 DEBUG --- stderr --- 2024-11-14 03:27:46,302 DEBUG source : /results/orders/benchmark-30/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/rc.txt 2024-11-14 03:27:46,302 INFO 2024-11-14 03:27:46,302 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 2024-11-14 03:27:46,302 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:46,581 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:46,581 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:46,581 DEBUG --- stdout --- 2024-11-14 03:27:46,581 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:46,581 DEBUG --- stderr --- 2024-11-14 03:27:46,581 DEBUG 2024-11-14 03:27:46,581 INFO 2024-11-14 03:27:46,581 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-30/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/rc.txt 2024-11-14 03:27:46,581 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 03:27:47,339 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:47,339 DEBUG --- stdout --- 2024-11-14 03:27:47,339 DEBUG tar: Removing leading `/' from member names 2024-11-14 03:27:47,339 DEBUG --- stderr --- 2024-11-14 03:27:47,339 DEBUG 2024-11-14 03:27:47,340 INFO 2024-11-14 03:27:47,340 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 2024-11-14 03:27:47,340 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:47,617 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:47,617 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:47,617 DEBUG --- stdout --- 2024-11-14 03:27:47,617 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:47,617 DEBUG --- stderr --- 2024-11-14 03:27:47,617 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 03:27:47,618 INFO 2024-11-14 03:27:47,618 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 2024-11-14 03:27:47,618 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:47,894 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:47,894 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:47,894 DEBUG --- stdout --- 2024-11-14 03:27:47,894 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:47,894 DEBUG --- stderr --- 2024-11-14 03:27:47,894 DEBUG 2024-11-14 03:27:47,895 INFO 2024-11-14 03:27:47,895 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/stderr.txt" ]; then echo "/results/orders/benchmark-30/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-30/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/stderr.txt file found" 2024-11-14 03:27:47,895 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 03:27:48,683 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 03:27:48,683 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:48,683 DEBUG --- stdout --- 2024-11-14 03:27:48,683 DEBUG /results/orders/benchmark-30/stderr.txt file found 2024-11-14 03:27:48,683 DEBUG --- stderr --- 2024-11-14 03:27:48,683 DEBUG 2024-11-14 03:27:48,683 INFO 2024-11-14 03:27:48,683 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 2024-11-14 03:27:48,683 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:48,958 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:48,958 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:48,958 DEBUG --- stdout --- 2024-11-14 03:27:48,958 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:48,959 DEBUG --- stderr --- 2024-11-14 03:27:48,959 DEBUG 2024-11-14 03:27:48,959 INFO 2024-11-14 03:27:48,959 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-30/stderr.txt 2024-11-14 03:27:49,749 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 03:27:49,749 DEBUG --- stdout --- 2024-11-14 03:27:49,749 DEBUG 0 /results/orders/benchmark-30/stderr.txt 2024-11-14 03:27:49,749 DEBUG --- stderr --- 2024-11-14 03:27:49,749 DEBUG 2024-11-14 03:27:49,749 INFO - Download file (size 0k) 2024-11-14 03:27:49,749 INFO 2024-11-14 03:27:49,749 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 2024-11-14 03:27:49,749 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:50,024 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:50,024 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:50,024 DEBUG --- stdout --- 2024-11-14 03:27:50,024 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:50,024 DEBUG --- stderr --- 2024-11-14 03:27:50,024 DEBUG source : /results/orders/benchmark-30/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/stderr.txt 2024-11-14 03:27:50,025 INFO 2024-11-14 03:27:50,025 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 2024-11-14 03:27:50,025 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:50,307 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:50,307 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:50,307 DEBUG --- stdout --- 2024-11-14 03:27:50,308 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:50,308 DEBUG --- stderr --- 2024-11-14 03:27:50,308 DEBUG 2024-11-14 03:27:50,309 INFO 2024-11-14 03:27:50,309 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-30/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/stderr.txt 2024-11-14 03:27:50,309 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 03:27:51,090 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:51,090 DEBUG --- stdout --- 2024-11-14 03:27:51,090 DEBUG tar: Removing leading `/' from member names 2024-11-14 03:27:51,090 DEBUG --- stderr --- 2024-11-14 03:27:51,090 DEBUG 2024-11-14 03:27:51,090 INFO 2024-11-14 03:27:51,090 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 2024-11-14 03:27:51,090 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:51,366 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:51,366 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:51,366 DEBUG --- stdout --- 2024-11-14 03:27:51,367 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:51,367 DEBUG --- stderr --- 2024-11-14 03:27:51,367 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 03:27:51,368 INFO 2024-11-14 03:27:51,368 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 2024-11-14 03:27:51,368 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:51,646 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:51,646 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:51,646 DEBUG --- stdout --- 2024-11-14 03:27:51,646 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:51,646 DEBUG --- stderr --- 2024-11-14 03:27:51,646 DEBUG 2024-11-14 03:27:51,647 INFO 2024-11-14 03:27:51,647 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/stdout.txt" ]; then echo "/results/orders/benchmark-30/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-30/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/stdout.txt file found" 2024-11-14 03:27:51,647 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 03:27:52,436 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 03:27:52,436 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:52,436 DEBUG --- stdout --- 2024-11-14 03:27:52,436 DEBUG /results/orders/benchmark-30/stdout.txt file found 2024-11-14 03:27:52,436 DEBUG --- stderr --- 2024-11-14 03:27:52,436 DEBUG 2024-11-14 03:27:52,437 INFO 2024-11-14 03:27:52,437 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 2024-11-14 03:27:52,437 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:52,714 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:52,714 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:52,714 DEBUG --- stdout --- 2024-11-14 03:27:52,714 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:52,714 DEBUG --- stderr --- 2024-11-14 03:27:52,714 DEBUG 2024-11-14 03:27:52,714 INFO 2024-11-14 03:27:52,714 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-30/stdout.txt 2024-11-14 03:27:53,515 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 03:27:53,515 DEBUG --- stdout --- 2024-11-14 03:27:53,515 DEBUG 3644 /results/orders/benchmark-30/stdout.txt 2024-11-14 03:27:53,515 DEBUG --- stderr --- 2024-11-14 03:27:53,515 DEBUG 2024-11-14 03:27:53,515 INFO - Download file (size 3644k) 2024-11-14 03:27:53,516 INFO 2024-11-14 03:27:53,516 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 2024-11-14 03:27:53,516 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:53,797 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:53,797 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:53,797 DEBUG --- stdout --- 2024-11-14 03:27:53,797 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:53,797 DEBUG --- stderr --- 2024-11-14 03:27:53,797 DEBUG source : /results/orders/benchmark-30/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/stdout.txt 2024-11-14 03:27:53,797 INFO 2024-11-14 03:27:53,798 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 2024-11-14 03:27:53,798 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:54,075 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:54,075 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:54,075 DEBUG --- stdout --- 2024-11-14 03:27:54,075 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:54,075 DEBUG --- stderr --- 2024-11-14 03:27:54,075 DEBUG 2024-11-14 03:27:54,076 INFO 2024-11-14 03:27:54,076 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-30/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/stdout.txt 2024-11-14 03:27:54,076 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 03:27:55,306 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:55,306 DEBUG --- stdout --- 2024-11-14 03:27:55,306 DEBUG tar: Removing leading `/' from member names 2024-11-14 03:27:55,306 DEBUG --- stderr --- 2024-11-14 03:27:55,306 DEBUG ________________________________________________________________________________ [2024-11-14 03:27:55] benchmark-30 show_cmd : Display order command ________________________________________________________________________________ 2024-11-14 03:27:55,307 INFO 2024-11-14 03:27:55,307 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 2024-11-14 03:27:55,307 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:55,583 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:55,583 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:55,583 DEBUG --- stdout --- 2024-11-14 03:27:55,583 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:55,583 DEBUG --- stderr --- 2024-11-14 03:27:55,583 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 03:27:55,583 INFO 2024-11-14 03:27:55,583 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 2024-11-14 03:27:55,584 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:55,859 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:55,860 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:55,860 DEBUG --- stdout --- 2024-11-14 03:27:55,860 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:55,860 DEBUG --- stderr --- 2024-11-14 03:27:55,860 DEBUG 2024-11-14 03:27:55,860 INFO 2024-11-14 03:27:55,860 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/cmd.txt" ]; then echo "/results/orders/benchmark-30/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-30/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/cmd.txt file found" 2024-11-14 03:27:55,860 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 03:27:56,663 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 03:27:56,663 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:56,663 DEBUG --- stdout --- 2024-11-14 03:27:56,663 DEBUG /results/orders/benchmark-30/cmd.txt file found 2024-11-14 03:27:56,663 DEBUG --- stderr --- 2024-11-14 03:27:56,663 DEBUG 2024-11-14 03:27:56,663 INFO 2024-11-14 03:27:56,663 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 2024-11-14 03:27:56,663 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:56,937 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:56,937 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:56,937 DEBUG --- stdout --- 2024-11-14 03:27:56,937 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:56,937 DEBUG --- stderr --- 2024-11-14 03:27:56,937 DEBUG 2024-11-14 03:27:56,938 INFO 2024-11-14 03:27:56,938 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-30/cmd.txt 2024-11-14 03:27:57,729 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 03:27:57,729 DEBUG --- stdout --- 2024-11-14 03:27:57,729 DEBUG 4 /results/orders/benchmark-30/cmd.txt 2024-11-14 03:27:57,729 DEBUG --- stderr --- 2024-11-14 03:27:57,729 DEBUG 2024-11-14 03:27:57,729 INFO - Download file (size 4k) 2024-11-14 03:27:57,729 INFO 2024-11-14 03:27:57,729 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 2024-11-14 03:27:57,729 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:58,004 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:58,005 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:58,005 DEBUG --- stdout --- 2024-11-14 03:27:58,005 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:58,005 DEBUG --- stderr --- 2024-11-14 03:27:58,005 DEBUG source : /results/orders/benchmark-30/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/cmd.txt 2024-11-14 03:27:58,005 INFO 2024-11-14 03:27:58,005 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 2024-11-14 03:27:58,005 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:27:58,281 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:27:58,281 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:58,281 DEBUG --- stdout --- 2024-11-14 03:27:58,281 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:27:58,281 DEBUG --- stderr --- 2024-11-14 03:27:58,281 DEBUG 2024-11-14 03:27:58,281 INFO 2024-11-14 03:27:58,281 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-30/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/cmd.txt 2024-11-14 03:27:58,281 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 03:27:59,039 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:27:59,039 DEBUG --- stdout --- 2024-11-14 03:27:59,039 DEBUG tar: Removing leading `/' from member names 2024-11-14 03:27:59,039 DEBUG --- stderr --- 2024-11-14 03:27:59,039 DEBUG 2024-11-14 03:27:59,039 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/cmd.txt is small (1 lines), printing all lines: 2024-11-14 03:27:59,039 DEBUG ----- output ----- 2024-11-14 03:27:59,039 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-30" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=30 -Duser_password=Pa_ssw0rd" 2024-11-14 03:27:59,039 INFO ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-30 show_rc : Display rc order ________________________________________________________________________________ 2024-11-14 03:27:59,039 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/rc.txt is small (1 lines), printing all lines: 2024-11-14 03:27:59,039 DEBUG ----- output ----- 2024-11-14 03:27:59,039 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-14 03:27:59,039 INFO ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-30 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-14 03:27:59,045 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/02_benchmark-30/stdout.txt is 48334 lines): 2024-11-14 03:27:59,045 DEBUG ----- output ----- 2024-11-14 03:27:59,045 INFO 2024-11-14 02:27:21,761 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp6dds2dan 2024-11-14 03:27:59,045 INFO 2024-11-14 02:27:21,763 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-30" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=30 -Duser_password=**** 2024-11-14 03:27:59,045 INFO [INFO] Scanning for projects... 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-14 03:27:59,045 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-14 03:27:59,045 INFO [INFO] from pom.xml 2024-11-14 03:27:59,045 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-14 03:27:59,045 INFO [INFO] skip non existing resourceDirectory /tmp/tmp6dds2dan/src/main/resources 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-14 03:27:59,045 INFO [INFO] No sources to compile 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-14 03:27:59,045 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-14 03:27:59,045 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-14 03:27:59,045 INFO [INFO] compiling 38 Scala sources to /tmp/tmp6dds2dan/target/test-classes ... 2024-11-14 03:27:59,045 INFO [INFO] compile in 6.9 s 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] 2024-11-14 03:27:59,045 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-14 03:27:59,045 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-14 03:27:59,045 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-14 03:27:59,045 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-14 03:27:59,045 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-14 03:27:59,045 INFO 2024-11-14 03:27:59,045 INFO ================================================================================ 2024-11-14 03:27:59,045 INFO 2024-11-14 02:27:37 GMT 5s elapsed 2024-11-14 03:27:59,045 INFO ---- Requests ------------------------------------------------------------------ 2024-11-14 03:27:59,045 INFO > Global (OK=103 KO=0 ) 2024-11-14 03:27:59,045 INFO > restLoginInitiate (OK=11 KO=0 ) 2024-11-14 03:27:59,045 INFO > restLoginUsernamePasswordCallback (OK=11 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI-Post-Login - stage 1 (OK=1 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=1 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI AM idFromSession (OK=1 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI AM validateGoto (OK=1 KO=0 ) 2024-11-14 03:27:59,045 INFO > User Authorize PKCE stage (OK=12 KO=0 ) 2024-11-14 03:27:59,045 INFO > User AccessToken PKCE stage (OK=11 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI-Post-Login - stage 2 (OK=1 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=1 KO=0 ) 2024-11-14 03:27:59,045 INFO > UI Enduser appAuthHelper2 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI Enduser appAuthHelper1 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > Skip 2FA (OK=6 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI-Post-Login - stage 3 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM uiconfig (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI Enduser sessioncheck (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM version (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM privilege (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM features (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM login (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > RootUserinfo (OK=7 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM dashboard (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM managed user schema (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM user (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI IDM oidcToken (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > userinfo (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI-Logout (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI-Logout Redirect 1 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI AM revoke2 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI AM revoke1 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI AM endsession (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > GetUUid (OK=3 KO=0 ) 2024-11-14 03:27:59,046 INFO > GetOpenidConfig (OK=3 KO=0 ) 2024-11-14 03:27:59,046 INFO > CreatePolicy (OK=3 KO=0 ) 2024-11-14 03:27:59,046 INFO > tokenUserinfo (OK=3 KO=0 ) 2024-11-14 03:27:59,046 INFO > getIdToken (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > getIdToken Redirect 1 (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > createOrganization (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > queryOrganization (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > deleteOrganization (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > loginTreeWorkflow_restLoginInitiate (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=1 KO=0 ) 2024-11-14 03:27:59,046 INFO 2024-11-14 03:27:59,046 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-14 03:27:59,046 INFO [- ] 0% 2024-11-14 03:27:59,046 INFO waiting: 108389 / active: 6 / done: 6 2024-11-14 03:27:59,046 INFO ================================================================================ 2024-11-14 03:27:59,046 INFO 2024-11-14 03:27:59,046 INFO 2024-11-14 03:27:59,046 INFO ================================================================================ 2024-11-14 03:27:59,046 INFO 2024-11-14 02:27:42 GMT 10s elapsed 2024-11-14 03:27:59,046 INFO ---- Requests ------------------------------------------------------------------ 2024-11-14 03:27:59,046 INFO > Global (OK=490 KO=0 ) 2024-11-14 03:27:59,046 INFO > restLoginInitiate (OK=48 KO=0 ) 2024-11-14 03:27:59,046 INFO > restLoginUsernamePasswordCallback (OK=47 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI-Post-Login - stage 1 (OK=7 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=7 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI AM idFromSession (OK=6 KO=0 ) 2024-11-14 03:27:59,046 INFO > UI AM validateGoto (OK=6 KO=0 ) 2024-11-14 03:27:59,046 INFO [...] 2024-11-14 03:27:59,053 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-14 03:27:59,053 INFO ========================= 2024-11-14 03:27:59,053 INFO Session: 2024-11-14 03:27:59,053 INFO Session(idc.benchmark.Mix2024,107460,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.178641, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@69e6ab73, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"f4_J6tDO0DG5eSYqdrklmg-qmN0.*AAJTSQACMDIAAlNLABxJSy9tNERsVWJRNVpRbWFaREI2U2RRTEUxRkU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","successUrl":"/enduser/?realm=/alpha","realm":"/alpha"}, gatling.http.cookies -> CookieJar(Map(CookieKey(amlbcookie,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731554852611), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=f4_J6tDO0DG5eSYqdrklmg-qmN0.*AAJTSQACMDIAAlNLABxJSy9tNERsVWJRNVpRbWFaREI2U2RRTEUxRkU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731554852611))), password -> Pa_ssw0rd, fake-ip -> 77.205.92.85, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@62e32de, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@697c4f8b, tokenId -> f4_J6tDO0DG5eSYqdrklmg-qmN0.*AAJTSQACMDIAAlNLABxJSy9tNERsVWJRNVpRbWFaREI2U2RRTEUxRkU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/17.17134),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d9980698800@328b5c17,io.netty.channel.epoll.EpollEventLoop@239b0f9d) 2024-11-14 03:27:59,053 INFO ========================= 2024-11-14 03:27:59,053 INFO HTTP request: 2024-11-14 03:27:59,053 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-14 03:27:59,053 INFO headers: 2024-11-14 03:27:59,053 INFO 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 2024-11-14 03:27:59,053 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-14 03:27:59,053 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-14 03:27:59,053 INFO accept: */* 2024-11-14 03:27:59,053 INFO cookie: amlbcookie=01; 9b75a55744995d0=f4_J6tDO0DG5eSYqdrklmg-qmN0.*AAJTSQACMDIAAlNLABxJSy9tNERsVWJRNVpRbWFaREI2U2RRTEUxRkU9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-14 03:27:59,053 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-14 03:27:59,053 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 03:27:59,053 INFO content-length: 0 2024-11-14 03:27:59,053 INFO cookies: 2024-11-14 03:27:59,053 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 03:27:59,053 INFO 9b75a55744995d0=f4_J6tDO0DG5eSYqdrklmg-qmN0.*AAJTSQACMDIAAlNLABxJSy9tNERsVWJRNVpRbWFaREI2U2RRTEUxRkU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 03:27:59,053 INFO ========================= 2024-11-14 03:27:59,053 INFO HTTP response: 2024-11-14 03:27:59,053 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 03:27:59,053 INFO 03:27:32.723 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 03:27:59,053 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 03:27:59,053 INFO Request: 2024-11-14 03:27:59,053 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-14 03:27:59,053 INFO ========================= 2024-11-14 03:27:59,054 INFO Session: 2024-11-14 03:27:59,054 INFO Session(idc.benchmark.Mix2024,107462,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.177699, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@658e55aa, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"pHaBHg8AqTgbbNI0BMQZHyAsfQY.*AAJTSQACMDIAAlNLABxuZFRWMlAwQ3pyb0dFeWwzMlVma1ZnaG1YZmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","successUrl":"/enduser/?realm=/alpha","realm":"/alpha"}, gatling.http.cookies -> CookieJar(Map(CookieKey(amlbcookie,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731554852614), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=pHaBHg8AqTgbbNI0BMQZHyAsfQY.*AAJTSQACMDIAAlNLABxuZFRWMlAwQ3pyb0dFeWwzMlVma1ZnaG1YZmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731554852614))), password -> Pa_ssw0rd, fake-ip -> 54.132.82.78, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@fa387bf, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@23693ec6, tokenId -> pHaBHg8AqTgbbNI0BMQZHyAsfQY.*AAJTSQACMDIAAlNLABxuZFRWMlAwQ3pyb0dFeWwzMlVma1ZnaG1YZmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d9980698800@328b5c17,io.netty.channel.epoll.EpollEventLoop@5b057c8c) 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO HTTP request: 2024-11-14 03:27:59,054 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-14 03:27:59,054 INFO headers: 2024-11-14 03:27:59,054 INFO 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 2024-11-14 03:27:59,054 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-14 03:27:59,054 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-14 03:27:59,054 INFO accept: */* 2024-11-14 03:27:59,054 INFO cookie: amlbcookie=01; 9b75a55744995d0=pHaBHg8AqTgbbNI0BMQZHyAsfQY.*AAJTSQACMDIAAlNLABxuZFRWMlAwQ3pyb0dFeWwzMlVma1ZnaG1YZmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-14 03:27:59,054 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-14 03:27:59,054 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 03:27:59,054 INFO content-length: 0 2024-11-14 03:27:59,054 INFO cookies: 2024-11-14 03:27:59,054 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 03:27:59,054 INFO 9b75a55744995d0=pHaBHg8AqTgbbNI0BMQZHyAsfQY.*AAJTSQACMDIAAlNLABxuZFRWMlAwQ3pyb0dFeWwzMlVma1ZnaG1YZmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO HTTP response: 2024-11-14 03:27:59,054 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 03:27:59,054 INFO 03:27:32.723 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 03:27:59,054 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 03:27:59,054 INFO Request: 2024-11-14 03:27:59,054 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO Session: 2024-11-14 03:27:59,054 INFO Session(idc.benchmark.Mix2024,107472,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.86760, randomPolicyName -> testPolicy658310, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@4331434, 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 -> 68.176.253.81, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@53fc1293),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d9980698800@328b5c17,io.netty.channel.epoll.EpollEventLoop@636e8cc) 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO HTTP request: 2024-11-14 03:27:59,054 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-14 03:27:59,054 INFO headers: 2024-11-14 03:27:59,054 INFO accept: application/json 2024-11-14 03:27:59,054 INFO content-type: application/json 2024-11-14 03:27:59,054 INFO user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36 2024-11-14 03:27:59,054 INFO X-Forwarded-For: 68.176.253.81 2024-11-14 03:27:59,054 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 03:27:59,054 INFO content-length: 0 2024-11-14 03:27:59,054 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO HTTP response: 2024-11-14 03:27:59,054 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 03:27:59,054 INFO 03:27:32.723 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 03:27:59,054 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 03:27:59,054 INFO Request: 2024-11-14 03:27:59,054 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO Session: 2024-11-14 03:27:59,054 INFO Session(idc.benchmark.Mix2024,107473,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.33197, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3fbdf3e4, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1, password -> Pa_ssw0rd, fake-ip -> 169.100.141.180, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@5cf31cd0),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d9980698800@328b5c17,io.netty.channel.epoll.EpollEventLoop@f79a760) 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO HTTP request: 2024-11-14 03:27:59,054 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-14 03:27:59,054 INFO headers: 2024-11-14 03:27:59,054 INFO accept: application/json 2024-11-14 03:27:59,054 INFO content-type: application/json 2024-11-14 03:27:59,054 INFO user-agent: Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1 2024-11-14 03:27:59,054 INFO X-Forwarded-For: 169.100.141.180 2024-11-14 03:27:59,054 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 03:27:59,054 INFO content-length: 0 2024-11-14 03:27:59,054 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-14 03:27:59,054 INFO ========================= 2024-11-14 03:27:59,054 INFO HTTP response: 2024-11-14 03:27:59,055 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 03:27:59,055 INFO 03:27:32.723 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-190' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-14 03:27:59,055 INFO 03:27:32.723 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-133' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-14 03:27:59,055 INFO 03:27:32.723 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-14 03:27:59,055 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 03:27:59,055 INFO [INFO] BUILD SUCCESS 2024-11-14 03:27:59,055 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 03:27:59,055 INFO [INFO] Total time: 01:00 h 2024-11-14 03:27:59,055 INFO [INFO] Finished at: 2024-11-14T03:27:32Z 2024-11-14 03:27:59,055 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 03:27:59,055 INFO 2024-11-14 03:27:32,823 INFO Gatling simulation run ended successfully 2024-11-14 03:27:59,055 INFO 2024-11-14 03:27:32,823 DEBUG No archive name provided. No archive will be created 2024-11-14 03:27:59,055 INFO ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-30 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-14 03:27:59,055 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-30/stderr.txt is small (0 lines), printing all lines: 2024-11-14 03:27:59,055 DEBUG ----- output ----- 2024-11-14 03:27:59,055 DEBUG 2024-11-14 03:27:59,055 INFO ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-30 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-30 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-30 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped