--Task-- name: benchmark-100 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates below loop: False interval: None dependencies: [] wait_for: ['benchmark-90'] preceding_task: benchmark-90 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self100-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 100} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-14 06:30:04] benchmark-100 pre : N/A ________________________________________________________________________________ 2024-11-14 06:30:04 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-14 06:30:04 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-100/stdout.txt Pod log : /results/orders/benchmark-100 2024-11-14 06:30:04,551 INFO 2024-11-14 06:30:04,551 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 06:30:04,551 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 06:30:04,826 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 06:30:04,827 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:04,827 DEBUG --- stdout --- 2024-11-14 06:30:04,827 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 06:30:04,827 DEBUG --- stderr --- 2024-11-14 06:30:04,827 DEBUG ________________________________________________________________________________ [2024-11-14 06:30:04] benchmark-100 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-14 06:30:04,827 INFO 2024-11-14 06:30:04,827 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 06:30:04,827 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 06:30:05,102 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 06:30:05,102 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:05,102 DEBUG --- stdout --- 2024-11-14 06:30:05,102 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 06:30:05,102 DEBUG --- stderr --- 2024-11-14 06:30:05,102 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-100" --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=self100- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=100 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-14 06:30:05] benchmark-100 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-14 06:30:05,102 INFO 2024-11-14 06:30:05,102 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 06:30:05,102 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 06:30:05,379 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 06:30:05,379 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:05,379 DEBUG --- stdout --- 2024-11-14 06:30:05,379 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 06:30:05,379 DEBUG --- stderr --- 2024-11-14 06:30:05,379 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/order.json { "name": "benchmark-100", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-100\" --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=self100- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=100 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-100" } ________________________________________________________________________________ [2024-11-14 06:30:05] benchmark-100 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2024-11-14 06:30:05,382 INFO 2024-11-14 06:30:05,382 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-14 06:30:05,382 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-14 06:30:05,600 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 06:30:05,600 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:05,600 DEBUG --- stdout --- 2024-11-14 06:30:05,600 DEBUG WAITING 2024-11-14 06:30:05,600 DEBUG --- stderr --- 2024-11-14 06:30:05,600 DEBUG % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 33 0 --:--:-- --:--:-- --:--:-- 33 ________________________________________________________________________________ [2024-11-14 06:30:05] benchmark-100 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-14 06:30:05,601 INFO 2024-11-14 06:30:05,601 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 06:30:05,601 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 06:30:05,878 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 06:30:05,878 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:05,878 DEBUG --- stdout --- 2024-11-14 06:30:05,878 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 06:30:05,878 DEBUG --- stderr --- 2024-11-14 06:30:05,878 DEBUG 2024-11-14 06:30:05,879 INFO 2024-11-14 06:30:05,879 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/06_benchmark-100/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-14 06:30:05,879 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 06:30:07,230 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:07,230 DEBUG --- stdout --- 2024-11-14 06:30:07,230 DEBUG 2024-11-14 06:30:07,230 DEBUG --- stderr --- 2024-11-14 06:30:07,230 DEBUG Order has been successfully forwarded to overseer 2024-11-14 06:30:07 - INFO: Check if Gatling simulation started successfully 2024-11-14 06:30:07,230 INFO 2024-11-14 06:30:07,230 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 06:30:07,230 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 06:30:07,508 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 06:30:07,508 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:07,508 DEBUG --- stdout --- 2024-11-14 06:30:07,508 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 06:30:07,508 DEBUG --- stderr --- 2024-11-14 06:30:07,508 DEBUG 2024-11-14 06:30:07,509 INFO 2024-11-14 06:30:07,509 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-100/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-14 06:30:07,509 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-14 06:30:08,230 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-14 06:30:13,956 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-14 06:30:19,683 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-14 06:30:19,683 INFO [loop_until]: OK (rc = 0) 2024-11-14 06:30:19,683 DEBUG --- stdout --- 2024-11-14 06:30:19,683 DEBUG 2024-11-14 06:30:08,043 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpcczsnmck 2024-11-14 06:30:08,044 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-100" -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=self100- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=100 -Duser_password=**** [INFO] Scanning for projects... [INFO] [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- [INFO] Building pyrock-gatling-simulation 3.12.0 [INFO] from pom.xml [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> [INFO] [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- [INFO] skip non existing resourceDirectory /tmp/tmpcczsnmck/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/tmpcczsnmck/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-14 06:30:19,683 DEBUG --- stderr --- 2024-11-14 06:30:19,683 DEBUG ________________________________________________________________________________ [2024-11-14 06:30:19] benchmark-100 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 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-14 07:30:28] benchmark-100 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-14 07:30:28,417 INFO 2024-11-14 07:30:28,417 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:28,417 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:28,733 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:28,733 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:28,733 DEBUG --- stdout --- 2024-11-14 07:30:28,733 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:28,733 DEBUG --- stderr --- 2024-11-14 07:30:28,733 DEBUG 2024-11-14 07:30:28,733 INFO 2024-11-14 07:30:28,733 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- rm -f /results/orders/order.json 2024-11-14 07:30:28,733 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 07:30:29,511 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:29,511 DEBUG --- stdout --- 2024-11-14 07:30:29,511 DEBUG 2024-11-14 07:30:29,511 DEBUG --- stderr --- 2024-11-14 07:30:29,511 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-14 07:30:29] benchmark-100 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-14 07:30:29 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/order.json 2024-11-14 07:30:29,512 INFO 2024-11-14 07:30:29,512 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:29,512 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:29,787 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:29,787 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:29,787 DEBUG --- stdout --- 2024-11-14 07:30:29,787 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:29,788 DEBUG --- stderr --- 2024-11-14 07:30:29,788 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 07:30:29,788 INFO 2024-11-14 07:30:29,788 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:29,788 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:30,062 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:30,062 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:30,062 DEBUG --- stdout --- 2024-11-14 07:30:30,062 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:30,062 DEBUG --- stderr --- 2024-11-14 07:30:30,062 DEBUG 2024-11-14 07:30:30,063 INFO 2024-11-14 07:30:30,063 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-100/rc.txt" ]; then echo "/results/orders/benchmark-100/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-100/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-100/rc.txt file found" 2024-11-14 07:30:30,063 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 07:30:30,855 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 07:30:30,855 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:30,855 DEBUG --- stdout --- 2024-11-14 07:30:30,855 DEBUG /results/orders/benchmark-100/rc.txt file found 2024-11-14 07:30:30,855 DEBUG --- stderr --- 2024-11-14 07:30:30,855 DEBUG 2024-11-14 07:30:30,855 INFO 2024-11-14 07:30:30,856 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:30,856 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:31,132 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:31,132 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:31,132 DEBUG --- stdout --- 2024-11-14 07:30:31,132 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:31,132 DEBUG --- stderr --- 2024-11-14 07:30:31,132 DEBUG 2024-11-14 07:30:31,132 INFO 2024-11-14 07:30:31,132 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-100/rc.txt 2024-11-14 07:30:31,928 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 07:30:31,928 DEBUG --- stdout --- 2024-11-14 07:30:31,928 DEBUG 4 /results/orders/benchmark-100/rc.txt 2024-11-14 07:30:31,928 DEBUG --- stderr --- 2024-11-14 07:30:31,928 DEBUG 2024-11-14 07:30:31,928 INFO - Download file (size 4k) 2024-11-14 07:30:31,929 INFO 2024-11-14 07:30:31,929 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:31,929 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:32,208 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:32,208 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:32,208 DEBUG --- stdout --- 2024-11-14 07:30:32,208 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:32,208 DEBUG --- stderr --- 2024-11-14 07:30:32,208 DEBUG source : /results/orders/benchmark-100/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/rc.txt 2024-11-14 07:30:32,208 INFO 2024-11-14 07:30:32,208 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:32,208 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:32,483 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:32,483 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:32,483 DEBUG --- stdout --- 2024-11-14 07:30:32,483 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:32,483 DEBUG --- stderr --- 2024-11-14 07:30:32,483 DEBUG 2024-11-14 07:30:32,484 INFO 2024-11-14 07:30:32,484 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-100/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/rc.txt 2024-11-14 07:30:32,484 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 07:30:33,238 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:33,238 DEBUG --- stdout --- 2024-11-14 07:30:33,238 DEBUG tar: Removing leading `/' from member names 2024-11-14 07:30:33,238 DEBUG --- stderr --- 2024-11-14 07:30:33,238 DEBUG 2024-11-14 07:30:33,238 INFO 2024-11-14 07:30:33,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-14 07:30:33,238 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:33,514 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:33,514 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:33,514 DEBUG --- stdout --- 2024-11-14 07:30:33,514 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:33,514 DEBUG --- stderr --- 2024-11-14 07:30:33,514 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 07:30:33,514 INFO 2024-11-14 07:30:33,514 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:33,514 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:33,789 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:33,789 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:33,789 DEBUG --- stdout --- 2024-11-14 07:30:33,789 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:33,789 DEBUG --- stderr --- 2024-11-14 07:30:33,789 DEBUG 2024-11-14 07:30:33,790 INFO 2024-11-14 07:30:33,790 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-100/stderr.txt" ]; then echo "/results/orders/benchmark-100/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-100/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-100/stderr.txt file found" 2024-11-14 07:30:33,790 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 07:30:34,578 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 07:30:34,579 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:34,579 DEBUG --- stdout --- 2024-11-14 07:30:34,579 DEBUG /results/orders/benchmark-100/stderr.txt file found 2024-11-14 07:30:34,579 DEBUG --- stderr --- 2024-11-14 07:30:34,579 DEBUG 2024-11-14 07:30:34,579 INFO 2024-11-14 07:30:34,579 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:34,579 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:34,854 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:34,854 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:34,854 DEBUG --- stdout --- 2024-11-14 07:30:34,854 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:34,854 DEBUG --- stderr --- 2024-11-14 07:30:34,854 DEBUG 2024-11-14 07:30:34,854 INFO 2024-11-14 07:30:34,855 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-100/stderr.txt 2024-11-14 07:30:35,644 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 07:30:35,644 DEBUG --- stdout --- 2024-11-14 07:30:35,644 DEBUG 0 /results/orders/benchmark-100/stderr.txt 2024-11-14 07:30:35,644 DEBUG --- stderr --- 2024-11-14 07:30:35,644 DEBUG 2024-11-14 07:30:35,644 INFO - Download file (size 0k) 2024-11-14 07:30:35,644 INFO 2024-11-14 07:30:35,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-14 07:30:35,644 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:35,919 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:35,919 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:35,919 DEBUG --- stdout --- 2024-11-14 07:30:35,919 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:35,919 DEBUG --- stderr --- 2024-11-14 07:30:35,919 DEBUG source : /results/orders/benchmark-100/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/stderr.txt 2024-11-14 07:30:35,919 INFO 2024-11-14 07:30:35,919 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:35,919 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:36,193 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:36,194 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:36,194 DEBUG --- stdout --- 2024-11-14 07:30:36,194 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:36,194 DEBUG --- stderr --- 2024-11-14 07:30:36,194 DEBUG 2024-11-14 07:30:36,194 INFO 2024-11-14 07:30:36,194 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-100/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/stderr.txt 2024-11-14 07:30:36,194 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 07:30:37,012 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:37,013 DEBUG --- stdout --- 2024-11-14 07:30:37,013 DEBUG tar: Removing leading `/' from member names 2024-11-14 07:30:37,013 DEBUG --- stderr --- 2024-11-14 07:30:37,013 DEBUG 2024-11-14 07:30:37,013 INFO 2024-11-14 07:30:37,013 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:37,013 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:37,292 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:37,292 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:37,292 DEBUG --- stdout --- 2024-11-14 07:30:37,292 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:37,292 DEBUG --- stderr --- 2024-11-14 07:30:37,292 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 07:30:37,292 INFO 2024-11-14 07:30:37,292 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:37,292 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:37,582 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:37,583 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:37,583 DEBUG --- stdout --- 2024-11-14 07:30:37,583 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:37,583 DEBUG --- stderr --- 2024-11-14 07:30:37,583 DEBUG 2024-11-14 07:30:37,583 INFO 2024-11-14 07:30:37,583 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-100/stdout.txt" ]; then echo "/results/orders/benchmark-100/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-100/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-100/stdout.txt file found" 2024-11-14 07:30:37,583 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 07:30:38,374 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 07:30:38,374 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:38,374 DEBUG --- stdout --- 2024-11-14 07:30:38,374 DEBUG /results/orders/benchmark-100/stdout.txt file found 2024-11-14 07:30:38,374 DEBUG --- stderr --- 2024-11-14 07:30:38,374 DEBUG 2024-11-14 07:30:38,375 INFO 2024-11-14 07:30:38,375 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:38,375 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:38,650 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:38,650 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:38,650 DEBUG --- stdout --- 2024-11-14 07:30:38,650 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:38,650 DEBUG --- stderr --- 2024-11-14 07:30:38,651 DEBUG 2024-11-14 07:30:38,651 INFO 2024-11-14 07:30:38,651 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-100/stdout.txt 2024-11-14 07:30:39,443 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 07:30:39,443 DEBUG --- stdout --- 2024-11-14 07:30:39,443 DEBUG 125924 /results/orders/benchmark-100/stdout.txt 2024-11-14 07:30:39,443 DEBUG --- stderr --- 2024-11-14 07:30:39,443 DEBUG 2024-11-14 07:30:39,443 INFO - Download file (size 125924k) 2024-11-14 07:30:39,443 INFO 2024-11-14 07:30:39,443 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:39,443 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:39,720 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:39,720 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:39,720 DEBUG --- stdout --- 2024-11-14 07:30:39,720 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:39,720 DEBUG --- stderr --- 2024-11-14 07:30:39,720 DEBUG source : /results/orders/benchmark-100/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/stdout.txt 2024-11-14 07:30:39,720 INFO 2024-11-14 07:30:39,720 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:39,720 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:40,004 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:40,004 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:40,004 DEBUG --- stdout --- 2024-11-14 07:30:40,004 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:40,004 DEBUG --- stderr --- 2024-11-14 07:30:40,004 DEBUG 2024-11-14 07:30:40,004 INFO 2024-11-14 07:30:40,004 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-100/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/stdout.txt 2024-11-14 07:30:40,004 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 07:30:43,944 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:43,944 DEBUG --- stdout --- 2024-11-14 07:30:43,944 DEBUG tar: Removing leading `/' from member names 2024-11-14 07:30:43,944 DEBUG --- stderr --- 2024-11-14 07:30:43,944 DEBUG ________________________________________________________________________________ [2024-11-14 07:30:43] benchmark-100 show_cmd : Display order command ________________________________________________________________________________ 2024-11-14 07:30:43,944 INFO 2024-11-14 07:30:43,944 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:43,945 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:44,217 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:44,218 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:44,218 DEBUG --- stdout --- 2024-11-14 07:30:44,218 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:44,218 DEBUG --- stderr --- 2024-11-14 07:30:44,218 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 07:30:44,218 INFO 2024-11-14 07:30:44,218 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:44,218 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:44,491 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:44,491 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:44,491 DEBUG --- stdout --- 2024-11-14 07:30:44,491 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:44,491 DEBUG --- stderr --- 2024-11-14 07:30:44,491 DEBUG 2024-11-14 07:30:44,492 INFO 2024-11-14 07:30:44,492 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-100/cmd.txt" ]; then echo "/results/orders/benchmark-100/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-100/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-100/cmd.txt file found" 2024-11-14 07:30:44,492 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 07:30:45,282 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 07:30:45,282 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:45,282 DEBUG --- stdout --- 2024-11-14 07:30:45,282 DEBUG /results/orders/benchmark-100/cmd.txt file found 2024-11-14 07:30:45,282 DEBUG --- stderr --- 2024-11-14 07:30:45,282 DEBUG 2024-11-14 07:30:45,282 INFO 2024-11-14 07:30:45,282 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:45,283 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:45,556 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:45,556 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:45,556 DEBUG --- stdout --- 2024-11-14 07:30:45,556 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:45,556 DEBUG --- stderr --- 2024-11-14 07:30:45,556 DEBUG 2024-11-14 07:30:45,556 INFO 2024-11-14 07:30:45,556 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-100/cmd.txt 2024-11-14 07:30:46,351 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 07:30:46,351 DEBUG --- stdout --- 2024-11-14 07:30:46,351 DEBUG 4 /results/orders/benchmark-100/cmd.txt 2024-11-14 07:30:46,351 DEBUG --- stderr --- 2024-11-14 07:30:46,351 DEBUG 2024-11-14 07:30:46,351 INFO - Download file (size 4k) 2024-11-14 07:30:46,351 INFO 2024-11-14 07:30:46,351 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:46,351 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:46,625 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:46,625 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:46,625 DEBUG --- stdout --- 2024-11-14 07:30:46,625 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:46,625 DEBUG --- stderr --- 2024-11-14 07:30:46,625 DEBUG source : /results/orders/benchmark-100/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/cmd.txt 2024-11-14 07:30:46,625 INFO 2024-11-14 07:30:46,625 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-14 07:30:46,625 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 07:30:46,901 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 07:30:46,901 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:46,901 DEBUG --- stdout --- 2024-11-14 07:30:46,901 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 07:30:46,901 DEBUG --- stderr --- 2024-11-14 07:30:46,901 DEBUG 2024-11-14 07:30:46,902 INFO 2024-11-14 07:30:46,902 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-100/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/cmd.txt 2024-11-14 07:30:46,902 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 07:30:47,658 INFO [loop_until]: OK (rc = 0) 2024-11-14 07:30:47,658 DEBUG --- stdout --- 2024-11-14 07:30:47,658 DEBUG tar: Removing leading `/' from member names 2024-11-14 07:30:47,658 DEBUG --- stderr --- 2024-11-14 07:30:47,658 DEBUG 2024-11-14 07:30:47,658 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/cmd.txt is small (1 lines), printing all lines: 2024-11-14 07:30:47,659 DEBUG ----- output ----- 2024-11-14 07:30:47,659 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-100" --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=self100- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=100 -Duser_password=Pa_ssw0rd" 2024-11-14 07:30:47,659 INFO ________________________________________________________________________________ [2024-11-14 07:30:47] benchmark-100 show_rc : Display rc order ________________________________________________________________________________ 2024-11-14 07:30:47,659 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/rc.txt is small (1 lines), printing all lines: 2024-11-14 07:30:47,659 DEBUG ----- output ----- 2024-11-14 07:30:47,659 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-14 07:30:47,659 INFO ________________________________________________________________________________ [2024-11-14 07:30:47] benchmark-100 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-14 07:30:47,803 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/06_benchmark-100/stdout.txt is 1169920 lines): 2024-11-14 07:30:47,803 DEBUG ----- output ----- 2024-11-14 07:30:47,803 INFO 2024-11-14 06:30:08,043 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpcczsnmck 2024-11-14 07:30:47,803 INFO 2024-11-14 06:30:08,044 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-100" -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=self100- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=100 -Duser_password=**** 2024-11-14 07:30:47,803 INFO [INFO] Scanning for projects... 2024-11-14 07:30:47,803 INFO [INFO] 2024-11-14 07:30:47,803 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-14 07:30:47,803 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-14 07:30:47,804 INFO [INFO] from pom.xml 2024-11-14 07:30:47,804 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-14 07:30:47,804 INFO [INFO] skip non existing resourceDirectory /tmp/tmpcczsnmck/src/main/resources 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-14 07:30:47,804 INFO [INFO] No sources to compile 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-14 07:30:47,804 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-14 07:30:47,804 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-14 07:30:47,804 INFO [INFO] compiling 38 Scala sources to /tmp/tmpcczsnmck/target/test-classes ... 2024-11-14 07:30:47,804 INFO [INFO] compile in 6.8 s 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] 2024-11-14 07:30:47,804 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-14 07:30:47,804 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-14 07:30:47,804 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-14 07:30:47,804 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-14 07:30:47,804 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-14 07:30:47,804 INFO 06:30:20.905 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,804 INFO 2024-11-14 07:30:47,804 INFO ================================================================================ 2024-11-14 07:30:47,804 INFO 2024-11-14 06:30:23 GMT 5s elapsed 2024-11-14 07:30:47,804 INFO ---- Requests ------------------------------------------------------------------ 2024-11-14 07:30:47,804 INFO > Global (OK=455 KO=0 ) 2024-11-14 07:30:47,804 INFO > restLoginInitiate (OK=41 KO=0 ) 2024-11-14 07:30:47,804 INFO > restLoginUsernamePasswordCallback (OK=39 KO=0 ) 2024-11-14 07:30:47,804 INFO > Skip 2FA (OK=25 KO=0 ) 2024-11-14 07:30:47,804 INFO > User Authorize PKCE stage (OK=44 KO=0 ) 2024-11-14 07:30:47,804 INFO > User AccessToken PKCE stage (OK=43 KO=0 ) 2024-11-14 07:30:47,804 INFO > GetUUid (OK=13 KO=0 ) 2024-11-14 07:30:47,804 INFO > GetOpenidConfig (OK=13 KO=0 ) 2024-11-14 07:30:47,804 INFO > CreatePolicy (OK=13 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI-Post-Login - stage 1 (OK=9 KO=0 ) 2024-11-14 07:30:47,804 INFO > RootUserinfo (OK=13 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI AM idFromSession (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI AM validateGoto (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI-Post-Login - stage 2 (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI Enduser appAuthHelper1 (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI Enduser appAuthHelper2 (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > getIdToken (OK=4 KO=0 ) 2024-11-14 07:30:47,804 INFO > getIdToken Redirect 1 (OK=4 KO=0 ) 2024-11-14 07:30:47,804 INFO > createOrganization (OK=3 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI-Post-Login - stage 3 (OK=8 KO=0 ) 2024-11-14 07:30:47,804 INFO > queryOrganization (OK=3 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=7 KO=0 ) 2024-11-14 07:30:47,804 INFO > deleteOrganization (OK=2 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI Enduser sessioncheck (OK=7 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI IDM uiconfig (OK=7 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI IDM version (OK=7 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI IDM privilege (OK=7 KO=0 ) 2024-11-14 07:30:47,804 INFO > UI IDM features (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI IDM login (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI IDM dashboard (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI IDM user (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI IDM managed user schema (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI IDM oidcToken (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > userinfo (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI-Logout (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI-Logout Redirect 1 (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI AM endsession (OK=6 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI AM revoke1 (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > UI AM revoke2 (OK=7 KO=0 ) 2024-11-14 07:30:47,805 INFO > tokenUserinfo (OK=3 KO=0 ) 2024-11-14 07:30:47,805 INFO > restloginProgressiveProfileCallback (OK=1 KO=0 ) 2024-11-14 07:30:47,805 INFO ---- Errors -------------------------------------------------------------------- 2024-11-14 07:30:47,805 INFO > tokenUserinfo: No attribute named 'access_token' is defined 1 (100.0%) 2024-11-14 07:30:47,805 INFO 2024-11-14 07:30:47,805 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-14 07:30:47,805 INFO [- ] 0% 2024-11-14 07:30:47,805 INFO waiting: 360690 / active: 29 / done: 12 2024-11-14 07:30:47,805 INFO ================================================================================ 2024-11-14 07:30:47,805 INFO 2024-11-14 07:30:47,805 INFO 06:30:24.206 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 06:30:24.682 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 06:30:25.141 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 06:30:25.784 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 06:30:27.403 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 06:30:28.680 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 06:30:28.688 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 07:30:47,805 INFO 2024-11-14 07:30:47,805 INFO ================================================================================ 2024-11-14 07:30:47,805 INFO [...] 2024-11-14 07:30:47,998 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 07:30:47,998 INFO Request: 2024-11-14 07:30:47,998 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO Session: 2024-11-14 07:30:47,998 INFO Session(idc.benchmark.Mix2024,357615,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.78203, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@5b82b8a0, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1, password -> Pa_ssw0rd, fake-ip -> 64.74.147.144, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@4476cfde),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d943069a0e0@668b2c1b,io.netty.channel.epoll.EpollEventLoop@4e28bdd1) 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO HTTP request: 2024-11-14 07:30:47,998 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-14 07:30:47,998 INFO headers: 2024-11-14 07:30:47,998 INFO accept: application/json 2024-11-14 07:30:47,998 INFO content-type: application/json 2024-11-14 07:30:47,998 INFO user-agent: Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1 2024-11-14 07:30:47,998 INFO X-Forwarded-For: 64.74.147.144 2024-11-14 07:30:47,998 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 07:30:47,998 INFO content-length: 0 2024-11-14 07:30:47,998 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO HTTP response: 2024-11-14 07:30:47,998 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 07:30:47,998 INFO 07:30:18.739 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-133' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-14 07:30:47,998 INFO 07:30:18.739 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request ' UI IDM features' failed for user 355320: j.i.IOException: Premature close 2024-11-14 07:30:47,998 INFO 07:30:18.739 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 07:30:47,998 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 07:30:47,998 INFO Request: 2024-11-14 07:30:47,998 INFO UI IDM features: KO j.i.IOException: Premature close 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO Session: 2024-11-14 07:30:47,998 INFO Session(idc.benchmark.Mix2024,355320,HashMap(access_token -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJlY2QyYjFjYi05M2NjLTRiYjQtOWI1OS04ZDA4OTAyY2I5NGYiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMDdmNTQxOWYtOTZkNS00ZDM3LWJmOTgtYzU4ODYxMzA3NjhmLTExMzc2OTc1MCIsInN1Ym5hbWUiOiJlY2QyYjFjYi05M2NjLTRiYjQtOWI1OS04ZDA4OTAyY2I5NGYiLCJpc3MiOiJodHRwczovL29wZW5hbS1wZXJmLWJlbmNobWFyay5mb3JnZWJsb2Nrcy5jb206NDQzL2FtL29hdXRoMi9yZWFsbXMvcm9vdC9yZWFsbXMvYWxwaGEiLCJ0b2tlbk5hbWUiOiJhY2Nlc3NfdG9rZW4iLCJ0b2tlbl90eXBlIjoiQmVhcmVyIiwiYXV0aEdyYW50SWQiOiJqS2JsT2hocktaU1NDWG9QRndSOVptQnVObDAiLCJub25jZSI6IjEyMzQiLCJjbGllbnRfaWQiOiJlbmRVc2VyVUlDbGllbnQiLCJhdWQiOiJlbmRVc2VyVUlDbGllbnQiLCJuYmYiOjE3MzE1Njk0MDksImdyYW50X3R5cGUiOiJhdXRob3JpemF0aW9uX2NvZGUiLCJzY29wZSI6WyJvcGVuaWQiLCJmcjppZG06KiJdLCJhdXRoX3RpbWUiOjE3MzE1NjkzOTgsInJlYWxtIjoiL2FscGhhIiwiZXhwIjoxNzMxNTczMDA5LCJpYXQiOjE3MzE1Njk0MDksImV4cGlyZXNfaW4iOjM2MDAsImp0aSI6IlBmRnE3a2Jzdnk4eDVSRnJZNFVWTHNhWUpYTSJ9.vBWjZggOiE8745TVgLj2lje2CuF1-Y-QTyXpGV3kkAI, username -> user.115796, access_token_2 -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJlY2QyYjFjYi05M2NjLTRiYjQtOWI1OS04ZDA4OTAyY2I5NGYiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiYTA2NGI3YzctNmJiYS00Y2MwLTg3ZTgtM2RhY2IxODliOTNkLTExMjAyMjEyNSIsInN1Ym5hbWUiOiJlY2QyYjFjYi05M2NjLTRiYjQtOWI1OS04ZDA4OTAyY2I5NGYiLCJpc3MiOiJodHRwczovL29wZW5hbS1wZXJmLWJlbmNobWFyay5mb3JnZWJsb2Nrcy5jb206NDQzL2FtL29hdXRoMi9yZWFsbXMvcm9vdC9yZWFsbXMvYWxwaGEiLCJ0b2tlbk5hbWUiOiJhY2Nlc3NfdG9rZW4iLCJ0b2tlbl90eXBlIjoiQmVhcmVyIiwiYXV0aEdyYW50SWQiOiJuUTltVVdmUGN4TWc3aEl5UklOSUFuTzVJWWMiLCJub25jZSI6IjEyMzQiLCJjbGllbnRfaWQiOiJlbmRVc2VyVUlDbGllbnQiLCJhdWQiOiJlbmRVc2VyVUlDbGllbnQiLCJuYmYiOjE3MzE1Njk0MTMsImdyYW50X3R5cGUiOiJhdXRob3JpemF0aW9uX2NvZGUiLCJzY29wZSI6WyJmcjppZG06KiJdLCJhdXRoX3RpbWUiOjE3MzE1NjkzOTgsInJlYWxtIjoiL2FscGhhIiwiZXhwIjoxNzMxNTczMDEzLCJpYXQiOjE3MzE1Njk0MTMsImV4cGlyZXNfaW4iOjM2MDAsImp0aSI6InlkNUtYRmFVc21iVTRuYWxPb3k4N2lhUnphNCJ9.b3NAMphlwRdLNgKqqMc4kznvznHIUSWnZZyp8Plqg3U, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3a111fa7, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, authcode -> -SMW8sFkg_nGGFEblyjv0Nl92Q4, callbacks -> {"tokenId":"vpCOX1QYYlom7wGtUV2YYqM9cMY.*AAJTSQACMDIAAlNLABxlTlJsbzJoNVlQb2QvdFpCZUluTHRjYzl2RGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1731569398445), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=vpCOX1QYYlom7wGtUV2YYqM9cMY.*AAJTSQACMDIAAlNLABxlTlJsbzJoNVlQb2QvdFpCZUluTHRjYzl2RGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731569398445))), user_uuid -> ecd2b1cb-93cc-4bb4-9b59-8d08902cb94f, password -> Pa_ssw0rd, challenge -> Ww8B7tzE-BGVm1teS4hMr_s0mE7xYFrDKWWpy-HStnc, gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, fake-ip -> 192.166.220.63, verifier -> NjcxOTYzOTA4NjcxNjcwNTU3Nw, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@15fd69bc, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@7aab5e, tokenId -> vpCOX1QYYlom7wGtUV2YYqM9cMY.*AAJTSQACMDIAAlNLABxlTlJsbzJoNVlQb2QvdFpCZUluTHRjYzl2RGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, 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/0x00007d943069a0e0@668b2c1b,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO HTTP request: 2024-11-14 07:30:47,998 INFO GET https://openam-perf-benchmark.forgeblocks.com/openidm/info/features?_queryFilter=true 2024-11-14 07:30:47,998 INFO headers: 2024-11-14 07:30:47,998 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 12_5_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36 2024-11-14 07:30:47,998 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-14 07:30:47,998 INFO Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJlY2QyYjFjYi05M2NjLTRiYjQtOWI1OS04ZDA4OTAyY2I5NGYiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiYTA2NGI3YzctNmJiYS00Y2MwLTg3ZTgtM2RhY2IxODliOTNkLTExMjAyMjEyNSIsInN1Ym5hbWUiOiJlY2QyYjFjYi05M2NjLTRiYjQtOWI1OS04ZDA4OTAyY2I5NGYiLCJpc3MiOiJodHRwczovL29wZW5hbS1wZXJmLWJlbmNobWFyay5mb3JnZWJsb2Nrcy5jb206NDQzL2FtL29hdXRoMi9yZWFsbXMvcm9vdC9yZWFsbXMvYWxwaGEiLCJ0b2tlbk5hbWUiOiJhY2Nlc3NfdG9rZW4iLCJ0b2tlbl90eXBlIjoiQmVhcmVyIiwiYXV0aEdyYW50SWQiOiJuUTltVVdmUGN4TWc3aEl5UklOSUFuTzVJWWMiLCJub25jZSI6IjEyMzQiLCJjbGllbnRfaWQiOiJlbmRVc2VyVUlDbGllbnQiLCJhdWQiOiJlbmRVc2VyVUlDbGllbnQiLCJuYmYiOjE3MzE1Njk0MTMsImdyYW50X3R5cGUiOiJhdXRob3JpemF0aW9uX2NvZGUiLCJzY29wZSI6WyJmcjppZG06KiJdLCJhdXRoX3RpbWUiOjE3MzE1NjkzOTgsInJlYWxtIjoiL2FscGhhIiwiZXhwIjoxNzMxNTczMDEzLCJpYXQiOjE3MzE1Njk0MTMsImV4cGlyZXNfaW4iOjM2MDAsImp0aSI6InlkNUtYRmFVc21iVTRuYWxPb3k4N2lhUnphNCJ9.b3NAMphlwRdLNgKqqMc4kznvznHIUSWnZZyp8Plqg3U 2024-11-14 07:30:47,998 INFO Accept-Api-Version: 2024-11-14 07:30:47,998 INFO accept: */* 2024-11-14 07:30:47,998 INFO cookie: amlbcookie=01; 9b75a55744995d0=vpCOX1QYYlom7wGtUV2YYqM9cMY.*AAJTSQACMDIAAlNLABxlTlJsbzJoNVlQb2QvdFpCZUluTHRjYzl2RGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-14 07:30:47,998 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 07:30:47,998 INFO cookies: 2024-11-14 07:30:47,998 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 07:30:47,998 INFO 9b75a55744995d0=vpCOX1QYYlom7wGtUV2YYqM9cMY.*AAJTSQACMDIAAlNLABxlTlJsbzJoNVlQb2QvdFpCZUluTHRjYzl2RGM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO HTTP response: 2024-11-14 07:30:47,998 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 07:30:47,998 INFO 07:30:18.739 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 357335: j.i.IOException: Premature close 2024-11-14 07:30:47,998 INFO 07:30:18.739 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 07:30:47,998 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 07:30:47,998 INFO Request: 2024-11-14 07:30:47,998 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-14 07:30:47,998 INFO ========================= 2024-11-14 07:30:47,998 INFO Session: 2024-11-14 07:30:47,999 INFO Session(idc.benchmark.Mix2024,357335,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.167701, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@30808106, 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 -> 10.70.108.140, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@3e1766d0),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d943069a0e0@668b2c1b,io.netty.channel.epoll.EpollEventLoop@1eb6749b) 2024-11-14 07:30:47,999 INFO ========================= 2024-11-14 07:30:47,999 INFO HTTP request: 2024-11-14 07:30:47,999 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-14 07:30:47,999 INFO headers: 2024-11-14 07:30:47,999 INFO accept: application/json 2024-11-14 07:30:47,999 INFO content-type: application/json 2024-11-14 07:30:47,999 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-14 07:30:47,999 INFO X-Forwarded-For: 10.70.108.140 2024-11-14 07:30:47,999 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 07:30:47,999 INFO content-length: 0 2024-11-14 07:30:47,999 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-14 07:30:47,999 INFO ========================= 2024-11-14 07:30:47,999 INFO HTTP response: 2024-11-14 07:30:47,999 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 07:30:47,999 INFO 07:30:18.739 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-163' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-14 07:30:47,999 INFO 07:30:18.740 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 357656: j.i.IOException: Premature close 2024-11-14 07:30:47,999 INFO 07:30:18.740 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 07:30:47,999 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 07:30:47,999 INFO Request: 2024-11-14 07:30:47,999 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-14 07:30:47,999 INFO ========================= 2024-11-14 07:30:47,999 INFO Session: 2024-11-14 07:30:47,999 INFO Session(idc.benchmark.Mix2024,357656,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.137739, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@75207b2, 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 -> 20.58.186.49, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@799c2e6d),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d943069a0e0@668b2c1b,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-14 07:30:47,999 INFO ========================= 2024-11-14 07:30:47,999 INFO HTTP request: 2024-11-14 07:30:47,999 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate 2024-11-14 07:30:47,999 INFO headers: 2024-11-14 07:30:47,999 INFO accept: application/json 2024-11-14 07:30:47,999 INFO content-type: application/json 2024-11-14 07:30:47,999 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-14 07:30:47,999 INFO X-Forwarded-For: 20.58.186.49 2024-11-14 07:30:47,999 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 07:30:47,999 INFO content-length: 0 2024-11-14 07:30:47,999 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-14 07:30:47,999 INFO ========================= 2024-11-14 07:30:47,999 INFO HTTP response: 2024-11-14 07:30:47,999 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 07:30:47,999 INFO 07:30:18.740 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-190' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-14 07:30:47,999 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 07:30:47,999 INFO [INFO] BUILD SUCCESS 2024-11-14 07:30:47,999 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 07:30:47,999 INFO [INFO] Total time: 01:00 h 2024-11-14 07:30:47,999 INFO [INFO] Finished at: 2024-11-14T07:30:18Z 2024-11-14 07:30:47,999 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 07:30:47,999 INFO 2024-11-14 07:30:18,946 INFO Gatling simulation run ended successfully 2024-11-14 07:30:47,999 INFO 2024-11-14 07:30:18,946 DEBUG No archive name provided. No archive will be created 2024-11-14 07:30:47,999 INFO ________________________________________________________________________________ [2024-11-14 07:30:47] benchmark-100 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-14 07:30:47,999 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-100/stderr.txt is small (0 lines), printing all lines: 2024-11-14 07:30:47,999 DEBUG ----- output ----- 2024-11-14 07:30:47,999 DEBUG 2024-11-14 07:30:48,000 INFO ________________________________________________________________________________ [2024-11-14 07:30:48] benchmark-100 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-11-14 07:30:49] benchmark-100 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-14 07:30:49] benchmark-100 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped