--Task-- name: benchmark-15 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-5'] preceding_task: benchmark-5 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 15} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-21 19:12:01] benchmark-15 pre : N/A ________________________________________________________________________________ 2024-11-21 19:12:01 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-21 19:12:01 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-15/stdout.txt Pod log : /results/orders/benchmark-15 2024-11-21 19:12:01,744 INFO 2024-11-21 19:12:01,744 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-21 19:12:01,744 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 19:12:02,016 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 19:12:02,016 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:02,016 DEBUG --- stdout --- 2024-11-21 19:12:02,016 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 19:12:02,016 DEBUG --- stderr --- 2024-11-21 19:12:02,016 DEBUG ________________________________________________________________________________ [2024-11-21 19:12:02] benchmark-15 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-21 19:12:02,016 INFO 2024-11-21 19:12:02,016 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-21 19:12:02,016 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 19:12:02,290 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 19:12:02,290 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:02,290 DEBUG --- stdout --- 2024-11-21 19:12:02,290 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 19:12:02,290 DEBUG --- stderr --- 2024-11-21 19:12:02,290 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-15" --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 -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=15 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-21 19:12:02] benchmark-15 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-21 19:12:02,290 INFO 2024-11-21 19:12:02,290 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-21 19:12:02,290 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 19:12:02,566 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 19:12:02,566 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:02,566 DEBUG --- stdout --- 2024-11-21 19:12:02,566 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 19:12:02,566 DEBUG --- stderr --- 2024-11-21 19:12:02,566 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/order.json { "name": "benchmark-15", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-15\" --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 -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=15 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-15" } ________________________________________________________________________________ [2024-11-21 19:12:02] benchmark-15 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-21 19:12:02,569 INFO 2024-11-21 19:12:02,569 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-21 19:12:02,569 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 19:12:02,783 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 19:12:02,783 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:02,783 DEBUG --- stdout --- 2024-11-21 19:12:02,783 DEBUG WAITING 2024-11-21 19:12:02,783 DEBUG --- stderr --- 2024-11-21 19:12:02,783 DEBUG % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 34 0 --:--:-- --:--:-- --:--:-- 34 ________________________________________________________________________________ [2024-11-21 19:12:02] benchmark-15 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-21 19:12:02,783 INFO 2024-11-21 19:12:02,783 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-21 19:12:02,783 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 19:12:03,056 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 19:12:03,056 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:03,056 DEBUG --- stdout --- 2024-11-21 19:12:03,056 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 19:12:03,056 DEBUG --- stderr --- 2024-11-21 19:12:03,056 DEBUG 2024-11-21 19:12:03,057 INFO 2024-11-21 19:12:03,057 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-15/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-21 19:12:03,057 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 19:12:04,377 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:04,377 DEBUG --- stdout --- 2024-11-21 19:12:04,377 DEBUG 2024-11-21 19:12:04,377 DEBUG --- stderr --- 2024-11-21 19:12:04,377 DEBUG Order has been successfully forwarded to overseer 2024-11-21 19:12:04 - INFO: Check if Gatling simulation started successfully 2024-11-21 19:12:04,378 INFO 2024-11-21 19:12:04,378 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-21 19:12:04,378 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 19:12:04,650 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 19:12:04,650 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:04,650 DEBUG --- stdout --- 2024-11-21 19:12:04,650 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 19:12:04,650 DEBUG --- stderr --- 2024-11-21 19:12:04,651 DEBUG 2024-11-21 19:12:04,651 INFO 2024-11-21 19:12:04,651 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-15/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-21 19:12:04,652 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 19:12:05,367 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 19:12:11,083 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 19:12:16,797 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-21 19:12:16,797 INFO [loop_until]: OK (rc = 0) 2024-11-21 19:12:16,797 DEBUG --- stdout --- 2024-11-21 19:12:16,797 DEBUG 2024-11-21 19:12:05,308 DEBUG Creating results folder /results/gatling/benchmark-15 2024-11-21 19:12:05,315 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpyypqf9eg 2024-11-21 19:12:05,317 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-15" -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 -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=15 -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/tmpyypqf9eg/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/tmpyypqf9eg/target/test-classes ... [INFO] compile in 6.8 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-21 19:12:16,797 DEBUG --- stderr --- 2024-11-21 19:12:16,797 DEBUG ________________________________________________________________________________ [2024-11-21 19:12:16] benchmark-15 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 01s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 02s, 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 05s, 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 06s, retry Order is running since 50m 07s, retry Order is running since 52m 07s, retry Order is running since 54m 07s, 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-21 20:12:25] benchmark-15 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-21 20:12:25,438 INFO 2024-11-21 20:12:25,438 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-21 20:12:25,438 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:25,731 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:25,731 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:25,731 DEBUG --- stdout --- 2024-11-21 20:12:25,731 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:25,731 DEBUG --- stderr --- 2024-11-21 20:12:25,731 DEBUG 2024-11-21 20:12:25,731 INFO 2024-11-21 20:12:25,731 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-21 20:12:25,731 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 20:12:26,507 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:26,507 DEBUG --- stdout --- 2024-11-21 20:12:26,507 DEBUG 2024-11-21 20:12:26,507 DEBUG --- stderr --- 2024-11-21 20:12:26,507 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-21 20:12:26] benchmark-15 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-21 20:12:26 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/order.json 2024-11-21 20:12:26,508 INFO 2024-11-21 20:12:26,508 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-21 20:12:26,508 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:26,783 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:26,783 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:26,783 DEBUG --- stdout --- 2024-11-21 20:12:26,783 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:26,783 DEBUG --- stderr --- 2024-11-21 20:12:26,783 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 20:12:26,783 INFO 2024-11-21 20:12:26,783 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-21 20:12:26,783 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:27,058 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:27,058 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:27,058 DEBUG --- stdout --- 2024-11-21 20:12:27,058 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:27,058 DEBUG --- stderr --- 2024-11-21 20:12:27,059 DEBUG 2024-11-21 20:12:27,059 INFO 2024-11-21 20:12:27,059 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-15/rc.txt" ]; then echo "/results/orders/benchmark-15/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-15/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-15/rc.txt file found" 2024-11-21 20:12:27,059 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 20:12:27,836 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 20:12:27,836 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:27,836 DEBUG --- stdout --- 2024-11-21 20:12:27,836 DEBUG /results/orders/benchmark-15/rc.txt file found 2024-11-21 20:12:27,837 DEBUG --- stderr --- 2024-11-21 20:12:27,837 DEBUG 2024-11-21 20:12:27,837 INFO 2024-11-21 20:12:27,837 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-21 20:12:27,837 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:28,114 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:28,114 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:28,114 DEBUG --- stdout --- 2024-11-21 20:12:28,114 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:28,114 DEBUG --- stderr --- 2024-11-21 20:12:28,114 DEBUG 2024-11-21 20:12:28,114 INFO 2024-11-21 20:12:28,114 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-15/rc.txt 2024-11-21 20:12:28,895 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 20:12:28,895 DEBUG --- stdout --- 2024-11-21 20:12:28,895 DEBUG 4 /results/orders/benchmark-15/rc.txt 2024-11-21 20:12:28,895 DEBUG --- stderr --- 2024-11-21 20:12:28,895 DEBUG 2024-11-21 20:12:28,895 INFO - Download file (size 4k) 2024-11-21 20:12:28,896 INFO 2024-11-21 20:12:28,896 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-21 20:12:28,896 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:29,167 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:29,167 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:29,167 DEBUG --- stdout --- 2024-11-21 20:12:29,167 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:29,168 DEBUG --- stderr --- 2024-11-21 20:12:29,168 DEBUG source : /results/orders/benchmark-15/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/rc.txt 2024-11-21 20:12:29,168 INFO 2024-11-21 20:12:29,168 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-21 20:12:29,168 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:29,440 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:29,440 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:29,440 DEBUG --- stdout --- 2024-11-21 20:12:29,440 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:29,440 DEBUG --- stderr --- 2024-11-21 20:12:29,440 DEBUG 2024-11-21 20:12:29,441 INFO 2024-11-21 20:12:29,441 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-15/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/rc.txt 2024-11-21 20:12:29,441 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 20:12:30,186 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:30,186 DEBUG --- stdout --- 2024-11-21 20:12:30,186 DEBUG tar: Removing leading `/' from member names 2024-11-21 20:12:30,186 DEBUG --- stderr --- 2024-11-21 20:12:30,186 DEBUG 2024-11-21 20:12:30,187 INFO 2024-11-21 20:12:30,187 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-21 20:12:30,187 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:30,468 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:30,468 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:30,468 DEBUG --- stdout --- 2024-11-21 20:12:30,468 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:30,468 DEBUG --- stderr --- 2024-11-21 20:12:30,468 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 20:12:30,468 INFO 2024-11-21 20:12:30,468 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-21 20:12:30,468 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:30,741 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:30,742 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:30,742 DEBUG --- stdout --- 2024-11-21 20:12:30,742 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:30,742 DEBUG --- stderr --- 2024-11-21 20:12:30,742 DEBUG 2024-11-21 20:12:30,742 INFO 2024-11-21 20:12:30,742 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-15/stderr.txt" ]; then echo "/results/orders/benchmark-15/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-15/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-15/stderr.txt file found" 2024-11-21 20:12:30,742 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 20:12:31,510 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 20:12:31,511 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:31,511 DEBUG --- stdout --- 2024-11-21 20:12:31,511 DEBUG /results/orders/benchmark-15/stderr.txt file found 2024-11-21 20:12:31,511 DEBUG --- stderr --- 2024-11-21 20:12:31,511 DEBUG 2024-11-21 20:12:31,511 INFO 2024-11-21 20:12:31,511 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 20:12:31,511 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:31,788 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:31,788 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:31,788 DEBUG --- stdout --- 2024-11-21 20:12:31,788 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:31,788 DEBUG --- stderr --- 2024-11-21 20:12:31,788 DEBUG 2024-11-21 20:12:31,788 INFO 2024-11-21 20:12:31,788 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-15/stderr.txt 2024-11-21 20:12:32,564 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 20:12:32,564 DEBUG --- stdout --- 2024-11-21 20:12:32,564 DEBUG 0 /results/orders/benchmark-15/stderr.txt 2024-11-21 20:12:32,564 DEBUG --- stderr --- 2024-11-21 20:12:32,564 DEBUG 2024-11-21 20:12:32,564 INFO - Download file (size 0k) 2024-11-21 20:12:32,565 INFO 2024-11-21 20:12:32,565 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-21 20:12:32,565 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:32,837 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:32,837 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:32,837 DEBUG --- stdout --- 2024-11-21 20:12:32,837 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:32,837 DEBUG --- stderr --- 2024-11-21 20:12:32,837 DEBUG source : /results/orders/benchmark-15/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/stderr.txt 2024-11-21 20:12:32,838 INFO 2024-11-21 20:12:32,838 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-21 20:12:32,838 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:33,108 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:33,108 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:33,108 DEBUG --- stdout --- 2024-11-21 20:12:33,108 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:33,108 DEBUG --- stderr --- 2024-11-21 20:12:33,108 DEBUG 2024-11-21 20:12:33,109 INFO 2024-11-21 20:12:33,109 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-15/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/stderr.txt 2024-11-21 20:12:33,109 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 20:12:33,853 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:33,853 DEBUG --- stdout --- 2024-11-21 20:12:33,853 DEBUG tar: Removing leading `/' from member names 2024-11-21 20:12:33,853 DEBUG --- stderr --- 2024-11-21 20:12:33,853 DEBUG 2024-11-21 20:12:33,853 INFO 2024-11-21 20:12:33,853 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-21 20:12:33,853 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:34,126 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:34,126 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:34,126 DEBUG --- stdout --- 2024-11-21 20:12:34,126 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:34,126 DEBUG --- stderr --- 2024-11-21 20:12:34,127 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 20:12:34,127 INFO 2024-11-21 20:12:34,127 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-21 20:12:34,127 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:34,399 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:34,399 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:34,399 DEBUG --- stdout --- 2024-11-21 20:12:34,399 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:34,399 DEBUG --- stderr --- 2024-11-21 20:12:34,399 DEBUG 2024-11-21 20:12:34,400 INFO 2024-11-21 20:12:34,400 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-15/stdout.txt" ]; then echo "/results/orders/benchmark-15/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-15/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-15/stdout.txt file found" 2024-11-21 20:12:34,400 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 20:12:35,179 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 20:12:35,180 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:35,180 DEBUG --- stdout --- 2024-11-21 20:12:35,180 DEBUG /results/orders/benchmark-15/stdout.txt file found 2024-11-21 20:12:35,180 DEBUG --- stderr --- 2024-11-21 20:12:35,180 DEBUG 2024-11-21 20:12:35,180 INFO 2024-11-21 20:12:35,180 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-21 20:12:35,180 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:35,456 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:35,456 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:35,456 DEBUG --- stdout --- 2024-11-21 20:12:35,456 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:35,456 DEBUG --- stderr --- 2024-11-21 20:12:35,456 DEBUG 2024-11-21 20:12:35,456 INFO 2024-11-21 20:12:35,456 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-15/stdout.txt 2024-11-21 20:12:36,235 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 20:12:36,235 DEBUG --- stdout --- 2024-11-21 20:12:36,235 DEBUG 3440 /results/orders/benchmark-15/stdout.txt 2024-11-21 20:12:36,235 DEBUG --- stderr --- 2024-11-21 20:12:36,235 DEBUG 2024-11-21 20:12:36,235 INFO - Download file (size 3440k) 2024-11-21 20:12:36,236 INFO 2024-11-21 20:12:36,236 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-21 20:12:36,236 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:36,509 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:36,509 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:36,509 DEBUG --- stdout --- 2024-11-21 20:12:36,509 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:36,509 DEBUG --- stderr --- 2024-11-21 20:12:36,509 DEBUG source : /results/orders/benchmark-15/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/stdout.txt 2024-11-21 20:12:36,509 INFO 2024-11-21 20:12:36,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-21 20:12:36,509 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:36,793 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:36,793 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:36,794 DEBUG --- stdout --- 2024-11-21 20:12:36,794 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:36,794 DEBUG --- stderr --- 2024-11-21 20:12:36,794 DEBUG 2024-11-21 20:12:36,794 INFO 2024-11-21 20:12:36,794 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-15/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/stdout.txt 2024-11-21 20:12:36,794 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 20:12:37,997 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:37,997 DEBUG --- stdout --- 2024-11-21 20:12:37,997 DEBUG tar: Removing leading `/' from member names 2024-11-21 20:12:37,997 DEBUG --- stderr --- 2024-11-21 20:12:37,997 DEBUG ________________________________________________________________________________ [2024-11-21 20:12:37] benchmark-15 show_cmd : Display order command ________________________________________________________________________________ 2024-11-21 20:12:37,997 INFO 2024-11-21 20:12:37,997 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-21 20:12:37,997 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:38,269 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:38,269 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:38,269 DEBUG --- stdout --- 2024-11-21 20:12:38,269 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:38,269 DEBUG --- stderr --- 2024-11-21 20:12:38,269 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 20:12:38,270 INFO 2024-11-21 20:12:38,270 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-21 20:12:38,270 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:38,545 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:38,546 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:38,546 DEBUG --- stdout --- 2024-11-21 20:12:38,546 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:38,546 DEBUG --- stderr --- 2024-11-21 20:12:38,546 DEBUG 2024-11-21 20:12:38,546 INFO 2024-11-21 20:12:38,546 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-15/cmd.txt" ]; then echo "/results/orders/benchmark-15/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-15/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-15/cmd.txt file found" 2024-11-21 20:12:38,546 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 20:12:39,330 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 20:12:39,330 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:39,330 DEBUG --- stdout --- 2024-11-21 20:12:39,330 DEBUG /results/orders/benchmark-15/cmd.txt file found 2024-11-21 20:12:39,330 DEBUG --- stderr --- 2024-11-21 20:12:39,330 DEBUG 2024-11-21 20:12:39,331 INFO 2024-11-21 20:12:39,331 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-21 20:12:39,331 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:39,603 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:39,603 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:39,603 DEBUG --- stdout --- 2024-11-21 20:12:39,603 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:39,603 DEBUG --- stderr --- 2024-11-21 20:12:39,604 DEBUG 2024-11-21 20:12:39,604 INFO 2024-11-21 20:12:39,604 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-15/cmd.txt 2024-11-21 20:12:40,545 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 20:12:40,545 DEBUG --- stdout --- 2024-11-21 20:12:40,545 DEBUG 4 /results/orders/benchmark-15/cmd.txt 2024-11-21 20:12:40,545 DEBUG --- stderr --- 2024-11-21 20:12:40,545 DEBUG 2024-11-21 20:12:40,545 INFO - Download file (size 4k) 2024-11-21 20:12:40,545 INFO 2024-11-21 20:12:40,545 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-21 20:12:40,545 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:40,818 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:40,818 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:40,818 DEBUG --- stdout --- 2024-11-21 20:12:40,818 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:40,818 DEBUG --- stderr --- 2024-11-21 20:12:40,818 DEBUG source : /results/orders/benchmark-15/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/cmd.txt 2024-11-21 20:12:40,818 INFO 2024-11-21 20:12:40,818 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-21 20:12:40,818 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 20:12:41,091 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 20:12:41,091 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:41,091 DEBUG --- stdout --- 2024-11-21 20:12:41,091 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 20:12:41,091 DEBUG --- stderr --- 2024-11-21 20:12:41,091 DEBUG 2024-11-21 20:12:41,092 INFO 2024-11-21 20:12:41,092 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-15/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/cmd.txt 2024-11-21 20:12:41,092 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 20:12:41,833 INFO [loop_until]: OK (rc = 0) 2024-11-21 20:12:41,833 DEBUG --- stdout --- 2024-11-21 20:12:41,833 DEBUG tar: Removing leading `/' from member names 2024-11-21 20:12:41,833 DEBUG --- stderr --- 2024-11-21 20:12:41,833 DEBUG 2024-11-21 20:12:41,833 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/cmd.txt is small (1 lines), printing all lines: 2024-11-21 20:12:41,833 DEBUG ----- output ----- 2024-11-21 20:12:41,833 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-15" --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 -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=15 -Duser_password=Pa_ssw0rd" 2024-11-21 20:12:41,833 INFO ________________________________________________________________________________ [2024-11-21 20:12:41] benchmark-15 show_rc : Display rc order ________________________________________________________________________________ 2024-11-21 20:12:41,833 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/rc.txt is small (1 lines), printing all lines: 2024-11-21 20:12:41,833 DEBUG ----- output ----- 2024-11-21 20:12:41,833 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-21 20:12:41,833 INFO ________________________________________________________________________________ [2024-11-21 20:12:41] benchmark-15 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-21 20:12:41,838 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-15/stdout.txt is 45622 lines): 2024-11-21 20:12:41,838 DEBUG ----- output ----- 2024-11-21 20:12:41,838 INFO 2024-11-21 19:12:05,308 DEBUG Creating results folder /results/gatling/benchmark-15 2024-11-21 20:12:41,838 INFO 2024-11-21 19:12:05,315 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpyypqf9eg 2024-11-21 20:12:41,838 INFO 2024-11-21 19:12:05,317 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-15" -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 -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=15 -Duser_password=**** 2024-11-21 20:12:41,838 INFO [INFO] Scanning for projects... 2024-11-21 20:12:41,838 INFO [INFO] 2024-11-21 20:12:41,838 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-21 20:12:41,838 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-21 20:12:41,838 INFO [INFO] from pom.xml 2024-11-21 20:12:41,838 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-21 20:12:41,838 INFO [INFO] 2024-11-21 20:12:41,838 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-21 20:12:41,838 INFO [INFO] 2024-11-21 20:12:41,838 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-21 20:12:41,838 INFO [INFO] skip non existing resourceDirectory /tmp/tmpyypqf9eg/src/main/resources 2024-11-21 20:12:41,838 INFO [INFO] 2024-11-21 20:12:41,838 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-21 20:12:41,839 INFO [INFO] No sources to compile 2024-11-21 20:12:41,839 INFO [INFO] 2024-11-21 20:12:41,839 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-21 20:12:41,839 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-21 20:12:41,839 INFO [INFO] 2024-11-21 20:12:41,839 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-21 20:12:41,839 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-21 20:12:41,839 INFO [INFO] 2024-11-21 20:12:41,839 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-21 20:12:41,839 INFO [INFO] compiling 38 Scala sources to /tmp/tmpyypqf9eg/target/test-classes ... 2024-11-21 20:12:41,839 INFO [INFO] compile in 6.8 s 2024-11-21 20:12:41,839 INFO [INFO] 2024-11-21 20:12:41,839 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-21 20:12:41,839 INFO [INFO] 2024-11-21 20:12:41,839 INFO [INFO] 2024-11-21 20:12:41,839 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-21 20:12:41,839 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-21 20:12:41,839 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-21 20:12:41,839 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-21 20:12:41,839 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-21 20:12:41,839 INFO 2024-11-21 20:12:41,839 INFO ================================================================================ 2024-11-21 20:12:41,839 INFO 2024-11-21 19:12:21 GMT 5s elapsed 2024-11-21 20:12:41,839 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 20:12:41,839 INFO > Global (OK=66 KO=0 ) 2024-11-21 20:12:41,839 INFO > restLoginInitiate (OK=6 KO=0 ) 2024-11-21 20:12:41,839 INFO > restLoginUsernamePasswordCallback (OK=6 KO=0 ) 2024-11-21 20:12:41,839 INFO > Skip 2FA (OK=4 KO=0 ) 2024-11-21 20:12:41,839 INFO > User Authorize PKCE stage (OK=7 KO=0 ) 2024-11-21 20:12:41,839 INFO > User AccessToken PKCE stage (OK=7 KO=0 ) 2024-11-21 20:12:41,839 INFO > GetUUid (OK=2 KO=0 ) 2024-11-21 20:12:41,839 INFO > GetOpenidConfig (OK=2 KO=0 ) 2024-11-21 20:12:41,839 INFO > CreatePolicy (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > RootUserinfo (OK=4 KO=0 ) 2024-11-21 20:12:41,839 INFO > tokenUserinfo (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > getIdToken (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > getIdToken Redirect 1 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > createOrganization (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > queryOrganization (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > deleteOrganization (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI-Post-Login - stage 1 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI AM idFromSession (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI AM validateGoto (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI-Post-Login - stage 2 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI Enduser appAuthHelper2 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI Enduser appAuthHelper1 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI-Post-Login - stage 3 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI Enduser sessioncheck (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM uiconfig (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM version (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM privilege (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM features (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM login (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM managed user schema (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM dashboard (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM user (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > UI IDM oidcToken (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO > userinfo (OK=1 KO=0 ) 2024-11-21 20:12:41,839 INFO 2024-11-21 20:12:41,840 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-21 20:12:41,840 INFO [- ] 0% 2024-11-21 20:12:41,840 INFO waiting: 54299 / active: 4 / done: 2 2024-11-21 20:12:41,840 INFO ================================================================================ 2024-11-21 20:12:41,840 INFO 2024-11-21 20:12:41,840 INFO 2024-11-21 20:12:41,840 INFO ================================================================================ 2024-11-21 20:12:41,840 INFO 2024-11-21 19:12:26 GMT 10s elapsed 2024-11-21 20:12:41,840 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 20:12:41,840 INFO > Global (OK=279 KO=0 ) 2024-11-21 20:12:41,840 INFO > restLoginInitiate (OK=25 KO=0 ) 2024-11-21 20:12:41,840 INFO > restLoginUsernamePasswordCallback (OK=25 KO=0 ) 2024-11-21 20:12:41,840 INFO > Skip 2FA (OK=13 KO=0 ) 2024-11-21 20:12:41,840 INFO > User Authorize PKCE stage (OK=28 KO=0 ) 2024-11-21 20:12:41,840 INFO > User AccessToken PKCE stage (OK=28 KO=0 ) 2024-11-21 20:12:41,840 INFO > GetUUid (OK=6 KO=0 ) 2024-11-21 20:12:41,840 INFO > GetOpenidConfig (OK=7 KO=0 ) 2024-11-21 20:12:41,840 INFO > CreatePolicy (OK=6 KO=0 ) 2024-11-21 20:12:41,840 INFO > RootUserinfo (OK=9 KO=0 ) 2024-11-21 20:12:41,840 INFO > tokenUserinfo (OK=7 KO=0 ) 2024-11-21 20:12:41,840 INFO > getIdToken (OK=4 KO=0 ) 2024-11-21 20:12:41,840 INFO > getIdToken Redirect 1 (OK=4 KO=0 ) 2024-11-21 20:12:41,840 INFO [...] 2024-11-21 20:12:41,846 INFO > UI AM endsession (OK=11489 KO=0 ) 2024-11-21 20:12:41,846 INFO > ReadPolicy (OK=17233 KO=1 ) 2024-11-21 20:12:41,846 INFO > DeletePolicy (OK=17208 KO=2 ) 2024-11-21 20:12:41,846 INFO > loginTreeWorkflow_restLoginInitiate (OK=1970 KO=0 ) 2024-11-21 20:12:41,846 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=1970 KO=0 ) 2024-11-21 20:12:41,846 INFO > loginTreeWorkflow_restloginProgressiveProfileCallback (OK=9 KO=0 ) 2024-11-21 20:12:41,846 INFO > restloginProgressiveProfileCallback (OK=67 KO=0 ) 2024-11-21 20:12:41,846 INFO ---- Errors -------------------------------------------------------------------- 2024-11-21 20:12:41,846 INFO > tokenUserinfo: No attribute named 'access_token' is defined 65 (84.42%) 2024-11-21 20:12:41,846 INFO > status.find.in([200, 209], 304), found 409 3 ( 3.90%) 2024-11-21 20:12:41,846 INFO > status.find.in([200, 209], 304), found 404 3 ( 3.90%) 2024-11-21 20:12:41,846 INFO > status.find.in([200, 209], 304), found 502 2 ( 2.60%) 2024-11-21 20:12:41,846 INFO > status.find.is(302), but actually found 502 2 ( 2.60%) 2024-11-21 20:12:41,846 INFO > userinfo: No attribute named 'access_token' is defined 1 ( 1.30%) 2024-11-21 20:12:41,846 INFO > UI AM revoke1: No attribute named 'access_token' is defined 1 ( 1.30%) 2024-11-21 20:12:41,846 INFO 2024-11-21 20:12:41,846 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-21 20:12:41,846 INFO [#########################################################################-] 99% 2024-11-21 20:12:41,846 INFO waiting: 457 / active: 75 / done: 53773 2024-11-21 20:12:41,846 INFO ================================================================================ 2024-11-21 20:12:41,846 INFO 2024-11-21 20:12:41,846 INFO 20:12:16.143 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 53849: j.n.c.ClosedChannelException 2024-11-21 20:12:41,846 INFO 20:12:16.143 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request ' UI AM validateGoto' failed for user 53844: j.i.IOException: Premature close 2024-11-21 20:12:41,847 INFO 20:12:16.143 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 53848: j.i.IOException: Premature close 2024-11-21 20:12:41,847 INFO 20:12:16.144 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 20:12:41,847 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 20:12:41,847 INFO Request: 2024-11-21 20:12:41,847 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO Session: 2024-11-21 20:12:41,847 INFO Session(idc.benchmark.Mix2024,53848,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.113696, randomPolicyName -> testPolicy569350, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@62ce2c2d, 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, password -> Pa_ssw0rd, fake-ip -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@1138abc),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007971e4699970@f388e7b,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO HTTP request: 2024-11-21 20:12:41,847 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 20:12:41,847 INFO headers: 2024-11-21 20:12:41,847 INFO accept: application/json 2024-11-21 20:12:41,847 INFO content-type: application/json 2024-11-21 20:12:41,847 INFO 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 2024-11-21 20:12:41,847 INFO X-Forwarded-For: 42.42.42.42 2024-11-21 20:12:41,847 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 20:12:41,847 INFO content-length: 0 2024-11-21 20:12:41,847 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO HTTP response: 2024-11-21 20:12:41,847 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 20:12:41,847 INFO 20:12:16.144 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 20:12:41,847 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 20:12:41,847 INFO Request: 2024-11-21 20:12:41,847 INFO restLoginInitiate: KO j.n.c.ClosedChannelException 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO Session: 2024-11-21 20:12:41,847 INFO Session(idc.benchmark.Mix2024,53849,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.129677, randomPolicyName -> testPolicy315785, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@737d9501, fake-user-agent -> Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9, password -> Pa_ssw0rd, fake-ip -> 5.4.23.167, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@38241aa4),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007971e4699970@f388e7b,io.netty.channel.epoll.EpollEventLoop@5b7ea70d) 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO HTTP request: 2024-11-21 20:12:41,847 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 20:12:41,847 INFO headers: 2024-11-21 20:12:41,847 INFO accept: application/json 2024-11-21 20:12:41,847 INFO content-type: application/json 2024-11-21 20:12:41,847 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9 2024-11-21 20:12:41,847 INFO X-Forwarded-For: 5.4.23.167 2024-11-21 20:12:41,847 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 20:12:41,847 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO HTTP response: 2024-11-21 20:12:41,847 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 20:12:41,847 INFO 20:12:16.144 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 20:12:41,847 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 20:12:41,847 INFO Request: 2024-11-21 20:12:41,847 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO Session: 2024-11-21 20:12:41,847 INFO Session(idc.benchmark.Mix2024,53844,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.3396, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@2753e63b, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"WYSIJgl9qPMgXVozx6cqTyKciXU.*AAJTSQACMDIAAlNLABxlbTZvdkNtVHh6YU5yVU0xNEJrbVA1QnNIbjA9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1732219936010), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=WYSIJgl9qPMgXVozx6cqTyKciXU.*AAJTSQACMDIAAlNLABxlbTZvdkNtVHh6YU5yVU0xNEJrbVA1QnNIbjA9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1732219936010))), password -> Pa_ssw0rd, fake-ip -> 179.219.125.28, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@7bbd8a86, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@6799b963, tokenId -> WYSIJgl9qPMgXVozx6cqTyKciXU.*AAJTSQACMDIAAlNLABxlbTZvdkNtVHh6YU5yVU0xNEJrbVA1QnNIbjA9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007971e4699970@f388e7b,io.netty.channel.epoll.EpollEventLoop@239b0f9d) 2024-11-21 20:12:41,847 INFO ========================= 2024-11-21 20:12:41,847 INFO HTTP request: 2024-11-21 20:12:41,847 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-21 20:12:41,847 INFO headers: 2024-11-21 20:12:41,847 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-21 20:12:41,847 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-21 20:12:41,847 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-21 20:12:41,847 INFO accept: */* 2024-11-21 20:12:41,847 INFO cookie: amlbcookie=01; 9b75a55744995d0=WYSIJgl9qPMgXVozx6cqTyKciXU.*AAJTSQACMDIAAlNLABxlbTZvdkNtVHh6YU5yVU0xNEJrbVA1QnNIbjA9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-21 20:12:41,847 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-21 20:12:41,847 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 20:12:41,847 INFO content-length: 0 2024-11-21 20:12:41,847 INFO cookies: 2024-11-21 20:12:41,848 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 20:12:41,848 INFO 9b75a55744995d0=WYSIJgl9qPMgXVozx6cqTyKciXU.*AAJTSQACMDIAAlNLABxlbTZvdkNtVHh6YU5yVU0xNEJrbVA1QnNIbjA9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 20:12:41,848 INFO ========================= 2024-11-21 20:12:41,848 INFO HTTP response: 2024-11-21 20:12:41,848 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 20:12:41,848 INFO 20:12:16.144 [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-21 20:12:41,848 INFO 20:12:16.144 [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-21 20:12:41,848 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 20:12:41,848 INFO [INFO] BUILD SUCCESS 2024-11-21 20:12:41,848 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 20:12:41,848 INFO [INFO] Total time: 01:00 h 2024-11-21 20:12:41,848 INFO [INFO] Finished at: 2024-11-21T20:12:16Z 2024-11-21 20:12:41,848 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 20:12:41,848 INFO 2024-11-21 20:12:16,233 INFO Gatling simulation run ended successfully 2024-11-21 20:12:41,848 INFO 2024-11-21 20:12:16,233 DEBUG No archive name provided. No archive will be created 2024-11-21 20:12:41,848 INFO ________________________________________________________________________________ [2024-11-21 20:12:41] benchmark-15 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-21 20:12:41,848 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-15/stderr.txt is small (0 lines), printing all lines: 2024-11-21 20:12:41,848 DEBUG ----- output ----- 2024-11-21 20:12:41,848 DEBUG 2024-11-21 20:12:41,848 INFO ________________________________________________________________________________ [2024-11-21 20:12:41] benchmark-15 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-21 20:12:41] benchmark-15 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-21 20:12:41] benchmark-15 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped