--Task-- name: benchmark-120 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-100'] preceding_task: benchmark-100 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 120} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-07 00:13:56] benchmark-120 pre : N/A ________________________________________________________________________________ 2024-11-07 00:13:56 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-07 00:13:56 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-120/stdout.txt Pod log : /results/orders/benchmark-120 2024-11-07 00:13:56,778 INFO 2024-11-07 00:13:56,778 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-07 00:13:56,779 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 00:13:57,053 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 00:13:57,053 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:57,053 DEBUG --- stdout --- 2024-11-07 00:13:57,053 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 00:13:57,053 DEBUG --- stderr --- 2024-11-07 00:13:57,053 DEBUG ________________________________________________________________________________ [2024-11-07 00:13:57] benchmark-120 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-07 00:13:57,054 INFO 2024-11-07 00:13:57,054 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-07 00:13:57,054 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 00:13:57,331 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 00:13:57,331 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:57,331 DEBUG --- stdout --- 2024-11-07 00:13:57,331 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 00:13:57,331 DEBUG --- stderr --- 2024-11-07 00:13:57,331 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-120" --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=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-07 00:13:57] benchmark-120 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-07 00:13:57,332 INFO 2024-11-07 00:13:57,332 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-07 00:13:57,332 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 00:13:57,606 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 00:13:57,607 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:57,607 DEBUG --- stdout --- 2024-11-07 00:13:57,607 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 00:13:57,607 DEBUG --- stderr --- 2024-11-07 00:13:57,607 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/order.json { "name": "benchmark-120", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-120\" --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=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-120" } ________________________________________________________________________________ [2024-11-07 00:13:57] benchmark-120 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-07 00:13:57,610 INFO 2024-11-07 00:13:57,610 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-07 00:13:57,610 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-07 00:13:57,921 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-07 00:13:57,921 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:57,921 DEBUG --- stdout --- 2024-11-07 00:13:57,921 DEBUG WAITING 2024-11-07 00:13:57,921 DEBUG --- stderr --- 2024-11-07 00:13:57,921 DEBUG % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 23 0 --:--:-- --:--:-- --:--:-- 23 ________________________________________________________________________________ [2024-11-07 00:13:57] benchmark-120 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-07 00:13:57,921 INFO 2024-11-07 00:13:57,921 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-07 00:13:57,921 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 00:13:58,199 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 00:13:58,199 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:58,200 DEBUG --- stdout --- 2024-11-07 00:13:58,200 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 00:13:58,200 DEBUG --- stderr --- 2024-11-07 00:13:58,200 DEBUG 2024-11-07 00:13:58,200 INFO 2024-11-07 00:13:58,200 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-120/order.json overseer-0-6644bb6697-9gfkx:/results/orders/order.json 2024-11-07 00:13:58,200 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-07 00:13:59,553 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:59,553 DEBUG --- stdout --- 2024-11-07 00:13:59,553 DEBUG 2024-11-07 00:13:59,553 DEBUG --- stderr --- 2024-11-07 00:13:59,553 DEBUG Order has been successfully forwarded to overseer 2024-11-07 00:13:59 - INFO: Check if Gatling simulation started successfully 2024-11-07 00:13:59,553 INFO 2024-11-07 00:13:59,553 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-07 00:13:59,553 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 00:13:59,829 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 00:13:59,829 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:13:59,829 DEBUG --- stdout --- 2024-11-07 00:13:59,829 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 00:13:59,829 DEBUG --- stderr --- 2024-11-07 00:13:59,829 DEBUG 2024-11-07 00:13:59,829 INFO 2024-11-07 00:13:59,829 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx -- head --lines 5000 /results/orders/benchmark-120/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-07 00:13:59,829 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-07 00:14:00,554 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-07 00:14:06,287 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-07 00:14:12,026 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-07 00:14:12,026 INFO [loop_until]: OK (rc = 0) 2024-11-07 00:14:12,026 DEBUG --- stdout --- 2024-11-07 00:14:12,026 DEBUG 2024-11-07 00:14:00,190 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp_bia93a6 2024-11-07 00:14:00,192 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-120" -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=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -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/tmp_bia93a6/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/tmp_bia93a6/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. 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-07 00:14:12,026 DEBUG --- stderr --- 2024-11-07 00:14:12,026 DEBUG ________________________________________________________________________________ [2024-11-07 00:14:12] benchmark-120 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 01s, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 03s, retry Order is running since 22m 03s, retry Order is running since 24m 04s, retry Order is running since 26m 04s, retry Order is running since 28m 04s, retry Order is running since 30m 05s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 06s, retry Order is running since 38m 06s, retry Order is running since 40m 06s, retry Order is running since 42m 07s, retry Order is running since 44m 07s, retry Order is running since 46m 07s, retry Order is running since 48m 07s, retry Order is running since 50m 08s, retry Order is running since 52m 08s, retry Order is running since 54m 08s, retry Order is running since 56m 09s, retry Order is running since 58m 09s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-07 01:14:21] benchmark-120 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-07 01:14:21,925 INFO 2024-11-07 01:14:21,925 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-07 01:14:21,925 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:22,219 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:22,219 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:22,219 DEBUG --- stdout --- 2024-11-07 01:14:22,220 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:22,220 DEBUG --- stderr --- 2024-11-07 01:14:22,220 DEBUG 2024-11-07 01:14:22,220 INFO 2024-11-07 01:14:22,220 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx -- rm -f /results/orders/order.json 2024-11-07 01:14:22,220 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-07 01:14:22,999 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:22,999 DEBUG --- stdout --- 2024-11-07 01:14:22,999 DEBUG 2024-11-07 01:14:22,999 DEBUG --- stderr --- 2024-11-07 01:14:22,999 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-07 01:14:22] benchmark-120 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-07 01:14:22 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/order.json 2024-11-07 01:14:22,999 INFO 2024-11-07 01:14:23,000 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-07 01:14:23,000 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:23,276 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:23,277 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:23,277 DEBUG --- stdout --- 2024-11-07 01:14:23,277 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:23,277 DEBUG --- stderr --- 2024-11-07 01:14:23,277 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-07 01:14:23,277 INFO 2024-11-07 01:14:23,277 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-07 01:14:23,277 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:23,553 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:23,553 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:23,553 DEBUG --- stdout --- 2024-11-07 01:14:23,553 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:23,553 DEBUG --- stderr --- 2024-11-07 01:14:23,553 DEBUG 2024-11-07 01:14:23,554 INFO 2024-11-07 01:14:23,554 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-120/rc.txt" ]; then echo "/results/orders/benchmark-120/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-120/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/rc.txt file found" 2024-11-07 01:14:23,554 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-07 01:14:24,348 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-07 01:14:24,348 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:24,348 DEBUG --- stdout --- 2024-11-07 01:14:24,348 DEBUG /results/orders/benchmark-120/rc.txt file found 2024-11-07 01:14:24,348 DEBUG --- stderr --- 2024-11-07 01:14:24,348 DEBUG 2024-11-07 01:14:24,348 INFO 2024-11-07 01:14:24,348 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-07 01:14:24,348 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:24,624 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:24,624 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:24,624 DEBUG --- stdout --- 2024-11-07 01:14:24,624 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:24,624 DEBUG --- stderr --- 2024-11-07 01:14:24,624 DEBUG 2024-11-07 01:14:24,624 INFO 2024-11-07 01:14:24,624 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-120/rc.txt 2024-11-07 01:14:25,411 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-07 01:14:25,411 DEBUG --- stdout --- 2024-11-07 01:14:25,411 DEBUG 4 /results/orders/benchmark-120/rc.txt 2024-11-07 01:14:25,411 DEBUG --- stderr --- 2024-11-07 01:14:25,411 DEBUG 2024-11-07 01:14:25,411 INFO - Download file (size 4k) 2024-11-07 01:14:25,412 INFO 2024-11-07 01:14:25,412 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-07 01:14:25,412 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:25,688 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:25,688 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:25,688 DEBUG --- stdout --- 2024-11-07 01:14:25,688 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:25,688 DEBUG --- stderr --- 2024-11-07 01:14:25,688 DEBUG source : /results/orders/benchmark-120/rc.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/rc.txt 2024-11-07 01:14:25,688 INFO 2024-11-07 01:14:25,688 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-07 01:14:25,688 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:25,962 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:25,962 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:25,962 DEBUG --- stdout --- 2024-11-07 01:14:25,962 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:25,962 DEBUG --- stderr --- 2024-11-07 01:14:25,962 DEBUG 2024-11-07 01:14:25,963 INFO 2024-11-07 01:14:25,963 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-120/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/rc.txt 2024-11-07 01:14:25,963 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-07 01:14:26,719 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:26,719 DEBUG --- stdout --- 2024-11-07 01:14:26,719 DEBUG tar: Removing leading `/' from member names 2024-11-07 01:14:26,719 DEBUG --- stderr --- 2024-11-07 01:14:26,719 DEBUG 2024-11-07 01:14:26,720 INFO 2024-11-07 01:14:26,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-07 01:14:26,720 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:26,995 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:26,995 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:26,995 DEBUG --- stdout --- 2024-11-07 01:14:26,995 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:26,995 DEBUG --- stderr --- 2024-11-07 01:14:26,995 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-07 01:14:26,996 INFO 2024-11-07 01:14:26,996 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-07 01:14:26,996 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:27,269 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:27,269 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:27,269 DEBUG --- stdout --- 2024-11-07 01:14:27,269 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:27,269 DEBUG --- stderr --- 2024-11-07 01:14:27,269 DEBUG 2024-11-07 01:14:27,270 INFO 2024-11-07 01:14:27,270 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-120/stderr.txt" ]; then echo "/results/orders/benchmark-120/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-120/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/stderr.txt file found" 2024-11-07 01:14:27,270 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-07 01:14:28,073 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-07 01:14:28,073 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:28,073 DEBUG --- stdout --- 2024-11-07 01:14:28,073 DEBUG /results/orders/benchmark-120/stderr.txt file found 2024-11-07 01:14:28,073 DEBUG --- stderr --- 2024-11-07 01:14:28,073 DEBUG 2024-11-07 01:14:28,073 INFO 2024-11-07 01:14:28,073 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-07 01:14:28,073 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:28,348 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:28,348 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:28,348 DEBUG --- stdout --- 2024-11-07 01:14:28,349 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:28,349 DEBUG --- stderr --- 2024-11-07 01:14:28,349 DEBUG 2024-11-07 01:14:28,349 INFO 2024-11-07 01:14:28,349 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-120/stderr.txt 2024-11-07 01:14:29,142 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-07 01:14:29,142 DEBUG --- stdout --- 2024-11-07 01:14:29,142 DEBUG 0 /results/orders/benchmark-120/stderr.txt 2024-11-07 01:14:29,142 DEBUG --- stderr --- 2024-11-07 01:14:29,142 DEBUG 2024-11-07 01:14:29,142 INFO - Download file (size 0k) 2024-11-07 01:14:29,143 INFO 2024-11-07 01:14:29,143 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-07 01:14:29,143 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:29,418 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:29,418 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:29,418 DEBUG --- stdout --- 2024-11-07 01:14:29,418 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:29,418 DEBUG --- stderr --- 2024-11-07 01:14:29,418 DEBUG source : /results/orders/benchmark-120/stderr.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stderr.txt 2024-11-07 01:14:29,418 INFO 2024-11-07 01:14:29,419 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-07 01:14:29,419 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:29,699 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:29,699 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:29,699 DEBUG --- stdout --- 2024-11-07 01:14:29,699 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:29,699 DEBUG --- stderr --- 2024-11-07 01:14:29,699 DEBUG 2024-11-07 01:14:29,701 INFO 2024-11-07 01:14:29,701 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-120/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stderr.txt 2024-11-07 01:14:29,701 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-07 01:14:30,482 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:30,482 DEBUG --- stdout --- 2024-11-07 01:14:30,482 DEBUG tar: Removing leading `/' from member names 2024-11-07 01:14:30,482 DEBUG --- stderr --- 2024-11-07 01:14:30,482 DEBUG 2024-11-07 01:14:30,482 INFO 2024-11-07 01:14:30,482 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-07 01:14:30,482 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:30,760 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:30,760 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:30,760 DEBUG --- stdout --- 2024-11-07 01:14:30,760 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:30,761 DEBUG --- stderr --- 2024-11-07 01:14:30,761 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-07 01:14:30,761 INFO 2024-11-07 01:14:30,761 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-07 01:14:30,761 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:31,037 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:31,037 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:31,037 DEBUG --- stdout --- 2024-11-07 01:14:31,037 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:31,037 DEBUG --- stderr --- 2024-11-07 01:14:31,037 DEBUG 2024-11-07 01:14:31,038 INFO 2024-11-07 01:14:31,038 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-120/stdout.txt" ]; then echo "/results/orders/benchmark-120/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-120/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/stdout.txt file found" 2024-11-07 01:14:31,038 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-07 01:14:31,882 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-07 01:14:31,882 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:31,882 DEBUG --- stdout --- 2024-11-07 01:14:31,882 DEBUG /results/orders/benchmark-120/stdout.txt file found 2024-11-07 01:14:31,882 DEBUG --- stderr --- 2024-11-07 01:14:31,882 DEBUG 2024-11-07 01:14:31,882 INFO 2024-11-07 01:14:31,883 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-07 01:14:31,883 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:32,161 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:32,161 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:32,161 DEBUG --- stdout --- 2024-11-07 01:14:32,161 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:32,161 DEBUG --- stderr --- 2024-11-07 01:14:32,161 DEBUG 2024-11-07 01:14:32,161 INFO 2024-11-07 01:14:32,161 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-120/stdout.txt 2024-11-07 01:14:32,958 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-07 01:14:32,959 DEBUG --- stdout --- 2024-11-07 01:14:32,959 DEBUG 6040 /results/orders/benchmark-120/stdout.txt 2024-11-07 01:14:32,959 DEBUG --- stderr --- 2024-11-07 01:14:32,959 DEBUG 2024-11-07 01:14:32,959 INFO - Download file (size 6040k) 2024-11-07 01:14:32,959 INFO 2024-11-07 01:14:32,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-07 01:14:32,959 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:33,252 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:33,252 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:33,252 DEBUG --- stdout --- 2024-11-07 01:14:33,252 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:33,252 DEBUG --- stderr --- 2024-11-07 01:14:33,252 DEBUG source : /results/orders/benchmark-120/stdout.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stdout.txt 2024-11-07 01:14:33,253 INFO 2024-11-07 01:14:33,253 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-07 01:14:33,253 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:33,532 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:33,532 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:33,532 DEBUG --- stdout --- 2024-11-07 01:14:33,532 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:33,532 DEBUG --- stderr --- 2024-11-07 01:14:33,532 DEBUG 2024-11-07 01:14:33,532 INFO 2024-11-07 01:14:33,533 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-120/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stdout.txt 2024-11-07 01:14:33,533 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-07 01:14:34,823 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:34,824 DEBUG --- stdout --- 2024-11-07 01:14:34,824 DEBUG tar: Removing leading `/' from member names 2024-11-07 01:14:34,824 DEBUG --- stderr --- 2024-11-07 01:14:34,824 DEBUG ________________________________________________________________________________ [2024-11-07 01:14:34] benchmark-120 show_cmd : Display order command ________________________________________________________________________________ 2024-11-07 01:14:34,824 INFO 2024-11-07 01:14:34,824 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-07 01:14:34,824 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:35,098 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:35,098 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:35,098 DEBUG --- stdout --- 2024-11-07 01:14:35,098 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:35,098 DEBUG --- stderr --- 2024-11-07 01:14:35,098 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-07 01:14:35,098 INFO 2024-11-07 01:14:35,098 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-07 01:14:35,098 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:35,373 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:35,373 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:35,373 DEBUG --- stdout --- 2024-11-07 01:14:35,373 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:35,373 DEBUG --- stderr --- 2024-11-07 01:14:35,373 DEBUG 2024-11-07 01:14:35,374 INFO 2024-11-07 01:14:35,374 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-120/cmd.txt" ]; then echo "/results/orders/benchmark-120/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-120/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/cmd.txt file found" 2024-11-07 01:14:35,374 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-07 01:14:36,167 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-07 01:14:36,167 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:36,168 DEBUG --- stdout --- 2024-11-07 01:14:36,168 DEBUG /results/orders/benchmark-120/cmd.txt file found 2024-11-07 01:14:36,168 DEBUG --- stderr --- 2024-11-07 01:14:36,168 DEBUG 2024-11-07 01:14:36,168 INFO 2024-11-07 01:14:36,168 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-07 01:14:36,168 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:36,443 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:36,443 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:36,443 DEBUG --- stdout --- 2024-11-07 01:14:36,443 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:36,443 DEBUG --- stderr --- 2024-11-07 01:14:36,443 DEBUG 2024-11-07 01:14:36,443 INFO 2024-11-07 01:14:36,444 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-120/cmd.txt 2024-11-07 01:14:37,253 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-07 01:14:37,253 DEBUG --- stdout --- 2024-11-07 01:14:37,253 DEBUG 4 /results/orders/benchmark-120/cmd.txt 2024-11-07 01:14:37,253 DEBUG --- stderr --- 2024-11-07 01:14:37,253 DEBUG 2024-11-07 01:14:37,253 INFO - Download file (size 4k) 2024-11-07 01:14:37,253 INFO 2024-11-07 01:14:37,253 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-07 01:14:37,253 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:37,528 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:37,528 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:37,528 DEBUG --- stdout --- 2024-11-07 01:14:37,528 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:37,528 DEBUG --- stderr --- 2024-11-07 01:14:37,528 DEBUG source : /results/orders/benchmark-120/cmd.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/cmd.txt 2024-11-07 01:14:37,529 INFO 2024-11-07 01:14:37,529 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-07 01:14:37,529 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-07 01:14:37,802 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-07 01:14:37,802 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:37,802 DEBUG --- stdout --- 2024-11-07 01:14:37,802 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-07 01:14:37,802 DEBUG --- stderr --- 2024-11-07 01:14:37,802 DEBUG 2024-11-07 01:14:37,803 INFO 2024-11-07 01:14:37,803 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-120/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/cmd.txt 2024-11-07 01:14:37,803 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-07 01:14:38,554 INFO [loop_until]: OK (rc = 0) 2024-11-07 01:14:38,554 DEBUG --- stdout --- 2024-11-07 01:14:38,554 DEBUG tar: Removing leading `/' from member names 2024-11-07 01:14:38,554 DEBUG --- stderr --- 2024-11-07 01:14:38,554 DEBUG 2024-11-07 01:14:38,554 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/cmd.txt is small (1 lines), printing all lines: 2024-11-07 01:14:38,554 DEBUG ----- output ----- 2024-11-07 01:14:38,554 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-120" --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=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=Pa_ssw0rd" 2024-11-07 01:14:38,554 INFO ________________________________________________________________________________ [2024-11-07 01:14:38] benchmark-120 show_rc : Display rc order ________________________________________________________________________________ 2024-11-07 01:14:38,555 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/rc.txt is small (1 lines), printing all lines: 2024-11-07 01:14:38,555 DEBUG ----- output ----- 2024-11-07 01:14:38,555 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-07 01:14:38,555 INFO ________________________________________________________________________________ [2024-11-07 01:14:38] benchmark-120 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-07 01:14:38,564 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-120/stdout.txt is 71612 lines): 2024-11-07 01:14:38,564 DEBUG ----- output ----- 2024-11-07 01:14:38,564 INFO 2024-11-07 00:14:00,190 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp_bia93a6 2024-11-07 01:14:38,564 INFO 2024-11-07 00:14:00,192 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-120" -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=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=**** 2024-11-07 01:14:38,564 INFO [INFO] Scanning for projects... 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-07 01:14:38,564 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-07 01:14:38,564 INFO [INFO] from pom.xml 2024-11-07 01:14:38,564 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-07 01:14:38,564 INFO [INFO] skip non existing resourceDirectory /tmp/tmp_bia93a6/src/main/resources 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-07 01:14:38,564 INFO [INFO] No sources to compile 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-07 01:14:38,564 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-07 01:14:38,564 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-07 01:14:38,564 INFO [INFO] compiling 38 Scala sources to /tmp/tmp_bia93a6/target/test-classes ... 2024-11-07 01:14:38,564 INFO [INFO] compile in 6.8 s 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] 2024-11-07 01:14:38,564 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-07 01:14:38,564 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-07 01:14:38,564 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-07 01:14:38,564 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-07 01:14:38,564 INFO 2024-11-07 01:14:38,564 INFO ================================================================================ 2024-11-07 01:14:38,564 INFO 2024-11-07 00:14:16 GMT 5s elapsed 2024-11-07 01:14:38,564 INFO ---- Requests ------------------------------------------------------------------ 2024-11-07 01:14:38,564 INFO > Global (OK=448 KO=0 ) 2024-11-07 01:14:38,564 INFO > loginTreeWorkflow_restLoginInitiate (OK=1 KO=0 ) 2024-11-07 01:14:38,564 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=1 KO=0 ) 2024-11-07 01:14:38,564 INFO > restLoginInitiate (OK=48 KO=0 ) 2024-11-07 01:14:38,564 INFO > restLoginUsernamePasswordCallback (OK=47 KO=0 ) 2024-11-07 01:14:38,564 INFO > Skip 2FA (OK=27 KO=0 ) 2024-11-07 01:14:38,564 INFO > User Authorize PKCE stage (OK=49 KO=0 ) 2024-11-07 01:14:38,564 INFO > User AccessToken PKCE stage (OK=48 KO=0 ) 2024-11-07 01:14:38,564 INFO > GetUUid (OK=12 KO=0 ) 2024-11-07 01:14:38,565 INFO > GetOpenidConfig (OK=12 KO=0 ) 2024-11-07 01:14:38,565 INFO > CreatePolicy (OK=12 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Post-Login - stage 1 (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > RootUserinfo (OK=11 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI AM idFromSession (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI AM validateGoto (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Post-Login - stage 2 (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI Enduser appAuthHelper1 (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI Enduser appAuthHelper2 (OK=6 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Post-Login - stage 3 (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI Enduser sessioncheck (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM uiconfig (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM version (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM privilege (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM features (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM login (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM dashboard (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM managed user schema (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM user (OK=5 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI IDM oidcToken (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > tokenUserinfo (OK=12 KO=0 ) 2024-11-07 01:14:38,565 INFO > userinfo (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Logout (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI-Logout Redirect 1 (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI AM endsession (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI AM revoke1 (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > UI AM revoke2 (OK=4 KO=0 ) 2024-11-07 01:14:38,565 INFO > getIdToken (OK=8 KO=0 ) 2024-11-07 01:14:38,565 INFO > getIdToken Redirect 1 (OK=8 KO=0 ) 2024-11-07 01:14:38,565 INFO > createOrganization (OK=7 KO=0 ) 2024-11-07 01:14:38,565 INFO > queryOrganization (OK=7 KO=0 ) 2024-11-07 01:14:38,565 INFO > deleteOrganization (OK=7 KO=0 ) 2024-11-07 01:14:38,565 INFO 2024-11-07 01:14:38,565 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-07 01:14:38,565 INFO [- ] 0% 2024-11-07 01:14:38,565 INFO waiting: 433976 / active: 26 / done: 24 2024-11-07 01:14:38,565 INFO ================================================================================ 2024-11-07 01:14:38,565 INFO 2024-11-07 01:14:38,565 INFO 2024-11-07 01:14:38,565 INFO ================================================================================ 2024-11-07 01:14:38,565 INFO 2024-11-07 00:14:21 GMT 10s elapsed 2024-11-07 01:14:38,565 INFO ---- Requests ------------------------------------------------------------------ 2024-11-07 01:14:38,565 INFO > Global (OK=2027 KO=0 ) 2024-11-07 01:14:38,565 INFO > loginTreeWorkflow_restLoginInitiate (OK=8 KO=0 ) 2024-11-07 01:14:38,565 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=7 KO=0 ) 2024-11-07 01:14:38,565 INFO > restLoginInitiate (OK=190 KO=0 ) 2024-11-07 01:14:38,565 INFO > restLoginUsernamePasswordCallback (OK=188 KO=0 ) 2024-11-07 01:14:38,565 INFO > Skip 2FA (OK=114 KO=0 ) 2024-11-07 01:14:38,565 INFO > User Authorize PKCE stage (OK=208 KO=0 ) 2024-11-07 01:14:38,565 INFO > User AccessToken PKCE stage (OK=205 KO=0 ) 2024-11-07 01:14:38,565 INFO [...] 2024-11-07 01:14:38,580 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-07 01:14:38,580 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-07 01:14:38,580 INFO Request: 2024-11-07 01:14:38,580 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-07 01:14:38,580 INFO ========================= 2024-11-07 01:14:38,580 INFO Session: 2024-11-07 01:14:38,580 INFO Session(idc.benchmark.Mix2024,430461,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.230236, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@28402c0b, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"5ji9MjRwD3f-ENBvv8wetIbtX6A.*AAJTSQACMDIAAlNLABwvTGdsRHp6N21BdVJ1clZrNUFkdUFQdVkyV1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1730942051142), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=5ji9MjRwD3f-ENBvv8wetIbtX6A.*AAJTSQACMDIAAlNLABwvTGdsRHp6N21BdVJ1clZrNUFkdUFQdVkyV1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1730942051142))), password -> Pa_ssw0rd, fake-ip -> 242.125.118.159, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@73c9f3ec, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@2a232078, tokenId -> 5ji9MjRwD3f-ENBvv8wetIbtX6A.*AAJTSQACMDIAAlNLABwvTGdsRHp6N21BdVJ1clZrNUFkdUFQdVkyV1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d6cf8699970@53e0e812,io.netty.channel.epoll.EpollEventLoop@1e1d3956) 2024-11-07 01:14:38,580 INFO ========================= 2024-11-07 01:14:38,580 INFO HTTP request: 2024-11-07 01:14:38,580 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-07 01:14:38,580 INFO headers: 2024-11-07 01:14:38,580 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-07 01:14:38,580 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-07 01:14:38,580 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-07 01:14:38,580 INFO accept: */* 2024-11-07 01:14:38,580 INFO cookie: amlbcookie=01; 9b75a55744995d0=5ji9MjRwD3f-ENBvv8wetIbtX6A.*AAJTSQACMDIAAlNLABwvTGdsRHp6N21BdVJ1clZrNUFkdUFQdVkyV1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-07 01:14:38,580 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-07 01:14:38,580 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-07 01:14:38,580 INFO content-length: 0 2024-11-07 01:14:38,580 INFO cookies: 2024-11-07 01:14:38,580 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-07 01:14:38,580 INFO 9b75a55744995d0=5ji9MjRwD3f-ENBvv8wetIbtX6A.*AAJTSQACMDIAAlNLABwvTGdsRHp6N21BdVJ1clZrNUFkdUFQdVkyV1E9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-07 01:14:38,580 INFO ========================= 2024-11-07 01:14:38,580 INFO HTTP response: 2024-11-07 01:14:38,580 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-07 01:14:38,580 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 430514: j.n.c.ClosedChannelException 2024-11-07 01:14:38,580 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-07 01:14:38,580 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-07 01:14:38,580 INFO Request: 2024-11-07 01:14:38,581 INFO restLoginInitiate: KO j.n.c.ClosedChannelException 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO Session: 2024-11-07 01:14:38,581 INFO Session(idc.benchmark.Mix2024,430514,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.871051, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1d78e3d3, 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@775d3ae3),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d6cf8699970@53e0e812,io.netty.channel.epoll.EpollEventLoop@14f5da2c) 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO HTTP request: 2024-11-07 01:14:38,581 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate?authIndexType=service&authIndexValue=Login 2024-11-07 01:14:38,581 INFO headers: 2024-11-07 01:14:38,581 INFO accept: application/json 2024-11-07 01:14:38,581 INFO content-type: application/json 2024-11-07 01:14:38,581 INFO user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0 2024-11-07 01:14:38,581 INFO X-Forwarded-For: 42.42.42.42 2024-11-07 01:14:38,581 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-07 01:14:38,581 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO HTTP response: 2024-11-07 01:14:38,581 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-07 01:14:38,581 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 430512: j.i.IOException: Premature close 2024-11-07 01:14:38,581 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-07 01:14:38,581 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-07 01:14:38,581 INFO Request: 2024-11-07 01:14:38,581 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO Session: 2024-11-07 01:14:38,581 INFO Session(idc.benchmark.Mix2024,430512,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.778843, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@389c2d73, fake-user-agent -> Mozilla/5.0 (Linux; Android 8.0.0; Pixel 2 Build/OPD3.170816.012) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36, password -> Pa_ssw0rd, fake-ip -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@385303e1),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d6cf8699970@53e0e812,io.netty.channel.epoll.EpollEventLoop@636e8cc) 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO HTTP request: 2024-11-07 01:14:38,581 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate 2024-11-07 01:14:38,581 INFO headers: 2024-11-07 01:14:38,581 INFO accept: application/json 2024-11-07 01:14:38,581 INFO content-type: application/json 2024-11-07 01:14:38,581 INFO user-agent: Mozilla/5.0 (Linux; Android 8.0.0; Pixel 2 Build/OPD3.170816.012) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36 2024-11-07 01:14:38,581 INFO X-Forwarded-For: 42.42.42.42 2024-11-07 01:14:38,581 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-07 01:14:38,581 INFO content-length: 0 2024-11-07 01:14:38,581 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO HTTP response: 2024-11-07 01:14:38,581 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-07 01:14:38,581 INFO 01:14:11.288 [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-07 01:14:38,581 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 430510: j.i.IOException: Premature close 2024-11-07 01:14:38,581 INFO 01:14:11.288 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-07 01:14:38,581 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-07 01:14:38,581 INFO Request: 2024-11-07 01:14:38,581 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO Session: 2024-11-07 01:14:38,581 INFO Session(idc.benchmark.Mix2024,430510,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.173248, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1dc854a8, 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 -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@23316c28),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007d6cf8699970@53e0e812,io.netty.channel.epoll.EpollEventLoop@4f2c9ba6) 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO HTTP request: 2024-11-07 01:14:38,581 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate 2024-11-07 01:14:38,581 INFO headers: 2024-11-07 01:14:38,581 INFO accept: application/json 2024-11-07 01:14:38,581 INFO content-type: application/json 2024-11-07 01:14:38,581 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-07 01:14:38,581 INFO X-Forwarded-For: 42.42.42.42 2024-11-07 01:14:38,581 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-07 01:14:38,581 INFO content-length: 0 2024-11-07 01:14:38,581 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-07 01:14:38,581 INFO ========================= 2024-11-07 01:14:38,581 INFO HTTP response: 2024-11-07 01:14:38,582 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-07 01:14:38,582 INFO 01:14:11.289 [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-07 01:14:38,582 INFO [INFO] ------------------------------------------------------------------------ 2024-11-07 01:14:38,582 INFO [INFO] BUILD SUCCESS 2024-11-07 01:14:38,582 INFO [INFO] ------------------------------------------------------------------------ 2024-11-07 01:14:38,582 INFO [INFO] Total time: 01:00 h 2024-11-07 01:14:38,582 INFO [INFO] Finished at: 2024-11-07T01:14:11Z 2024-11-07 01:14:38,582 INFO [INFO] ------------------------------------------------------------------------ 2024-11-07 01:14:38,582 INFO 2024-11-07 01:14:11,428 INFO Gatling simulation run ended successfully 2024-11-07 01:14:38,582 INFO 2024-11-07 01:14:11,428 DEBUG No archive name provided. No archive will be created 2024-11-07 01:14:38,582 INFO ________________________________________________________________________________ [2024-11-07 01:14:38] benchmark-120 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-07 01:14:38,582 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stderr.txt is small (0 lines), printing all lines: 2024-11-07 01:14:38,582 DEBUG ----- output ----- 2024-11-07 01:14:38,582 DEBUG 2024-11-07 01:14:38,582 INFO ________________________________________________________________________________ [2024-11-07 01:14:38] benchmark-120 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-07 01:14:38] benchmark-120 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-07 01:14:38] benchmark-120 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped