--Task-- name: benchmark-35 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-30'] preceding_task: benchmark-30 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 35} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-21 22:14:04] benchmark-35 pre : N/A ________________________________________________________________________________ 2024-11-21 22:14:04 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-21 22:14:04 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-35/stdout.txt Pod log : /results/orders/benchmark-35 2024-11-21 22:14:04,341 INFO 2024-11-21 22:14:04,341 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 22:14:04,341 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 22:14:04,614 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 22:14:04,614 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:04,614 DEBUG --- stdout --- 2024-11-21 22:14:04,615 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 22:14:04,615 DEBUG --- stderr --- 2024-11-21 22:14:04,615 DEBUG ________________________________________________________________________________ [2024-11-21 22:14:04] benchmark-35 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-21 22:14:04,615 INFO 2024-11-21 22:14:04,615 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 22:14:04,615 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 22:14:04,885 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 22:14:04,885 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:04,885 DEBUG --- stdout --- 2024-11-21 22:14:04,885 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 22:14:04,885 DEBUG --- stderr --- 2024-11-21 22:14:04,885 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-35" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=35 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-21 22:14:04] benchmark-35 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-21 22:14:04,886 INFO 2024-11-21 22:14:04,886 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 22:14:04,886 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 22:14:05,156 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 22:14:05,156 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:05,156 DEBUG --- stdout --- 2024-11-21 22:14:05,156 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 22:14:05,156 DEBUG --- stderr --- 2024-11-21 22:14:05,156 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/order.json { "name": "benchmark-35", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-35\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=35 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-35" } ________________________________________________________________________________ [2024-11-21 22:14:05] benchmark-35 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2024-11-21 22:14:05,159 INFO 2024-11-21 22:14:05,159 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-21 22:14:05,159 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 22:14:05,372 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 22:14:05,373 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:05,373 DEBUG --- stdout --- 2024-11-21 22:14:05,373 DEBUG WAITING 2024-11-21 22:14:05,373 DEBUG --- stderr --- 2024-11-21 22:14:05,373 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-21 22:14:05] benchmark-35 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-21 22:14:05,373 INFO 2024-11-21 22:14:05,373 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 22:14:05,373 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 22:14:05,645 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 22:14:05,645 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:05,645 DEBUG --- stdout --- 2024-11-21 22:14:05,645 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 22:14:05,645 DEBUG --- stderr --- 2024-11-21 22:14:05,645 DEBUG 2024-11-21 22:14:05,645 INFO 2024-11-21 22:14:05,645 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/05_benchmark-35/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-21 22:14:05,645 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 22:14:06,966 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:06,966 DEBUG --- stdout --- 2024-11-21 22:14:06,966 DEBUG 2024-11-21 22:14:06,966 DEBUG --- stderr --- 2024-11-21 22:14:06,966 DEBUG Order has been successfully forwarded to overseer 2024-11-21 22:14:06 - INFO: Check if Gatling simulation started successfully 2024-11-21 22:14:06,967 INFO 2024-11-21 22:14:06,967 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 22:14:06,967 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 22:14:07,239 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 22:14:07,239 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:07,239 DEBUG --- stdout --- 2024-11-21 22:14:07,239 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 22:14:07,239 DEBUG --- stderr --- 2024-11-21 22:14:07,239 DEBUG 2024-11-21 22:14:07,239 INFO 2024-11-21 22:14:07,239 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-35/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-21 22:14:07,239 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 22:14:07,953 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 22:14:13,667 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 22:14:19,375 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-21 22:14:19,375 INFO [loop_until]: OK (rc = 0) 2024-11-21 22:14:19,375 DEBUG --- stdout --- 2024-11-21 22:14:19,375 DEBUG 2024-11-21 22:14:07,789 DEBUG Creating results folder /results/gatling/benchmark-35 2024-11-21 22:14:07,797 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmprnc120tw 2024-11-21 22:14:07,798 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-35" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=35 -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/tmprnc120tw/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/tmprnc120tw/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-21 22:14:19,375 DEBUG --- stderr --- 2024-11-21 22:14:19,375 DEBUG ________________________________________________________________________________ [2024-11-21 22:14:19] benchmark-35 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 04s, retry Order is running since 36m 05s, retry Order is running since 38m 05s, retry Order is running since 40m 05s, retry Order is running since 42m 06s, retry Order is running since 44m 06s, retry Order is running since 46m 06s, retry Order is running since 48m 06s, retry Order is running since 50m 07s, retry Order is running since 52m 07s, retry Order is running since 54m 07s, retry Order is running since 56m 08s, retry Order is running since 58m 08s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-21 23:14:28] benchmark-35 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-21 23:14:28,068 INFO 2024-11-21 23:14:28,068 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:28,068 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:28,383 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:28,383 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:28,383 DEBUG --- stdout --- 2024-11-21 23:14:28,383 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:28,384 DEBUG --- stderr --- 2024-11-21 23:14:28,384 DEBUG 2024-11-21 23:14:28,384 INFO 2024-11-21 23:14:28,384 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- rm -f /results/orders/order.json 2024-11-21 23:14:28,384 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 23:14:29,154 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:29,154 DEBUG --- stdout --- 2024-11-21 23:14:29,154 DEBUG 2024-11-21 23:14:29,154 DEBUG --- stderr --- 2024-11-21 23:14:29,154 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-21 23:14:29] benchmark-35 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-21 23:14:29 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/order.json 2024-11-21 23:14:29,155 INFO 2024-11-21 23:14:29,155 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:29,155 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:29,427 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:29,427 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:29,427 DEBUG --- stdout --- 2024-11-21 23:14:29,427 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:29,427 DEBUG --- stderr --- 2024-11-21 23:14:29,427 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 23:14:29,427 INFO 2024-11-21 23:14:29,428 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:29,428 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:29,717 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:29,717 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:29,717 DEBUG --- stdout --- 2024-11-21 23:14:29,717 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:29,717 DEBUG --- stderr --- 2024-11-21 23:14:29,717 DEBUG 2024-11-21 23:14:29,718 INFO 2024-11-21 23:14:29,718 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-35/rc.txt" ]; then echo "/results/orders/benchmark-35/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-35/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-35/rc.txt file found" 2024-11-21 23:14:29,718 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 23:14:30,499 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 23:14:30,499 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:30,499 DEBUG --- stdout --- 2024-11-21 23:14:30,499 DEBUG /results/orders/benchmark-35/rc.txt file found 2024-11-21 23:14:30,499 DEBUG --- stderr --- 2024-11-21 23:14:30,499 DEBUG 2024-11-21 23:14:30,499 INFO 2024-11-21 23:14:30,500 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:30,500 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:30,775 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:30,775 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:30,775 DEBUG --- stdout --- 2024-11-21 23:14:30,775 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:30,775 DEBUG --- stderr --- 2024-11-21 23:14:30,775 DEBUG 2024-11-21 23:14:30,775 INFO 2024-11-21 23:14:30,775 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-35/rc.txt 2024-11-21 23:14:31,556 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 23:14:31,556 DEBUG --- stdout --- 2024-11-21 23:14:31,556 DEBUG 4 /results/orders/benchmark-35/rc.txt 2024-11-21 23:14:31,556 DEBUG --- stderr --- 2024-11-21 23:14:31,556 DEBUG 2024-11-21 23:14:31,556 INFO - Download file (size 4k) 2024-11-21 23:14:31,557 INFO 2024-11-21 23:14:31,557 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:31,557 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:31,830 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:31,830 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:31,830 DEBUG --- stdout --- 2024-11-21 23:14:31,830 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:31,830 DEBUG --- stderr --- 2024-11-21 23:14:31,830 DEBUG source : /results/orders/benchmark-35/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/rc.txt 2024-11-21 23:14:31,830 INFO 2024-11-21 23:14:31,830 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:31,830 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:32,101 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:32,102 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:32,102 DEBUG --- stdout --- 2024-11-21 23:14:32,102 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:32,102 DEBUG --- stderr --- 2024-11-21 23:14:32,102 DEBUG 2024-11-21 23:14:32,102 INFO 2024-11-21 23:14:32,102 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-35/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/rc.txt 2024-11-21 23:14:32,102 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 23:14:32,814 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:32,814 DEBUG --- stdout --- 2024-11-21 23:14:32,814 DEBUG tar: Removing leading `/' from member names 2024-11-21 23:14:32,814 DEBUG --- stderr --- 2024-11-21 23:14:32,814 DEBUG 2024-11-21 23:14:32,815 INFO 2024-11-21 23:14:32,815 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:32,815 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:33,091 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:33,091 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:33,091 DEBUG --- stdout --- 2024-11-21 23:14:33,091 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:33,091 DEBUG --- stderr --- 2024-11-21 23:14:33,091 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 23:14:33,092 INFO 2024-11-21 23:14:33,092 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:33,092 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:33,364 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:33,364 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:33,364 DEBUG --- stdout --- 2024-11-21 23:14:33,364 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:33,364 DEBUG --- stderr --- 2024-11-21 23:14:33,364 DEBUG 2024-11-21 23:14:33,365 INFO 2024-11-21 23:14:33,365 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-35/stderr.txt" ]; then echo "/results/orders/benchmark-35/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-35/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-35/stderr.txt file found" 2024-11-21 23:14:33,365 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 23:14:34,152 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 23:14:34,152 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:34,152 DEBUG --- stdout --- 2024-11-21 23:14:34,152 DEBUG /results/orders/benchmark-35/stderr.txt file found 2024-11-21 23:14:34,152 DEBUG --- stderr --- 2024-11-21 23:14:34,152 DEBUG 2024-11-21 23:14:34,152 INFO 2024-11-21 23:14:34,152 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:34,153 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:34,425 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:34,425 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:34,425 DEBUG --- stdout --- 2024-11-21 23:14:34,425 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:34,425 DEBUG --- stderr --- 2024-11-21 23:14:34,425 DEBUG 2024-11-21 23:14:34,425 INFO 2024-11-21 23:14:34,425 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-35/stderr.txt 2024-11-21 23:14:35,203 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 23:14:35,203 DEBUG --- stdout --- 2024-11-21 23:14:35,203 DEBUG 0 /results/orders/benchmark-35/stderr.txt 2024-11-21 23:14:35,203 DEBUG --- stderr --- 2024-11-21 23:14:35,203 DEBUG 2024-11-21 23:14:35,203 INFO - Download file (size 0k) 2024-11-21 23:14:35,203 INFO 2024-11-21 23:14:35,203 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:35,203 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:35,474 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:35,474 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:35,474 DEBUG --- stdout --- 2024-11-21 23:14:35,474 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:35,474 DEBUG --- stderr --- 2024-11-21 23:14:35,474 DEBUG source : /results/orders/benchmark-35/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/stderr.txt 2024-11-21 23:14:35,474 INFO 2024-11-21 23:14:35,474 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:35,474 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:35,746 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:35,746 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:35,746 DEBUG --- stdout --- 2024-11-21 23:14:35,746 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:35,746 DEBUG --- stderr --- 2024-11-21 23:14:35,746 DEBUG 2024-11-21 23:14:35,747 INFO 2024-11-21 23:14:35,747 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-35/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/stderr.txt 2024-11-21 23:14:35,747 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 23:14:36,487 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:36,488 DEBUG --- stdout --- 2024-11-21 23:14:36,488 DEBUG tar: Removing leading `/' from member names 2024-11-21 23:14:36,488 DEBUG --- stderr --- 2024-11-21 23:14:36,488 DEBUG 2024-11-21 23:14:36,488 INFO 2024-11-21 23:14:36,488 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:36,488 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:36,761 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:36,761 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:36,761 DEBUG --- stdout --- 2024-11-21 23:14:36,761 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:36,761 DEBUG --- stderr --- 2024-11-21 23:14:36,761 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 23:14:36,762 INFO 2024-11-21 23:14:36,762 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:36,762 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:37,033 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:37,034 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:37,034 DEBUG --- stdout --- 2024-11-21 23:14:37,034 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:37,034 DEBUG --- stderr --- 2024-11-21 23:14:37,034 DEBUG 2024-11-21 23:14:37,034 INFO 2024-11-21 23:14:37,035 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-35/stdout.txt" ]; then echo "/results/orders/benchmark-35/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-35/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-35/stdout.txt file found" 2024-11-21 23:14:37,035 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 23:14:37,817 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 23:14:37,817 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:37,817 DEBUG --- stdout --- 2024-11-21 23:14:37,817 DEBUG /results/orders/benchmark-35/stdout.txt file found 2024-11-21 23:14:37,817 DEBUG --- stderr --- 2024-11-21 23:14:37,817 DEBUG 2024-11-21 23:14:37,817 INFO 2024-11-21 23:14:37,817 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:37,817 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:38,089 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:38,089 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:38,090 DEBUG --- stdout --- 2024-11-21 23:14:38,090 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:38,090 DEBUG --- stderr --- 2024-11-21 23:14:38,090 DEBUG 2024-11-21 23:14:38,090 INFO 2024-11-21 23:14:38,090 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-35/stdout.txt 2024-11-21 23:14:38,903 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 23:14:38,903 DEBUG --- stdout --- 2024-11-21 23:14:38,903 DEBUG 4564 /results/orders/benchmark-35/stdout.txt 2024-11-21 23:14:38,903 DEBUG --- stderr --- 2024-11-21 23:14:38,903 DEBUG 2024-11-21 23:14:38,903 INFO - Download file (size 4564k) 2024-11-21 23:14:38,903 INFO 2024-11-21 23:14:38,903 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:38,903 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:39,178 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:39,178 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:39,178 DEBUG --- stdout --- 2024-11-21 23:14:39,178 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:39,178 DEBUG --- stderr --- 2024-11-21 23:14:39,178 DEBUG source : /results/orders/benchmark-35/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/stdout.txt 2024-11-21 23:14:39,179 INFO 2024-11-21 23:14:39,179 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:39,179 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:39,451 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:39,451 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:39,451 DEBUG --- stdout --- 2024-11-21 23:14:39,452 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:39,452 DEBUG --- stderr --- 2024-11-21 23:14:39,452 DEBUG 2024-11-21 23:14:39,452 INFO 2024-11-21 23:14:39,452 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-35/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/stdout.txt 2024-11-21 23:14:39,452 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 23:14:40,686 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:40,686 DEBUG --- stdout --- 2024-11-21 23:14:40,686 DEBUG tar: Removing leading `/' from member names 2024-11-21 23:14:40,686 DEBUG --- stderr --- 2024-11-21 23:14:40,686 DEBUG ________________________________________________________________________________ [2024-11-21 23:14:40] benchmark-35 show_cmd : Display order command ________________________________________________________________________________ 2024-11-21 23:14:40,687 INFO 2024-11-21 23:14:40,687 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:40,687 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:40,958 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:40,959 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:40,959 DEBUG --- stdout --- 2024-11-21 23:14:40,959 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:40,959 DEBUG --- stderr --- 2024-11-21 23:14:40,959 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 23:14:40,959 INFO 2024-11-21 23:14:40,959 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:40,959 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:41,230 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:41,231 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:41,231 DEBUG --- stdout --- 2024-11-21 23:14:41,231 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:41,231 DEBUG --- stderr --- 2024-11-21 23:14:41,231 DEBUG 2024-11-21 23:14:41,231 INFO 2024-11-21 23:14:41,231 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-35/cmd.txt" ]; then echo "/results/orders/benchmark-35/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-35/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-35/cmd.txt file found" 2024-11-21 23:14:41,231 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 23:14:42,017 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 23:14:42,017 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:42,017 DEBUG --- stdout --- 2024-11-21 23:14:42,017 DEBUG /results/orders/benchmark-35/cmd.txt file found 2024-11-21 23:14:42,017 DEBUG --- stderr --- 2024-11-21 23:14:42,017 DEBUG 2024-11-21 23:14:42,017 INFO 2024-11-21 23:14:42,017 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:42,017 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:42,289 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:42,289 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:42,290 DEBUG --- stdout --- 2024-11-21 23:14:42,290 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:42,290 DEBUG --- stderr --- 2024-11-21 23:14:42,290 DEBUG 2024-11-21 23:14:42,290 INFO 2024-11-21 23:14:42,290 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-35/cmd.txt 2024-11-21 23:14:43,071 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 23:14:43,071 DEBUG --- stdout --- 2024-11-21 23:14:43,071 DEBUG 4 /results/orders/benchmark-35/cmd.txt 2024-11-21 23:14:43,071 DEBUG --- stderr --- 2024-11-21 23:14:43,071 DEBUG 2024-11-21 23:14:43,071 INFO - Download file (size 4k) 2024-11-21 23:14:43,072 INFO 2024-11-21 23:14:43,072 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:43,072 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:43,344 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:43,345 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:43,345 DEBUG --- stdout --- 2024-11-21 23:14:43,345 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:43,345 DEBUG --- stderr --- 2024-11-21 23:14:43,345 DEBUG source : /results/orders/benchmark-35/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/cmd.txt 2024-11-21 23:14:43,345 INFO 2024-11-21 23:14:43,345 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 23:14:43,345 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 23:14:43,618 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 23:14:43,618 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:43,618 DEBUG --- stdout --- 2024-11-21 23:14:43,618 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 23:14:43,618 DEBUG --- stderr --- 2024-11-21 23:14:43,618 DEBUG 2024-11-21 23:14:43,618 INFO 2024-11-21 23:14:43,618 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-35/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/cmd.txt 2024-11-21 23:14:43,618 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 23:14:44,361 INFO [loop_until]: OK (rc = 0) 2024-11-21 23:14:44,361 DEBUG --- stdout --- 2024-11-21 23:14:44,361 DEBUG tar: Removing leading `/' from member names 2024-11-21 23:14:44,361 DEBUG --- stderr --- 2024-11-21 23:14:44,361 DEBUG 2024-11-21 23:14:44,361 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/cmd.txt is small (1 lines), printing all lines: 2024-11-21 23:14:44,361 DEBUG ----- output ----- 2024-11-21 23:14:44,361 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-35" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=35 -Duser_password=Pa_ssw0rd" 2024-11-21 23:14:44,361 INFO ________________________________________________________________________________ [2024-11-21 23:14:44] benchmark-35 show_rc : Display rc order ________________________________________________________________________________ 2024-11-21 23:14:44,361 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/rc.txt is small (1 lines), printing all lines: 2024-11-21 23:14:44,361 DEBUG ----- output ----- 2024-11-21 23:14:44,361 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-21 23:14:44,361 INFO ________________________________________________________________________________ [2024-11-21 23:14:44] benchmark-35 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-21 23:14:44,368 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/05_benchmark-35/stdout.txt is 57664 lines): 2024-11-21 23:14:44,368 DEBUG ----- output ----- 2024-11-21 23:14:44,368 INFO 2024-11-21 22:14:07,789 DEBUG Creating results folder /results/gatling/benchmark-35 2024-11-21 23:14:44,368 INFO 2024-11-21 22:14:07,797 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmprnc120tw 2024-11-21 23:14:44,368 INFO 2024-11-21 22:14:07,798 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-35" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=35 -Duser_password=**** 2024-11-21 23:14:44,368 INFO [INFO] Scanning for projects... 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-21 23:14:44,368 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-21 23:14:44,368 INFO [INFO] from pom.xml 2024-11-21 23:14:44,368 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-21 23:14:44,368 INFO [INFO] skip non existing resourceDirectory /tmp/tmprnc120tw/src/main/resources 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-21 23:14:44,368 INFO [INFO] No sources to compile 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-21 23:14:44,368 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-21 23:14:44,368 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-21 23:14:44,368 INFO [INFO] compiling 38 Scala sources to /tmp/tmprnc120tw/target/test-classes ... 2024-11-21 23:14:44,368 INFO [INFO] compile in 6.9 s 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] 2024-11-21 23:14:44,368 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-21 23:14:44,368 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-21 23:14:44,368 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-21 23:14:44,368 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-21 23:14:44,368 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-21 23:14:44,368 INFO 22:14:23.856 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 23:14:44,368 INFO 2024-11-21 23:14:44,368 INFO ================================================================================ 2024-11-21 23:14:44,368 INFO 2024-11-21 22:14:23 GMT 5s elapsed 2024-11-21 23:14:44,368 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 23:14:44,368 INFO > Global (OK=122 KO=0 ) 2024-11-21 23:14:44,368 INFO > restLoginInitiate (OK=12 KO=0 ) 2024-11-21 23:14:44,368 INFO > restLoginUsernamePasswordCallback (OK=12 KO=0 ) 2024-11-21 23:14:44,368 INFO > Skip 2FA (OK=7 KO=0 ) 2024-11-21 23:14:44,368 INFO > User Authorize PKCE stage (OK=13 KO=0 ) 2024-11-21 23:14:44,368 INFO > User AccessToken PKCE stage (OK=13 KO=0 ) 2024-11-21 23:14:44,368 INFO > GetUUid (OK=6 KO=0 ) 2024-11-21 23:14:44,368 INFO > GetOpenidConfig (OK=6 KO=0 ) 2024-11-21 23:14:44,369 INFO > CreatePolicy (OK=6 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Post-Login - stage 1 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI AM idFromSession (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI AM validateGoto (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Post-Login - stage 2 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI Enduser appAuthHelper1 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI Enduser appAuthHelper2 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Post-Login - stage 3 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM uiconfig (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI Enduser sessioncheck (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM version (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM login (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM features (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM privilege (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM dashboard (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM user (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM managed user schema (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI IDM oidcToken (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > userinfo (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > tokenUserinfo (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Logout (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI-Logout Redirect 1 (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > loginTreeWorkflow_restLoginInitiate (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI AM revoke1 (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI AM revoke2 (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > UI AM endsession (OK=1 KO=0 ) 2024-11-21 23:14:44,369 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=2 KO=0 ) 2024-11-21 23:14:44,369 INFO ---- Errors -------------------------------------------------------------------- 2024-11-21 23:14:44,369 INFO > tokenUserinfo: No attribute named 'access_token' is defined 1 (100.0%) 2024-11-21 23:14:44,369 INFO 2024-11-21 23:14:44,369 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-21 23:14:44,369 INFO [- ] 0% 2024-11-21 23:14:44,369 INFO waiting: 126324 / active: 8 / done: 6 2024-11-21 23:14:44,369 INFO ================================================================================ 2024-11-21 23:14:44,369 INFO 2024-11-21 23:14:44,369 INFO 2024-11-21 23:14:44,369 INFO ================================================================================ 2024-11-21 23:14:44,369 INFO 2024-11-21 22:14:28 GMT 10s elapsed 2024-11-21 23:14:44,369 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 23:14:44,369 INFO > Global (OK=598 KO=0 ) 2024-11-21 23:14:44,369 INFO > restLoginInitiate (OK=52 KO=0 ) 2024-11-21 23:14:44,369 INFO > restLoginUsernamePasswordCallback (OK=51 KO=0 ) 2024-11-21 23:14:44,369 INFO > Skip 2FA (OK=31 KO=0 ) 2024-11-21 23:14:44,369 INFO > User Authorize PKCE stage (OK=58 KO=0 ) 2024-11-21 23:14:44,369 INFO > User AccessToken PKCE stage (OK=58 KO=0 ) 2024-11-21 23:14:44,369 INFO > GetUUid (OK=25 KO=0 ) 2024-11-21 23:14:44,369 INFO > GetOpenidConfig (OK=31 KO=0 ) 2024-11-21 23:14:44,369 INFO > CreatePolicy (OK=25 KO=0 ) 2024-11-21 23:14:44,369 INFO [...] 2024-11-21 23:14:44,377 INFO 23:14:18.889 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 23:14:44,377 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 23:14:44,377 INFO Request: 2024-11-21 23:14:44,378 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO Session: 2024-11-21 23:14:44,378 INFO Session(idc.benchmark.Mix2024,125223,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.79094, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@35fc5229, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0, password -> Pa_ssw0rd, fake-ip -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@b955d86),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a6cb869a0e0@769ed581,io.netty.channel.epoll.EpollEventLoop@1eb6749b) 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO HTTP request: 2024-11-21 23:14:44,378 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate?authIndexType=service&authIndexValue=Login 2024-11-21 23:14:44,378 INFO headers: 2024-11-21 23:14:44,378 INFO accept: application/json 2024-11-21 23:14:44,378 INFO content-type: application/json 2024-11-21 23:14:44,378 INFO user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0 2024-11-21 23:14:44,378 INFO X-Forwarded-For: 42.42.42.42 2024-11-21 23:14:44,378 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 23:14:44,378 INFO content-length: 0 2024-11-21 23:14:44,378 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO HTTP response: 2024-11-21 23:14:44,378 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 23:14:44,378 INFO 23:14:18.889 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 23:14:44,378 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 23:14:44,378 INFO Request: 2024-11-21 23:14:44,378 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO Session: 2024-11-21 23:14:44,378 INFO Session(idc.benchmark.Mix2024,125225,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.52172, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1dfbc06b, fake-user-agent -> Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36, password -> Pa_ssw0rd, fake-ip -> 86.151.8.102, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@44f8071b),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a6cb869a0e0@769ed581,io.netty.channel.epoll.EpollEventLoop@5b7ea70d) 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO HTTP request: 2024-11-21 23:14:44,378 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 23:14:44,378 INFO headers: 2024-11-21 23:14:44,378 INFO accept: application/json 2024-11-21 23:14:44,378 INFO content-type: application/json 2024-11-21 23:14:44,378 INFO user-agent: Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36 2024-11-21 23:14:44,378 INFO X-Forwarded-For: 86.151.8.102 2024-11-21 23:14:44,378 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 23:14:44,378 INFO content-length: 0 2024-11-21 23:14:44,378 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO HTTP response: 2024-11-21 23:14:44,378 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 23:14:44,378 INFO 23:14:18.889 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 23:14:44,378 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 23:14:44,378 INFO Request: 2024-11-21 23:14:44,378 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO Session: 2024-11-21 23:14:44,378 INFO Session(idc.benchmark.Mix2024,125188,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.134899, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3997079e, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"authId":"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJ3aGl0ZWxpc3Qtc3RhdGUiOiI0NmNlMzg1Mi0zODkxLTQzNjEtOGMwYy03OTA5OTUzNGYwZTciLCJhdXRoSW5kZXhWYWx1ZSI6IkxvZ2luIiwib3RrIjoiMWV1cm9oYjhnMG5ra3BiOXJrZWkyMGtwb3QiLCJhdXRoSW5kZXhUeXBlIjoic2VydmljZSIsInJlYWxtIjoiL2FscGhhIiwic2Vzc2lvbklkIjoiKkFBSlRTUUFDTURJQUJIUjVjR1VBQ0VwWFZGOUJWVlJJQUFKVE1RQUNNREUuKmV5SjBlWEFpT2lKS1YxUWlMQ0pqZEhraU9pSktWMVFpTENKaGJHY2lPaUpJVXpJMU5pSjkuWlhsS01HVllRV2xQYVVwTFZqRlJhVXhEU214aWJVMXBUMmxLUWsxVVNUUlJNRXBFVEZWb1ZFMXFWVEpKYVhkcFdWZDRia2xxYjJsYVIyeDVTVzR3TGk0d1RHTnJhbFZLTVhkdmNWZEtkVWhKTjFCTlMybDNMa2hLZVVoa1pHSlRWSGRhUVU5NWRXOUJNRXhpV1RWV2FGQm9NV2RzVVZFMllUUmpSM0oxU1hkRE9XdDJOV04xY1ZoM1ZIUlBSa1ZEY2xNemMwc3lTV0o1UWxsVVpUWjFORmd0T1c5alZIaHVYM1J5WldkQ1JTMUdUVTVKYlhGMlVITkVZbHBxVkhwQ1QwbDFVa2RoYUdabllYUm9NSEJ0Y2xwWFdXbFllbkJDZEUxVVFXUlZUVVZ4YkZkWlRYWXpka05aT1dWaU5saFZWMnhHU3pWblYybzFhMHhhUkdGWWFIcHFZVUpWVW5wUlIwUTFTV3N0Tm10UmExUXlVVUZNZVZaM1drdDNaV2szWnpjdFJsSlpObWhmTkZCUWEyVjVjbUZoVG5CMlNEUTFWM2xJTjI5S1UyaFVibE5EVDJOUU4xVlZhVkkzY1RkSVNuZE9hVWhSUzJSV1MydERTVXB1WjI1alREQlJSVGx6TlhCcWQyOVZZbGhETTJsSVgwRnNMVzR5WjAxQ1YwaDBiVlJKYzJvMVVFMDVPWGxQVG1vemFqWnJWRmxsUmtKTE9XWnVTRUpqYmpOTWFXOWlNRVJwYnpNM1QxQldVelptVVVoeU1sVTNibEptVUMxQ2FHVjJRWEp6Tkd4RGNYbHlSRlZvVVZBelVTMXRPRmhMV0dwdU9XRndhbkV0U0RKRmRreFBSWFZZVDB0SmNUUXRhMUZ0ZDBvMmVqQllRbXB5ZDFOMVV6SlFRM0pKY3pOZmFUQk9iMVZoY1dGWVpHRkhjbkpDYjJadlptOVFaekpsVDJWaGRtaE1lRGhYUmtGNFRuVk9keloxTFhwQlgyNHpkR2hNYTI0eWRuQTRVbXhpVFhWdE4zRlhPRVI2WmxwblowNVVTa0ZQUldSM2JFTXdRakppWWxkc2VVOUViME5GTVU1VU5sOWhTREJRTUd0ak9XUldTVkpuWjNrMU5sRmhaVU5YU0RaSFJVRk5jRTlyTW1GNGFXaDNNa0pLVTBac1luVjZjWEJDV0dvelFVdGFPSFJPYzFRMlQwa3pUM0psZDFka1YyNURjbFp5TXpOR1UxZEtiVGhsTFhkQ2NVc3hiakJmV2tWaVVtRk9iMTlXTlZwd1NIbGxielU1ZUROTloycFNiV1JZYVhweWNsWndlbXRsVVc1RFgyRk5XamRpYUUxUE1XNW5kMWRGTUVsRGFIUkVWekpGU1Rad1l6UTRVRU5DYUhoUmVtZFdXSEYwTUhSRE4yVmlXRVl3VGtsQ1dGWlllaTFuYUZaQlNqVktUa0U1VVRKMWFVeEtkVzFsUW0xRFpGUkJkV3RUT1dWdU5XZEhhbDlNU2tGVGFHaHpNblJzYVhGUFRrdDFkeTFsTTNaVWNrdDZjRGxWT1hSQk5tUXRkR2wzY0ROblR6RmZWbUZ2Wmw5aFptcHljREJWU0ZwM2JFNUpNMDlHU1cxVVoxZHhlRkJNYjFCU1dWUlRTbEJ3VDBkdE0zTnlaRzlZTUZGV2NFVlpVVlZOV0dRdFZWcEtUMHBRYmpCM1JUTldRV1p0Y1dkeWVIVkljemhhTWpWZmFuZFdPRWRGT1VnMVIxWllUemhhZWpkQ1JYWllhWFYwWDFWcVJsQnBaa3RwY21OclNtUTBVMkZvWjBZNUxYaHVZMmhGYlhkNE1WTm1NRlUyWW5kS2FGVjNSVTlrUzNoRk5FcFZVV1JmV0VGdVdXeEZjVU5rYW5WT1JuRmFURGRsWkRWRmMzUmZRWFY2WVRWM1h6UmplRk5oYm5WeFJGWXpWbDh6V0UxSVRWOTVRMk5zVldWaWIyMWxRMWR3YWpSTVNFcElVbTlWVG5kalUwTmhZMWw0VXpJNGNUQjRhSEZqYVZoU056QkVhbEpDYUcxcWIwZHhPRUp1WVRGa1ltaGpPVTFvTTNSeFNVNXBRa0ZqWlc1eFRqTlJPRm96ZDJveWJHcDVVV1l0WTE5WVJGZFphbGhDVVU1VFZGRjZkREZpWjFsV1duUnRObFpFTTJwd1MwWmpkalpPYUhwZlZpMXFVMWw0YjAxUk0yTllhSFZxU1RSV04zWkVaM2hrV0dRNGJGSlRWelExVGpka01XMUpOWFkzUW5WSU1ubDZhRjlSU1ZocmFqTlJVR1E0UlVWeVpVUjFOMmhqY0VJMmNFRlBTRXAzZEY4eFNIcFZaMHhWY1VoR1YxWmpXbXRwZEc0eVYxaGlWVjh6UzJwMWNreG5XVnBpY2xONk4xOWZiRE4zZEc5d05WaDZNMjlsVVZOVE1IbEhSa1JDVDBoc1V6Vk9Na1UxVW1JMFdXaHRZVTFYV2xWV1V5MDJZV0k1Wm5CNlZubEhXbDlLYzBKeU0xbG9ObGhMTjB4dFJqTmZRWEJGVkhCQk5rbEhkMUl6U2w5d1ozQTFVMUZ6V1VaUE1tRTBZVzVHY1hKRWJGRnRlVWhOWDJScGFsOWpPWGxzYm1kdVNUaHFPVmc1Ym5ObmJWQnRPV3RpTlhwVFprVm9ZM3BqY0RsYWNXbEhkV1ZOWkVWbFlWTlZiamx0U0RRNWNFMTZVWFpPY1d0TU4ydDZTVXhzWjJJeFoydG5UV0pTVFhGVFFrNW5lVFpUT0RKc04yeEJWVWRmUlV0b2JIZFJVSEZMUkZWS2QyWmljVWhGT1hobE9WcFlXa0pIVTB4TkxVRlNWSEpFVGxScVVHNU5ZWE5VWDNoMVFsUnBNbFZ0WDJWSmVqRXdhMlJoYzBwWmFVcGZMVXBwVUhSRFpHWjNNekZ4ZG5BelZFazRVRVJ2Wm5SdGVHNWphSEJuZVdGS1pHTm5XVk42WlhCTFZHOUtOa3R0VUd4dlNGTkJlVzh4UkVsME1VVm1MVVZ4WDBvd2IzZHBSMDloVVdWNWVESmFZbWRCWkRSWWNtSTJUazB5YW5aWlpXWjBaMUZ5ZUd4WFZuSm5RMUo1WVdnMVJtUXlRalpNT0dabWJFUmxjWGRvU0dGeWFWcE5SRWN5U1doaE1IUnJUMjluUjFZMmQxWmZOVUYzUjBjd2FHaDBhR2R3UTJKTlFWRlRNMHR4UzE4M2FVVktRVXBNVmt4eVpHcEhjelZQTFZwWVZsUlFRekptY0d4MU1WUkJVMVpaYzNOek5FVXdaRlpNT0UxWlZFVlBiR1ZMWW1wVmJXYzNORVpuZFVzeFozZGFNVVp1VW1kSFpFNVRUM1JFYW5KclpHMWpWbEYwVEV0RkxVbElOSGxSUTI1MFltSk5PRFJaVEVaWlZtSmxUakUxVEZwelpuTmZiblV4V0ZCd2RVazBVRTEzTlhsSlVURkthVzVJWTJOTVRsRktiRWRVZW5aSVNWVnNPVmhGWlZGSWVWQlZjV1EyT1Y5UE5USktZbEprYXpkSGNYcFVhakJtWjFaaVJWRTRURXBNZG1sSFYyeGlXRmh4ZUZOaFQyOTFSMlpWUWpWRlNHdFJUV1oxWHkxSE1FRkJhalZJTkVGbFN6TkhWRk5LTTB0d1dtMUtTak4yWkcwNGVtVnNTVkU1UldaVFl6Y3diRXB3YkVSUE5EWmtRa0Y1TjB0ck1VOVFZVTFQTVhGSFgwaGpiVTlyTFZwelVHdDJXbDlyWkVSeVpXOVBOVGx5ZFhBMlZXcHVhSEkyWm5wbFVWVkRjamR2U2tVdGVYbEZPWHB2YXpVek9USmhVUzVTTTNjM0xWWkxWVmMzT1RSR2NXRTVNRlZSZWxaMy56THhIOGc3eVNXWVdER2NCZm9UMUc4V21uTWZDNzRLUldpZ2F4ZlV2SFFNIiwiZXhwIjoxNzMyMjMxMTU4LCJpYXQiOjE3MzIyMzA4NTh9.YV6TcZeeUVfpJ38Z84kLReuOqSujSP4p0cRRA6_Lz2Y","callbacks":[{"type":"BooleanAttributeInputCallback","output":[{"name":"name","value":"preferences/updates"},{"name":"prompt","value":"Send me news and updates"},{"name":"required","value":false},{"name":"policies","value":{}},{"name":"failedPolicies","value":[]},{"name":"validateOnly","value":false},{"name":"value","value":false}],"input":[{"name":"IDToken1","value":true},{"name":"IDToken1validateOnly","value":false}],"_id":2},{"type":"BooleanAttributeInputCallback","output":[{"name":"name","value":"preferences/marketing"},{"name":"prompt","value":"Send me special offers and services"},{"name":"required","value":false},{"name":"policies","value":{}},{"name":"failedPolicies","value":[]},{"name":"validateOnly","value":false},{"name":"value","value":false}],"input":[{"name":"IDToken2","value":true},{"name":"IDToken2validateOnly","value":false}],"_id":3}],"header":"Please select your preferences"}, 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,1732230858766), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=e6t5BvqX4DqSkAq4wpU9q8KnLMY.*AAJTSQACMDIAAlNLABxQR20zeUtDdi9ycnlQVFB4cUN5RE1CWmFlWFk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*,true,false,1732230858766))), password -> Pa_ssw0rd, fake-ip -> 186.2.9.54, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@16bb12b3, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@7090cb55, tokenId -> e6t5BvqX4DqSkAq4wpU9q8KnLMY.*AAJTSQACMDIAAlNLABxQR20zeUtDdi9ycnlQVFB4cUN5RE1CWmFlWFk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/17.17134),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a6cb869a0e0@769ed581,io.netty.channel.epoll.EpollEventLoop@239b0f9d) 2024-11-21 23:14:44,378 INFO ========================= 2024-11-21 23:14:44,378 INFO HTTP request: 2024-11-21 23:14:44,378 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-21 23:14:44,378 INFO headers: 2024-11-21 23:14:44,378 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 12_5_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36 2024-11-21 23:14:44,378 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-21 23:14:44,378 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-21 23:14:44,378 INFO accept: */* 2024-11-21 23:14:44,378 INFO cookie: amlbcookie=01; 9b75a55744995d0=e6t5BvqX4DqSkAq4wpU9q8KnLMY.*AAJTSQACMDIAAlNLABxQR20zeUtDdi9ycnlQVFB4cUN5RE1CWmFlWFk9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-21 23:14:44,378 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-21 23:14:44,378 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 23:14:44,378 INFO content-length: 0 2024-11-21 23:14:44,378 INFO cookies: 2024-11-21 23:14:44,378 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 23:14:44,379 INFO 9b75a55744995d0=e6t5BvqX4DqSkAq4wpU9q8KnLMY.*AAJTSQACMDIAAlNLABxQR20zeUtDdi9ycnlQVFB4cUN5RE1CWmFlWFk9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-21 23:14:44,379 INFO ========================= 2024-11-21 23:14:44,379 INFO HTTP response: 2024-11-21 23:14:44,379 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 23:14:44,379 INFO 23:14:18.889 [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-21 23:14:44,379 INFO 23:14:18.889 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 125221: j.i.IOException: Premature close 2024-11-21 23:14:44,379 INFO 23:14:18.889 [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-21 23:14:44,379 INFO 23:14:18.889 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 23:14:44,379 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 23:14:44,379 INFO Request: 2024-11-21 23:14:44,379 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 23:14:44,379 INFO ========================= 2024-11-21 23:14:44,379 INFO Session: 2024-11-21 23:14:44,379 INFO Session(idc.benchmark.Mix2024,125221,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.85369, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@35bcdea3, fake-user-agent -> Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9, password -> Pa_ssw0rd, fake-ip -> 247.204.226.55, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@792e7e8f),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007a6cb869a0e0@769ed581,io.netty.channel.epoll.EpollEventLoop@619bfe29) 2024-11-21 23:14:44,379 INFO ========================= 2024-11-21 23:14:44,379 INFO HTTP request: 2024-11-21 23:14:44,379 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 23:14:44,379 INFO headers: 2024-11-21 23:14:44,379 INFO accept: application/json 2024-11-21 23:14:44,379 INFO content-type: application/json 2024-11-21 23:14:44,379 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9 2024-11-21 23:14:44,379 INFO X-Forwarded-For: 247.204.226.55 2024-11-21 23:14:44,379 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 23:14:44,379 INFO content-length: 0 2024-11-21 23:14:44,379 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 23:14:44,379 INFO ========================= 2024-11-21 23:14:44,379 INFO HTTP response: 2024-11-21 23:14:44,379 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 23:14:44,379 INFO 23:14:18.889 [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-21 23:14:44,379 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 23:14:44,379 INFO [INFO] BUILD SUCCESS 2024-11-21 23:14:44,379 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 23:14:44,379 INFO [INFO] Total time: 01:00 h 2024-11-21 23:14:44,379 INFO [INFO] Finished at: 2024-11-21T23:14:18Z 2024-11-21 23:14:44,379 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 23:14:44,379 INFO 2024-11-21 23:14:18,994 INFO Gatling simulation run ended successfully 2024-11-21 23:14:44,379 INFO 2024-11-21 23:14:18,994 DEBUG No archive name provided. No archive will be created 2024-11-21 23:14:44,379 INFO ________________________________________________________________________________ [2024-11-21 23:14:44] benchmark-35 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-21 23:14:44,379 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-35/stderr.txt is small (0 lines), printing all lines: 2024-11-21 23:14:44,379 DEBUG ----- output ----- 2024-11-21 23:14:44,379 DEBUG 2024-11-21 23:14:44,379 INFO ________________________________________________________________________________ [2024-11-21 23:14:44] benchmark-35 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-11-21 23:14:44] benchmark-35 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-21 23:14:44] benchmark-35 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped