--Task-- name: benchmark-80 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-40'] preceding_task: benchmark-40 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 80} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-20 21:09:39] benchmark-80 pre : N/A ________________________________________________________________________________ 2024-11-20 21:09:39 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-20 21:09:39 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-80/stdout.txt Pod log : /results/orders/benchmark-80 2024-11-20 21:09:39,371 INFO 2024-11-20 21:09:39,371 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-20 21:09:39,371 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 21:09:39,644 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 21:09:39,644 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:39,644 DEBUG --- stdout --- 2024-11-20 21:09:39,644 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 21:09:39,644 DEBUG --- stderr --- 2024-11-20 21:09:39,644 DEBUG ________________________________________________________________________________ [2024-11-20 21:09:39] benchmark-80 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-20 21:09:39,644 INFO 2024-11-20 21:09:39,644 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-20 21:09:39,644 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 21:09:39,915 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 21:09:39,915 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:39,915 DEBUG --- stdout --- 2024-11-20 21:09:39,915 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 21:09:39,915 DEBUG --- stderr --- 2024-11-20 21:09:39,915 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-80" --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=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-20 21:09:39] benchmark-80 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-20 21:09:39,915 INFO 2024-11-20 21:09:39,915 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-20 21:09:39,915 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 21:09:40,194 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 21:09:40,194 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:40,194 DEBUG --- stdout --- 2024-11-20 21:09:40,194 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 21:09:40,195 DEBUG --- stderr --- 2024-11-20 21:09:40,195 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/order.json { "name": "benchmark-80", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-80\" --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=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-80" } ________________________________________________________________________________ [2024-11-20 21:09:40] benchmark-80 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-20 21:09:40,198 INFO 2024-11-20 21:09:40,198 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-20 21:09:40,198 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-20 21:09:40,411 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-20 21:09:40,411 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:40,411 DEBUG --- stdout --- 2024-11-20 21:09:40,411 DEBUG WAITING 2024-11-20 21:09:40,411 DEBUG --- stderr --- 2024-11-20 21:09:40,411 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 34 0 --:--:-- --:--:-- --:--:-- 34 ________________________________________________________________________________ [2024-11-20 21:09:40] benchmark-80 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-20 21:09:40,412 INFO 2024-11-20 21:09:40,412 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-20 21:09:40,412 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 21:09:40,682 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 21:09:40,682 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:40,682 DEBUG --- stdout --- 2024-11-20 21:09:40,682 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 21:09:40,682 DEBUG --- stderr --- 2024-11-20 21:09:40,682 DEBUG 2024-11-20 21:09:40,683 INFO 2024-11-20 21:09:40,683 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/03_benchmark-80/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-20 21:09:40,683 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 21:09:42,002 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:42,003 DEBUG --- stdout --- 2024-11-20 21:09:42,003 DEBUG 2024-11-20 21:09:42,003 DEBUG --- stderr --- 2024-11-20 21:09:42,003 DEBUG Order has been successfully forwarded to overseer 2024-11-20 21:09:42 - INFO: Check if Gatling simulation started successfully 2024-11-20 21:09:42,003 INFO 2024-11-20 21:09:42,003 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-20 21:09:42,003 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 21:09:42,273 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 21:09:42,273 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:42,273 DEBUG --- stdout --- 2024-11-20 21:09:42,273 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 21:09:42,273 DEBUG --- stderr --- 2024-11-20 21:09:42,273 DEBUG 2024-11-20 21:09:42,273 INFO 2024-11-20 21:09:42,273 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-80/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-20 21:09:42,273 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-20 21:09:42,991 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-20 21:09:48,713 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-20 21:09:54,440 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-20 21:09:54,441 INFO [loop_until]: OK (rc = 0) 2024-11-20 21:09:54,441 DEBUG --- stdout --- 2024-11-20 21:09:54,441 DEBUG 2024-11-20 21:09:42,783 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpotbdes67 2024-11-20 21:09:42,785 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-80" -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=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -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/tmpotbdes67/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/tmpotbdes67/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-20 21:09:54,441 DEBUG --- stderr --- 2024-11-20 21:09:54,441 DEBUG ________________________________________________________________________________ [2024-11-20 21:09:54] benchmark-80 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 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 07s, 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-20 22:10:03] benchmark-80 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-20 22:10:03,237 INFO 2024-11-20 22:10:03,238 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-20 22:10:03,238 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:03,530 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:03,531 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:03,531 DEBUG --- stdout --- 2024-11-20 22:10:03,531 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:03,531 DEBUG --- stderr --- 2024-11-20 22:10:03,531 DEBUG 2024-11-20 22:10:03,531 INFO 2024-11-20 22:10:03,531 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-20 22:10:03,531 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 22:10:04,287 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:04,287 DEBUG --- stdout --- 2024-11-20 22:10:04,287 DEBUG 2024-11-20 22:10:04,287 DEBUG --- stderr --- 2024-11-20 22:10:04,287 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-20 22:10:04] benchmark-80 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-20 22:10:04 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/order.json 2024-11-20 22:10:04,288 INFO 2024-11-20 22:10:04,288 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-20 22:10:04,288 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:04,563 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:04,563 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:04,563 DEBUG --- stdout --- 2024-11-20 22:10:04,563 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:04,563 DEBUG --- stderr --- 2024-11-20 22:10:04,563 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-20 22:10:04,563 INFO 2024-11-20 22:10:04,563 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-20 22:10:04,564 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:04,835 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:04,835 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:04,835 DEBUG --- stdout --- 2024-11-20 22:10:04,835 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:04,835 DEBUG --- stderr --- 2024-11-20 22:10:04,835 DEBUG 2024-11-20 22:10:04,836 INFO 2024-11-20 22:10:04,836 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-80/rc.txt" ]; then echo "/results/orders/benchmark-80/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-80/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/rc.txt file found" 2024-11-20 22:10:04,836 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 22:10:05,618 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-20 22:10:05,618 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:05,618 DEBUG --- stdout --- 2024-11-20 22:10:05,618 DEBUG /results/orders/benchmark-80/rc.txt file found 2024-11-20 22:10:05,618 DEBUG --- stderr --- 2024-11-20 22:10:05,618 DEBUG 2024-11-20 22:10:05,619 INFO 2024-11-20 22:10:05,619 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-20 22:10:05,619 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:05,890 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:05,890 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:05,890 DEBUG --- stdout --- 2024-11-20 22:10:05,890 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:05,890 DEBUG --- stderr --- 2024-11-20 22:10:05,890 DEBUG 2024-11-20 22:10:05,890 INFO 2024-11-20 22:10:05,891 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-80/rc.txt 2024-11-20 22:10:06,672 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-20 22:10:06,673 DEBUG --- stdout --- 2024-11-20 22:10:06,673 DEBUG 4 /results/orders/benchmark-80/rc.txt 2024-11-20 22:10:06,673 DEBUG --- stderr --- 2024-11-20 22:10:06,673 DEBUG 2024-11-20 22:10:06,673 INFO - Download file (size 4k) 2024-11-20 22:10:06,673 INFO 2024-11-20 22:10:06,673 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-20 22:10:06,673 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:06,947 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:06,947 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:06,947 DEBUG --- stdout --- 2024-11-20 22:10:06,947 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:06,947 DEBUG --- stderr --- 2024-11-20 22:10:06,947 DEBUG source : /results/orders/benchmark-80/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/rc.txt 2024-11-20 22:10:06,947 INFO 2024-11-20 22:10:06,947 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-20 22:10:06,947 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:07,222 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:07,223 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:07,223 DEBUG --- stdout --- 2024-11-20 22:10:07,223 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:07,223 DEBUG --- stderr --- 2024-11-20 22:10:07,223 DEBUG 2024-11-20 22:10:07,223 INFO 2024-11-20 22:10:07,223 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/rc.txt 2024-11-20 22:10:07,223 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-20 22:10:07,968 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:07,968 DEBUG --- stdout --- 2024-11-20 22:10:07,968 DEBUG tar: Removing leading `/' from member names 2024-11-20 22:10:07,968 DEBUG --- stderr --- 2024-11-20 22:10:07,968 DEBUG 2024-11-20 22:10:07,968 INFO 2024-11-20 22:10:07,968 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-20 22:10:07,968 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:08,241 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:08,241 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:08,241 DEBUG --- stdout --- 2024-11-20 22:10:08,241 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:08,241 DEBUG --- stderr --- 2024-11-20 22:10:08,241 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-20 22:10:08,241 INFO 2024-11-20 22:10:08,241 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-20 22:10:08,241 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:08,513 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:08,513 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:08,513 DEBUG --- stdout --- 2024-11-20 22:10:08,513 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:08,513 DEBUG --- stderr --- 2024-11-20 22:10:08,513 DEBUG 2024-11-20 22:10:08,514 INFO 2024-11-20 22:10:08,514 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-80/stderr.txt" ]; then echo "/results/orders/benchmark-80/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-80/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/stderr.txt file found" 2024-11-20 22:10:08,514 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 22:10:09,301 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-20 22:10:09,301 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:09,301 DEBUG --- stdout --- 2024-11-20 22:10:09,301 DEBUG /results/orders/benchmark-80/stderr.txt file found 2024-11-20 22:10:09,301 DEBUG --- stderr --- 2024-11-20 22:10:09,301 DEBUG 2024-11-20 22:10:09,301 INFO 2024-11-20 22:10:09,301 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-20 22:10:09,301 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:09,577 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:09,577 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:09,577 DEBUG --- stdout --- 2024-11-20 22:10:09,577 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:09,577 DEBUG --- stderr --- 2024-11-20 22:10:09,577 DEBUG 2024-11-20 22:10:09,577 INFO 2024-11-20 22:10:09,577 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-80/stderr.txt 2024-11-20 22:10:10,406 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-20 22:10:10,407 DEBUG --- stdout --- 2024-11-20 22:10:10,407 DEBUG 0 /results/orders/benchmark-80/stderr.txt 2024-11-20 22:10:10,407 DEBUG --- stderr --- 2024-11-20 22:10:10,407 DEBUG 2024-11-20 22:10:10,407 INFO - Download file (size 0k) 2024-11-20 22:10:10,407 INFO 2024-11-20 22:10:10,407 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-20 22:10:10,407 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:10,678 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:10,678 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:10,678 DEBUG --- stdout --- 2024-11-20 22:10:10,678 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:10,678 DEBUG --- stderr --- 2024-11-20 22:10:10,678 DEBUG source : /results/orders/benchmark-80/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/stderr.txt 2024-11-20 22:10:10,678 INFO 2024-11-20 22:10:10,678 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-20 22:10:10,678 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:10,950 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:10,950 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:10,950 DEBUG --- stdout --- 2024-11-20 22:10:10,950 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:10,950 DEBUG --- stderr --- 2024-11-20 22:10:10,950 DEBUG 2024-11-20 22:10:10,951 INFO 2024-11-20 22:10:10,951 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/stderr.txt 2024-11-20 22:10:10,951 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-20 22:10:11,695 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:11,695 DEBUG --- stdout --- 2024-11-20 22:10:11,695 DEBUG tar: Removing leading `/' from member names 2024-11-20 22:10:11,695 DEBUG --- stderr --- 2024-11-20 22:10:11,695 DEBUG 2024-11-20 22:10:11,695 INFO 2024-11-20 22:10:11,695 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-20 22:10:11,695 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:11,969 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:11,969 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:11,969 DEBUG --- stdout --- 2024-11-20 22:10:11,969 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:11,969 DEBUG --- stderr --- 2024-11-20 22:10:11,969 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-20 22:10:11,969 INFO 2024-11-20 22:10:11,969 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-20 22:10:11,969 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:12,245 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:12,245 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:12,245 DEBUG --- stdout --- 2024-11-20 22:10:12,245 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:12,245 DEBUG --- stderr --- 2024-11-20 22:10:12,245 DEBUG 2024-11-20 22:10:12,246 INFO 2024-11-20 22:10:12,246 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-80/stdout.txt" ]; then echo "/results/orders/benchmark-80/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-80/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/stdout.txt file found" 2024-11-20 22:10:12,246 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 22:10:13,023 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-20 22:10:13,023 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:13,023 DEBUG --- stdout --- 2024-11-20 22:10:13,024 DEBUG /results/orders/benchmark-80/stdout.txt file found 2024-11-20 22:10:13,024 DEBUG --- stderr --- 2024-11-20 22:10:13,024 DEBUG 2024-11-20 22:10:13,024 INFO 2024-11-20 22:10:13,024 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-20 22:10:13,024 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:13,295 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:13,295 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:13,295 DEBUG --- stdout --- 2024-11-20 22:10:13,295 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:13,295 DEBUG --- stderr --- 2024-11-20 22:10:13,295 DEBUG 2024-11-20 22:10:13,295 INFO 2024-11-20 22:10:13,296 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-80/stdout.txt 2024-11-20 22:10:14,073 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-20 22:10:14,073 DEBUG --- stdout --- 2024-11-20 22:10:14,073 DEBUG 4768 /results/orders/benchmark-80/stdout.txt 2024-11-20 22:10:14,073 DEBUG --- stderr --- 2024-11-20 22:10:14,073 DEBUG 2024-11-20 22:10:14,073 INFO - Download file (size 4768k) 2024-11-20 22:10:14,073 INFO 2024-11-20 22:10:14,073 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-20 22:10:14,073 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:14,348 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:14,348 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:14,348 DEBUG --- stdout --- 2024-11-20 22:10:14,348 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:14,348 DEBUG --- stderr --- 2024-11-20 22:10:14,348 DEBUG source : /results/orders/benchmark-80/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/stdout.txt 2024-11-20 22:10:14,348 INFO 2024-11-20 22:10:14,348 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-20 22:10:14,348 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:14,623 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:14,623 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:14,623 DEBUG --- stdout --- 2024-11-20 22:10:14,623 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:14,623 DEBUG --- stderr --- 2024-11-20 22:10:14,623 DEBUG 2024-11-20 22:10:14,623 INFO 2024-11-20 22:10:14,623 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/stdout.txt 2024-11-20 22:10:14,623 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-20 22:10:15,852 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:15,852 DEBUG --- stdout --- 2024-11-20 22:10:15,852 DEBUG tar: Removing leading `/' from member names 2024-11-20 22:10:15,852 DEBUG --- stderr --- 2024-11-20 22:10:15,852 DEBUG ________________________________________________________________________________ [2024-11-20 22:10:15] benchmark-80 show_cmd : Display order command ________________________________________________________________________________ 2024-11-20 22:10:15,853 INFO 2024-11-20 22:10:15,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-20 22:10:15,853 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:16,125 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:16,126 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:16,127 DEBUG --- stdout --- 2024-11-20 22:10:16,127 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:16,127 DEBUG --- stderr --- 2024-11-20 22:10:16,127 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-20 22:10:16,127 INFO 2024-11-20 22:10:16,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-20 22:10:16,127 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:16,400 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:16,400 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:16,400 DEBUG --- stdout --- 2024-11-20 22:10:16,400 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:16,400 DEBUG --- stderr --- 2024-11-20 22:10:16,400 DEBUG 2024-11-20 22:10:16,401 INFO 2024-11-20 22:10:16,401 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-80/cmd.txt" ]; then echo "/results/orders/benchmark-80/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-80/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/cmd.txt file found" 2024-11-20 22:10:16,401 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 22:10:17,189 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-20 22:10:17,189 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:17,189 DEBUG --- stdout --- 2024-11-20 22:10:17,190 DEBUG /results/orders/benchmark-80/cmd.txt file found 2024-11-20 22:10:17,190 DEBUG --- stderr --- 2024-11-20 22:10:17,190 DEBUG 2024-11-20 22:10:17,190 INFO 2024-11-20 22:10:17,190 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-20 22:10:17,190 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:17,463 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:17,463 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:17,463 DEBUG --- stdout --- 2024-11-20 22:10:17,463 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:17,463 DEBUG --- stderr --- 2024-11-20 22:10:17,463 DEBUG 2024-11-20 22:10:17,463 INFO 2024-11-20 22:10:17,464 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-80/cmd.txt 2024-11-20 22:10:18,248 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-20 22:10:18,248 DEBUG --- stdout --- 2024-11-20 22:10:18,248 DEBUG 4 /results/orders/benchmark-80/cmd.txt 2024-11-20 22:10:18,248 DEBUG --- stderr --- 2024-11-20 22:10:18,248 DEBUG 2024-11-20 22:10:18,248 INFO - Download file (size 4k) 2024-11-20 22:10:18,249 INFO 2024-11-20 22:10:18,249 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-20 22:10:18,249 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:18,521 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:18,521 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:18,521 DEBUG --- stdout --- 2024-11-20 22:10:18,521 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:18,521 DEBUG --- stderr --- 2024-11-20 22:10:18,521 DEBUG source : /results/orders/benchmark-80/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/cmd.txt 2024-11-20 22:10:18,521 INFO 2024-11-20 22:10:18,521 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-20 22:10:18,521 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 22:10:18,795 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 22:10:18,795 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:18,795 DEBUG --- stdout --- 2024-11-20 22:10:18,795 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 22:10:18,795 DEBUG --- stderr --- 2024-11-20 22:10:18,795 DEBUG 2024-11-20 22:10:18,796 INFO 2024-11-20 22:10:18,796 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/cmd.txt 2024-11-20 22:10:18,796 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-20 22:10:19,510 INFO [loop_until]: OK (rc = 0) 2024-11-20 22:10:19,510 DEBUG --- stdout --- 2024-11-20 22:10:19,510 DEBUG tar: Removing leading `/' from member names 2024-11-20 22:10:19,510 DEBUG --- stderr --- 2024-11-20 22:10:19,510 DEBUG 2024-11-20 22:10:19,510 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/cmd.txt is small (1 lines), printing all lines: 2024-11-20 22:10:19,510 DEBUG ----- output ----- 2024-11-20 22:10:19,510 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-80" --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=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=Pa_ssw0rd" 2024-11-20 22:10:19,510 INFO ________________________________________________________________________________ [2024-11-20 22:10:19] benchmark-80 show_rc : Display rc order ________________________________________________________________________________ 2024-11-20 22:10:19,510 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/rc.txt is small (1 lines), printing all lines: 2024-11-20 22:10:19,510 DEBUG ----- output ----- 2024-11-20 22:10:19,510 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-20 22:10:19,510 INFO ________________________________________________________________________________ [2024-11-20 22:10:19] benchmark-80 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-20 22:10:19,517 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/03_benchmark-80/stdout.txt is 56525 lines): 2024-11-20 22:10:19,517 DEBUG ----- output ----- 2024-11-20 22:10:19,517 INFO 2024-11-20 21:09:42,783 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpotbdes67 2024-11-20 22:10:19,517 INFO 2024-11-20 21:09:42,785 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-80" -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=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=**** 2024-11-20 22:10:19,517 INFO [INFO] Scanning for projects... 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-20 22:10:19,517 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-20 22:10:19,517 INFO [INFO] from pom.xml 2024-11-20 22:10:19,517 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-20 22:10:19,517 INFO [INFO] skip non existing resourceDirectory /tmp/tmpotbdes67/src/main/resources 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-20 22:10:19,517 INFO [INFO] No sources to compile 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-20 22:10:19,517 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-20 22:10:19,517 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-20 22:10:19,517 INFO [INFO] compiling 38 Scala sources to /tmp/tmpotbdes67/target/test-classes ... 2024-11-20 22:10:19,517 INFO [INFO] compile in 6.9 s 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] 2024-11-20 22:10:19,517 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-20 22:10:19,517 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-20 22:10:19,517 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-20 22:10:19,517 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-20 22:10:19,517 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-20 22:10:19,517 INFO 2024-11-20 22:10:19,517 INFO ================================================================================ 2024-11-20 22:10:19,517 INFO 2024-11-20 21:09:58 GMT 5s elapsed 2024-11-20 22:10:19,517 INFO ---- Requests ------------------------------------------------------------------ 2024-11-20 22:10:19,517 INFO > Global (OK=391 KO=0 ) 2024-11-20 22:10:19,517 INFO > restLoginInitiate (OK=31 KO=0 ) 2024-11-20 22:10:19,517 INFO > restLoginUsernamePasswordCallback (OK=30 KO=0 ) 2024-11-20 22:10:19,517 INFO > User Authorize PKCE stage (OK=35 KO=0 ) 2024-11-20 22:10:19,517 INFO > User AccessToken PKCE stage (OK=35 KO=0 ) 2024-11-20 22:10:19,517 INFO > tokenUserinfo (OK=3 KO=0 ) 2024-11-20 22:10:19,517 INFO > UI-Post-Login - stage 1 (OK=9 KO=0 ) 2024-11-20 22:10:19,517 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=9 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI AM idFromSession (OK=9 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI AM validateGoto (OK=9 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI-Post-Login - stage 2 (OK=8 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=8 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI Enduser appAuthHelper2 (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI Enduser appAuthHelper1 (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI-Post-Login - stage 3 (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > Skip 2FA (OK=17 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI Enduser sessioncheck (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM uiconfig (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM version (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM privilege (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM features (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM login (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM dashboard (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM managed user schema (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM user (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI IDM oidcToken (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > userinfo (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > GetUUid (OK=10 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI-Logout (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > GetOpenidConfig (OK=10 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI-Logout Redirect 1 (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI AM revoke1 (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI AM revoke2 (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > UI AM endsession (OK=6 KO=0 ) 2024-11-20 22:10:19,518 INFO > CreatePolicy (OK=10 KO=0 ) 2024-11-20 22:10:19,518 INFO > RootUserinfo (OK=7 KO=0 ) 2024-11-20 22:10:19,518 INFO > getIdToken (OK=3 KO=0 ) 2024-11-20 22:10:19,518 INFO > getIdToken Redirect 1 (OK=3 KO=0 ) 2024-11-20 22:10:19,518 INFO > createOrganization (OK=3 KO=0 ) 2024-11-20 22:10:19,518 INFO > queryOrganization (OK=3 KO=0 ) 2024-11-20 22:10:19,518 INFO > deleteOrganization (OK=3 KO=0 ) 2024-11-20 22:10:19,518 INFO > loginTreeWorkflow_restLoginInitiate (OK=2 KO=0 ) 2024-11-20 22:10:19,518 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=1 KO=0 ) 2024-11-20 22:10:19,518 INFO 2024-11-20 22:10:19,518 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-20 22:10:19,518 INFO [- ] 0% 2024-11-20 22:10:19,518 INFO waiting: 289042 / active: 20 / done: 13 2024-11-20 22:10:19,518 INFO ================================================================================ 2024-11-20 22:10:19,518 INFO 2024-11-20 22:10:19,518 INFO 21:09:59.303 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-20 22:10:19,518 INFO 21:09:59.499 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-20 22:10:19,518 INFO 21:10:02.222 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-20 22:10:19,518 INFO 21:10:02.654 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-20 22:10:19,518 INFO 21:10:02.952 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-20 22:10:19,518 INFO 2024-11-20 22:10:19,518 INFO ================================================================================ 2024-11-20 22:10:19,518 INFO 2024-11-20 21:10:03 GMT 10s elapsed 2024-11-20 22:10:19,518 INFO ---- Requests ------------------------------------------------------------------ 2024-11-20 22:10:19,518 INFO > Global (OK=1505 KO=0 ) 2024-11-20 22:10:19,518 INFO > restLoginInitiate (OK=126 KO=0 ) 2024-11-20 22:10:19,518 INFO [...] 2024-11-20 22:10:19,527 INFO Session: 2024-11-20 22:10:19,527 INFO Session(idc.benchmark.Mix2024,286664,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.106682, randomPolicyName -> testPolicy681314, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@30a539b6, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/602.1.50 (KHTML, like Gecko) CriOS/56.0.2924.75 Mobile/14E5239e Safari/602.1, password -> Pa_ssw0rd, fake-ip -> 254.236.100.162, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@649ea03d),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a5cec698000@3acfee0b,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,527 INFO HTTP request: 2024-11-20 22:10:19,527 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-20 22:10:19,527 INFO headers: 2024-11-20 22:10:19,527 INFO accept: application/json 2024-11-20 22:10:19,527 INFO content-type: application/json 2024-11-20 22:10:19,527 INFO user-agent: Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/602.1.50 (KHTML, like Gecko) CriOS/56.0.2924.75 Mobile/14E5239e Safari/602.1 2024-11-20 22:10:19,527 INFO X-Forwarded-For: 254.236.100.162 2024-11-20 22:10:19,527 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,527 INFO content-length: 0 2024-11-20 22:10:19,527 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,527 INFO HTTP response: 2024-11-20 22:10:19,527 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-20 22:10:19,527 INFO 22:09:53.671 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-20 22:10:19,527 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-20 22:10:19,527 INFO Request: 2024-11-20 22:10:19,527 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,527 INFO Session: 2024-11-20 22:10:19,527 INFO Session(idc.benchmark.Mix2024,286633,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.55810, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@246df46c, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"m4oWKLgLuX4kA5oJ7fLHpk-NYC0.*AAJTSQACMDIAAlNLABw4d2dSeFNCMjBIaEhYaUlFNzEzTnM0WWdEU1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1732140593548), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=m4oWKLgLuX4kA5oJ7fLHpk-NYC0.*AAJTSQACMDIAAlNLABw4d2dSeFNCMjBIaEhYaUlFNzEzTnM0WWdEU1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1732140593548))), password -> Pa_ssw0rd, fake-ip -> 39.184.221.64, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@7a35ba37, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@23803f9, tokenId -> m4oWKLgLuX4kA5oJ7fLHpk-NYC0.*AAJTSQACMDIAAlNLABw4d2dSeFNCMjBIaEhYaUlFNzEzTnM0WWdEU1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Linux; Android 8.0.0; Pixel 2 Build/OPD3.170816.012) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a5cec698000@3acfee0b,io.netty.channel.epoll.EpollEventLoop@5b7ea70d) 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,527 INFO HTTP request: 2024-11-20 22:10:19,527 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-20 22:10:19,527 INFO headers: 2024-11-20 22:10:19,527 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-20 22:10:19,527 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-20 22:10:19,527 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-20 22:10:19,527 INFO accept: */* 2024-11-20 22:10:19,527 INFO cookie: amlbcookie=01; 9b75a55744995d0=m4oWKLgLuX4kA5oJ7fLHpk-NYC0.*AAJTSQACMDIAAlNLABw4d2dSeFNCMjBIaEhYaUlFNzEzTnM0WWdEU1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-20 22:10:19,527 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,527 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,527 INFO content-length: 0 2024-11-20 22:10:19,527 INFO cookies: 2024-11-20 22:10:19,527 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-20 22:10:19,527 INFO 9b75a55744995d0=m4oWKLgLuX4kA5oJ7fLHpk-NYC0.*AAJTSQACMDIAAlNLABw4d2dSeFNCMjBIaEhYaUlFNzEzTnM0WWdEU1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,527 INFO HTTP response: 2024-11-20 22:10:19,527 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-20 22:10:19,527 INFO 22:09:53.671 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-20 22:10:19,527 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-20 22:10:19,527 INFO Request: 2024-11-20 22:10:19,527 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,527 INFO Session: 2024-11-20 22:10:19,527 INFO Session(idc.benchmark.Mix2024,286635,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.657, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@72f9a807, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"scZI6hfReegH5dYc1EP8uZTtHp8.*AAJTSQACMDIAAlNLABxTdEcxNWhOOEJNQUk4ZXJQMHdZemZCbWtmNmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1732140593569), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=scZI6hfReegH5dYc1EP8uZTtHp8.*AAJTSQACMDIAAlNLABxTdEcxNWhOOEJNQUk4ZXJQMHdZemZCbWtmNmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1732140593569))), password -> Pa_ssw0rd, fake-ip -> 211.171.162.165, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@4972a78, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@68e3db0b, tokenId -> scZI6hfReegH5dYc1EP8uZTtHp8.*AAJTSQACMDIAAlNLABxTdEcxNWhOOEJNQUk4ZXJQMHdZemZCbWtmNmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, 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/0x00007a5cec698000@3acfee0b,io.netty.channel.epoll.EpollEventLoop@650eab8) 2024-11-20 22:10:19,527 INFO ========================= 2024-11-20 22:10:19,528 INFO HTTP request: 2024-11-20 22:10:19,528 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-20 22:10:19,528 INFO headers: 2024-11-20 22:10:19,528 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-20 22:10:19,528 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-20 22:10:19,528 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-20 22:10:19,528 INFO accept: */* 2024-11-20 22:10:19,528 INFO cookie: amlbcookie=01; 9b75a55744995d0=scZI6hfReegH5dYc1EP8uZTtHp8.*AAJTSQACMDIAAlNLABxTdEcxNWhOOEJNQUk4ZXJQMHdZemZCbWtmNmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-20 22:10:19,528 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,528 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,528 INFO content-length: 0 2024-11-20 22:10:19,528 INFO cookies: 2024-11-20 22:10:19,528 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-20 22:10:19,528 INFO 9b75a55744995d0=scZI6hfReegH5dYc1EP8uZTtHp8.*AAJTSQACMDIAAlNLABxTdEcxNWhOOEJNQUk4ZXJQMHdZemZCbWtmNmM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-20 22:10:19,528 INFO ========================= 2024-11-20 22:10:19,528 INFO HTTP response: 2024-11-20 22:10:19,528 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-20 22:10:19,528 INFO 22:09:53.671 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-20 22:10:19,528 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-20 22:10:19,528 INFO Request: 2024-11-20 22:10:19,528 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-20 22:10:19,528 INFO ========================= 2024-11-20 22:10:19,528 INFO Session: 2024-11-20 22:10:19,528 INFO Session(idc.benchmark.Mix2024,286636,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.18835, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3c5efbff, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"8sMufTPWWP-Z6ooM5-cTu47TRzY.*AAJTSQACMDIAAlNLABw5Tm5IYjJubnBncnFib0JQNjUvbWhPY1ZsM2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1732140593565), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=8sMufTPWWP-Z6ooM5-cTu47TRzY.*AAJTSQACMDIAAlNLABw5Tm5IYjJubnBncnFib0JQNjUvbWhPY1ZsM2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1732140593565))), password -> Pa_ssw0rd, fake-ip -> 137.34.214.34, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@5e4904b, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@2405958, tokenId -> 8sMufTPWWP-Z6ooM5-cTu47TRzY.*AAJTSQACMDIAAlNLABw5Tm5IYjJubnBncnFib0JQNjUvbWhPY1ZsM2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.3),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a5cec698000@3acfee0b,io.netty.channel.epoll.EpollEventLoop@30f5a68a) 2024-11-20 22:10:19,528 INFO ========================= 2024-11-20 22:10:19,528 INFO HTTP request: 2024-11-20 22:10:19,528 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-20 22:10:19,528 INFO headers: 2024-11-20 22:10:19,528 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-20 22:10:19,528 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-20 22:10:19,528 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-20 22:10:19,528 INFO accept: */* 2024-11-20 22:10:19,528 INFO cookie: amlbcookie=01; 9b75a55744995d0=8sMufTPWWP-Z6ooM5-cTu47TRzY.*AAJTSQACMDIAAlNLABw5Tm5IYjJubnBncnFib0JQNjUvbWhPY1ZsM2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-20 22:10:19,528 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,528 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-20 22:10:19,528 INFO content-length: 0 2024-11-20 22:10:19,528 INFO cookies: 2024-11-20 22:10:19,528 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-20 22:10:19,528 INFO 9b75a55744995d0=8sMufTPWWP-Z6ooM5-cTu47TRzY.*AAJTSQACMDIAAlNLABw5Tm5IYjJubnBncnFib0JQNjUvbWhPY1ZsM2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-20 22:10:19,528 INFO ========================= 2024-11-20 22:10:19,528 INFO HTTP response: 2024-11-20 22:10:19,528 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-20 22:10:19,528 INFO 22:09:53.671 [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-20 22:10:19,528 INFO [INFO] ------------------------------------------------------------------------ 2024-11-20 22:10:19,528 INFO [INFO] BUILD SUCCESS 2024-11-20 22:10:19,528 INFO [INFO] ------------------------------------------------------------------------ 2024-11-20 22:10:19,528 INFO [INFO] Total time: 01:00 h 2024-11-20 22:10:19,528 INFO [INFO] Finished at: 2024-11-20T22:09:53Z 2024-11-20 22:10:19,528 INFO [INFO] ------------------------------------------------------------------------ 2024-11-20 22:10:19,528 INFO 2024-11-20 22:09:53,779 INFO Gatling simulation run ended successfully 2024-11-20 22:10:19,528 INFO 2024-11-20 22:09:53,779 DEBUG No archive name provided. No archive will be created 2024-11-20 22:10:19,528 INFO ________________________________________________________________________________ [2024-11-20 22:10:19] benchmark-80 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-20 22:10:19,529 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-80/stderr.txt is small (0 lines), printing all lines: 2024-11-20 22:10:19,529 DEBUG ----- output ----- 2024-11-20 22:10:19,529 DEBUG 2024-11-20 22:10:19,529 INFO ________________________________________________________________________________ [2024-11-20 22:10:19] benchmark-80 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-20 22:10:19] benchmark-80 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-20 22:10:19] benchmark-80 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped