--Task-- name: benchmark-130 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-120'] preceding_task: benchmark-120 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self130-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 130} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-21 00:11:43] benchmark-130 pre : N/A ________________________________________________________________________________ 2024-11-21 00:11:43 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-21 00:11:43 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-130/stdout.txt Pod log : /results/orders/benchmark-130 2024-11-21 00:11:43,103 INFO 2024-11-21 00:11:43,103 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 00:11:43,104 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:43,375 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:43,376 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:43,376 DEBUG --- stdout --- 2024-11-21 00:11:43,376 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:43,376 DEBUG --- stderr --- 2024-11-21 00:11:43,376 DEBUG ________________________________________________________________________________ [2024-11-21 00:11:43] benchmark-130 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-21 00:11:43,376 INFO 2024-11-21 00:11:43,376 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 00:11:43,376 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:43,649 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:43,649 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:43,649 DEBUG --- stdout --- 2024-11-21 00:11:43,649 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:43,649 DEBUG --- stderr --- 2024-11-21 00:11:43,649 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-130" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self130- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=130 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-21 00:11:43] benchmark-130 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-21 00:11:43,649 INFO 2024-11-21 00:11:43,649 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 00:11:43,650 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:43,926 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:43,926 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:43,926 DEBUG --- stdout --- 2024-11-21 00:11:43,926 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:43,926 DEBUG --- stderr --- 2024-11-21 00:11:43,926 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/order.json { "name": "benchmark-130", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-130\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self130- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=130 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-130" } ________________________________________________________________________________ [2024-11-21 00:11:43] benchmark-130 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 00:11:43,929 INFO 2024-11-21 00:11:43,929 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-21 00:11:43,929 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 00:11:44,141 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 00:11:44,141 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:44,141 DEBUG --- stdout --- 2024-11-21 00:11:44,141 DEBUG WAITING 2024-11-21 00:11:44,141 DEBUG --- stderr --- 2024-11-21 00:11:44,141 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 00:11:44] benchmark-130 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-21 00:11:44,142 INFO 2024-11-21 00:11:44,142 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 00:11:44,142 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:44,416 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:44,417 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:44,417 DEBUG --- stdout --- 2024-11-21 00:11:44,417 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:44,417 DEBUG --- stderr --- 2024-11-21 00:11:44,417 DEBUG 2024-11-21 00:11:44,417 INFO 2024-11-21 00:11:44,417 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-21 00:11:44,417 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 00:11:45,749 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:45,749 DEBUG --- stdout --- 2024-11-21 00:11:45,749 DEBUG 2024-11-21 00:11:45,749 DEBUG --- stderr --- 2024-11-21 00:11:45,749 DEBUG Order has been successfully forwarded to overseer 2024-11-21 00:11:45 - INFO: Check if Gatling simulation started successfully 2024-11-21 00:11:45,750 INFO 2024-11-21 00:11:45,750 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 00:11:45,750 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:46,022 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:46,022 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:46,022 DEBUG --- stdout --- 2024-11-21 00:11:46,022 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:46,022 DEBUG --- stderr --- 2024-11-21 00:11:46,022 DEBUG 2024-11-21 00:11:46,023 INFO 2024-11-21 00:11:46,023 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-130/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-21 00:11:46,023 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 00:11:46,742 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 00:11:52,463 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 00:11:58,180 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-21 00:11:58,180 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:58,180 DEBUG --- stdout --- 2024-11-21 00:11:58,180 DEBUG 2024-11-21 00:11:46,734 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpqt4qent0 2024-11-21 00:11:46,736 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-130" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self130- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=130 -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/tmpqt4qent0/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/tmpqt4qent0/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 00:11:58,180 DEBUG --- stderr --- 2024-11-21 00:11:58,180 DEBUG ________________________________________________________________________________ [2024-11-21 00:11:58] benchmark-130 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 02s, retry Order is running since 22m 03s, retry Order is running since 24m 03s, retry Order is running since 26m 03s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 04s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 05s, retry Order is running since 40m 05s, retry Order is running since 42m 06s, retry Order is running since 44m 06s, retry Order is running since 46m 06s, retry Order is running since 48m 07s, retry Order is running since 50m 07s, retry Order is running since 52m 07s, retry Order is running since 54m 07s, retry Order is running since 56m 08s, retry Order is running since 58m 08s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-21 01:12:07] benchmark-130 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-21 01:12:07,110 INFO 2024-11-21 01:12:07,110 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 01:12:07,110 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:07,408 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:07,408 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:07,408 DEBUG --- stdout --- 2024-11-21 01:12:07,408 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:07,408 DEBUG --- stderr --- 2024-11-21 01:12:07,408 DEBUG 2024-11-21 01:12:07,408 INFO 2024-11-21 01:12:07,408 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 01:12:07,408 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 01:12:08,171 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:08,171 DEBUG --- stdout --- 2024-11-21 01:12:08,171 DEBUG 2024-11-21 01:12:08,171 DEBUG --- stderr --- 2024-11-21 01:12:08,171 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-21 01:12:08] benchmark-130 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-21 01:12:08 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/order.json 2024-11-21 01:12:08,171 INFO 2024-11-21 01:12:08,171 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 01:12:08,171 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:08,442 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:08,443 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:08,443 DEBUG --- stdout --- 2024-11-21 01:12:08,443 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:08,443 DEBUG --- stderr --- 2024-11-21 01:12:08,443 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 01:12:08,443 INFO 2024-11-21 01:12:08,443 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 01:12:08,443 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:08,745 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:08,745 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:08,745 DEBUG --- stdout --- 2024-11-21 01:12:08,745 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:08,745 DEBUG --- stderr --- 2024-11-21 01:12:08,746 DEBUG 2024-11-21 01:12:08,746 INFO 2024-11-21 01:12:08,746 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-130/rc.txt" ]; then echo "/results/orders/benchmark-130/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-130/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-130/rc.txt file found" 2024-11-21 01:12:08,746 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 01:12:09,526 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 01:12:09,526 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:09,526 DEBUG --- stdout --- 2024-11-21 01:12:09,526 DEBUG /results/orders/benchmark-130/rc.txt file found 2024-11-21 01:12:09,526 DEBUG --- stderr --- 2024-11-21 01:12:09,526 DEBUG 2024-11-21 01:12:09,526 INFO 2024-11-21 01:12:09,526 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 01:12:09,526 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:09,798 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:09,798 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:09,798 DEBUG --- stdout --- 2024-11-21 01:12:09,798 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:09,798 DEBUG --- stderr --- 2024-11-21 01:12:09,798 DEBUG 2024-11-21 01:12:09,798 INFO 2024-11-21 01:12:09,798 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-130/rc.txt 2024-11-21 01:12:10,582 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 01:12:10,582 DEBUG --- stdout --- 2024-11-21 01:12:10,582 DEBUG 4 /results/orders/benchmark-130/rc.txt 2024-11-21 01:12:10,582 DEBUG --- stderr --- 2024-11-21 01:12:10,582 DEBUG 2024-11-21 01:12:10,582 INFO - Download file (size 4k) 2024-11-21 01:12:10,582 INFO 2024-11-21 01:12:10,582 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 01:12:10,582 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:10,852 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:10,852 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:10,852 DEBUG --- stdout --- 2024-11-21 01:12:10,852 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:10,852 DEBUG --- stderr --- 2024-11-21 01:12:10,852 DEBUG source : /results/orders/benchmark-130/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/rc.txt 2024-11-21 01:12:10,852 INFO 2024-11-21 01:12:10,852 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 01:12:10,852 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:11,125 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:11,125 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:11,125 DEBUG --- stdout --- 2024-11-21 01:12:11,125 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:11,125 DEBUG --- stderr --- 2024-11-21 01:12:11,125 DEBUG 2024-11-21 01:12:11,126 INFO 2024-11-21 01:12:11,126 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-130/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/rc.txt 2024-11-21 01:12:11,126 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 01:12:11,870 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:11,871 DEBUG --- stdout --- 2024-11-21 01:12:11,871 DEBUG tar: Removing leading `/' from member names 2024-11-21 01:12:11,871 DEBUG --- stderr --- 2024-11-21 01:12:11,871 DEBUG 2024-11-21 01:12:11,871 INFO 2024-11-21 01:12:11,871 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 01:12:11,871 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:12,143 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:12,143 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:12,143 DEBUG --- stdout --- 2024-11-21 01:12:12,143 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:12,143 DEBUG --- stderr --- 2024-11-21 01:12:12,143 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 01:12:12,144 INFO 2024-11-21 01:12:12,144 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 01:12:12,144 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:12,418 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:12,418 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:12,418 DEBUG --- stdout --- 2024-11-21 01:12:12,418 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:12,418 DEBUG --- stderr --- 2024-11-21 01:12:12,418 DEBUG 2024-11-21 01:12:12,419 INFO 2024-11-21 01:12:12,419 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-130/stderr.txt" ]; then echo "/results/orders/benchmark-130/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-130/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-130/stderr.txt file found" 2024-11-21 01:12:12,419 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 01:12:13,262 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 01:12:13,262 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:13,262 DEBUG --- stdout --- 2024-11-21 01:12:13,263 DEBUG /results/orders/benchmark-130/stderr.txt file found 2024-11-21 01:12:13,263 DEBUG --- stderr --- 2024-11-21 01:12:13,263 DEBUG 2024-11-21 01:12:13,263 INFO 2024-11-21 01:12:13,263 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 01:12:13,263 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:13,555 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:13,555 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:13,555 DEBUG --- stdout --- 2024-11-21 01:12:13,555 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:13,555 DEBUG --- stderr --- 2024-11-21 01:12:13,555 DEBUG 2024-11-21 01:12:13,555 INFO 2024-11-21 01:12:13,555 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-130/stderr.txt 2024-11-21 01:12:14,349 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 01:12:14,349 DEBUG --- stdout --- 2024-11-21 01:12:14,349 DEBUG 0 /results/orders/benchmark-130/stderr.txt 2024-11-21 01:12:14,349 DEBUG --- stderr --- 2024-11-21 01:12:14,349 DEBUG 2024-11-21 01:12:14,349 INFO - Download file (size 0k) 2024-11-21 01:12:14,350 INFO 2024-11-21 01:12:14,350 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 01:12:14,350 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:14,622 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:14,623 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:14,623 DEBUG --- stdout --- 2024-11-21 01:12:14,623 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:14,623 DEBUG --- stderr --- 2024-11-21 01:12:14,623 DEBUG source : /results/orders/benchmark-130/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/stderr.txt 2024-11-21 01:12:14,623 INFO 2024-11-21 01:12:14,623 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 01:12:14,623 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:14,899 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:14,899 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:14,899 DEBUG --- stdout --- 2024-11-21 01:12:14,899 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:14,899 DEBUG --- stderr --- 2024-11-21 01:12:14,899 DEBUG 2024-11-21 01:12:14,900 INFO 2024-11-21 01:12:14,900 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-130/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/stderr.txt 2024-11-21 01:12:14,900 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 01:12:15,644 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:15,644 DEBUG --- stdout --- 2024-11-21 01:12:15,644 DEBUG tar: Removing leading `/' from member names 2024-11-21 01:12:15,644 DEBUG --- stderr --- 2024-11-21 01:12:15,644 DEBUG 2024-11-21 01:12:15,645 INFO 2024-11-21 01:12:15,645 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 01:12:15,645 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:15,917 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:15,917 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:15,917 DEBUG --- stdout --- 2024-11-21 01:12:15,917 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:15,917 DEBUG --- stderr --- 2024-11-21 01:12:15,917 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 01:12:15,917 INFO 2024-11-21 01:12:15,917 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 01:12:15,917 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:16,190 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:16,190 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:16,190 DEBUG --- stdout --- 2024-11-21 01:12:16,190 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:16,190 DEBUG --- stderr --- 2024-11-21 01:12:16,190 DEBUG 2024-11-21 01:12:16,190 INFO 2024-11-21 01:12:16,191 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-130/stdout.txt" ]; then echo "/results/orders/benchmark-130/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-130/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-130/stdout.txt file found" 2024-11-21 01:12:16,191 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 01:12:16,975 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 01:12:16,975 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:16,975 DEBUG --- stdout --- 2024-11-21 01:12:16,975 DEBUG /results/orders/benchmark-130/stdout.txt file found 2024-11-21 01:12:16,975 DEBUG --- stderr --- 2024-11-21 01:12:16,975 DEBUG 2024-11-21 01:12:16,975 INFO 2024-11-21 01:12:16,975 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 01:12:16,975 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:17,248 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:17,248 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:17,248 DEBUG --- stdout --- 2024-11-21 01:12:17,248 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:17,248 DEBUG --- stderr --- 2024-11-21 01:12:17,248 DEBUG 2024-11-21 01:12:17,248 INFO 2024-11-21 01:12:17,249 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-130/stdout.txt 2024-11-21 01:12:18,031 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 01:12:18,031 DEBUG --- stdout --- 2024-11-21 01:12:18,031 DEBUG 5025968 /results/orders/benchmark-130/stdout.txt 2024-11-21 01:12:18,031 DEBUG --- stderr --- 2024-11-21 01:12:18,031 DEBUG 2024-11-21 01:12:18,031 INFO - Download file (size 5025968k) 2024-11-21 01:12:18,032 INFO 2024-11-21 01:12:18,032 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 01:12:18,032 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:18,305 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:18,305 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:18,305 DEBUG --- stdout --- 2024-11-21 01:12:18,305 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:18,305 DEBUG --- stderr --- 2024-11-21 01:12:18,305 DEBUG source : /results/orders/benchmark-130/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/stdout.txt 2024-11-21 01:12:18,306 INFO 2024-11-21 01:12:18,306 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 01:12:18,306 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:12:18,577 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:12:18,577 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:12:18,577 DEBUG --- stdout --- 2024-11-21 01:12:18,577 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:12:18,577 DEBUG --- stderr --- 2024-11-21 01:12:18,577 DEBUG 2024-11-21 01:12:18,578 INFO 2024-11-21 01:12:18,578 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-130/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/stdout.txt 2024-11-21 01:12:18,578 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 01:14:37,511 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:37,512 DEBUG --- stdout --- 2024-11-21 01:14:37,512 DEBUG tar: Removing leading `/' from member names 2024-11-21 01:14:37,512 DEBUG --- stderr --- 2024-11-21 01:14:37,512 DEBUG ________________________________________________________________________________ [2024-11-21 01:14:37] benchmark-130 show_cmd : Display order command ________________________________________________________________________________ 2024-11-21 01:14:37,512 INFO 2024-11-21 01:14:37,512 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 01:14:37,512 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:14:37,807 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:14:37,807 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:37,807 DEBUG --- stdout --- 2024-11-21 01:14:37,807 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:14:37,807 DEBUG --- stderr --- 2024-11-21 01:14:37,807 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 01:14:37,807 INFO 2024-11-21 01:14:37,807 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 01:14:37,807 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:14:38,077 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:14:38,077 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:38,077 DEBUG --- stdout --- 2024-11-21 01:14:38,077 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:14:38,077 DEBUG --- stderr --- 2024-11-21 01:14:38,077 DEBUG 2024-11-21 01:14:38,077 INFO 2024-11-21 01:14:38,077 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-130/cmd.txt" ]; then echo "/results/orders/benchmark-130/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-130/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-130/cmd.txt file found" 2024-11-21 01:14:38,078 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 01:14:38,940 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 01:14:38,940 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:38,940 DEBUG --- stdout --- 2024-11-21 01:14:38,940 DEBUG /results/orders/benchmark-130/cmd.txt file found 2024-11-21 01:14:38,940 DEBUG --- stderr --- 2024-11-21 01:14:38,940 DEBUG 2024-11-21 01:14:38,941 INFO 2024-11-21 01:14:38,941 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 01:14:38,941 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:14:39,213 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:14:39,213 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:39,213 DEBUG --- stdout --- 2024-11-21 01:14:39,213 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:14:39,213 DEBUG --- stderr --- 2024-11-21 01:14:39,213 DEBUG 2024-11-21 01:14:39,214 INFO 2024-11-21 01:14:39,214 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-130/cmd.txt 2024-11-21 01:14:40,001 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 01:14:40,001 DEBUG --- stdout --- 2024-11-21 01:14:40,001 DEBUG 4 /results/orders/benchmark-130/cmd.txt 2024-11-21 01:14:40,001 DEBUG --- stderr --- 2024-11-21 01:14:40,001 DEBUG 2024-11-21 01:14:40,001 INFO - Download file (size 4k) 2024-11-21 01:14:40,001 INFO 2024-11-21 01:14:40,002 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 01:14:40,002 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:14:40,275 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:14:40,275 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:40,275 DEBUG --- stdout --- 2024-11-21 01:14:40,275 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:14:40,275 DEBUG --- stderr --- 2024-11-21 01:14:40,275 DEBUG source : /results/orders/benchmark-130/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/cmd.txt 2024-11-21 01:14:40,275 INFO 2024-11-21 01:14:40,276 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 01:14:40,276 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:14:40,549 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:14:40,549 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:40,549 DEBUG --- stdout --- 2024-11-21 01:14:40,549 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:14:40,549 DEBUG --- stderr --- 2024-11-21 01:14:40,549 DEBUG 2024-11-21 01:14:40,549 INFO 2024-11-21 01:14:40,549 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-130/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/cmd.txt 2024-11-21 01:14:40,549 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 01:14:41,305 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:14:41,305 DEBUG --- stdout --- 2024-11-21 01:14:41,305 DEBUG tar: Removing leading `/' from member names 2024-11-21 01:14:41,305 DEBUG --- stderr --- 2024-11-21 01:14:41,305 DEBUG 2024-11-21 01:14:41,305 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/cmd.txt is small (1 lines), printing all lines: 2024-11-21 01:14:41,305 DEBUG ----- output ----- 2024-11-21 01:14:41,305 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-130" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self130- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=130 -Duser_password=Pa_ssw0rd" 2024-11-21 01:14:41,305 INFO ________________________________________________________________________________ [2024-11-21 01:14:41] benchmark-130 show_rc : Display rc order ________________________________________________________________________________ 2024-11-21 01:14:41,305 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/rc.txt is small (1 lines), printing all lines: 2024-11-21 01:14:41,305 DEBUG ----- output ----- 2024-11-21 01:14:41,305 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-21 01:14:41,305 INFO ________________________________________________________________________________ [2024-11-21 01:14:41] benchmark-130 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-21 01:14:47,428 DEBUG [print_head_tail]: Print head (100 lines) and tail (100 lines) of input file (/mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/stdout.txt is 46035261 lines): 2024-11-21 01:14:47,428 DEBUG ----- output ----- 2024-11-21 01:14:47,428 INFO 2024-11-21 00:11:46,734 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpqt4qent0 2024-11-21 01:14:47,428 INFO 2024-11-21 00:11:46,736 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-130" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self130- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=130 -Duser_password=**** 2024-11-21 01:14:47,428 INFO [INFO] Scanning for projects... 2024-11-21 01:14:47,428 INFO [INFO] 2024-11-21 01:14:47,428 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-21 01:14:47,428 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-21 01:14:47,428 INFO [INFO] from pom.xml 2024-11-21 01:14:47,428 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-21 01:14:47,428 INFO [INFO] 2024-11-21 01:14:47,428 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-21 01:14:47,428 INFO [INFO] 2024-11-21 01:14:47,428 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-21 01:14:47,428 INFO [INFO] skip non existing resourceDirectory /tmp/tmpqt4qent0/src/main/resources 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-21 01:14:47,429 INFO [INFO] No sources to compile 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-21 01:14:47,429 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-21 01:14:47,429 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-21 01:14:47,429 INFO [INFO] compiling 38 Scala sources to /tmp/tmpqt4qent0/target/test-classes ... 2024-11-21 01:14:47,429 INFO [INFO] compile in 6.9 s 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] 2024-11-21 01:14:47,429 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-21 01:14:47,429 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-21 01:14:47,429 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-21 01:14:47,429 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-21 01:14:47,429 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-21 01:14:47,429 INFO 00:12:02.190 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,429 INFO 2024-11-21 01:14:47,429 INFO ================================================================================ 2024-11-21 01:14:47,429 INFO 2024-11-21 00:12:02 GMT 5s elapsed 2024-11-21 01:14:47,429 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 01:14:47,429 INFO > Global (OK=567 KO=0 ) 2024-11-21 01:14:47,429 INFO > restLoginInitiate (OK=53 KO=0 ) 2024-11-21 01:14:47,429 INFO > restLoginUsernamePasswordCallback (OK=51 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Post-Login - stage 1 (OK=12 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=11 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI AM idFromSession (OK=11 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI AM validateGoto (OK=11 KO=0 ) 2024-11-21 01:14:47,429 INFO > User Authorize PKCE stage (OK=55 KO=0 ) 2024-11-21 01:14:47,429 INFO > User AccessToken PKCE stage (OK=55 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Post-Login - stage 2 (OK=10 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=10 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI Enduser appAuthHelper1 (OK=10 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI Enduser appAuthHelper2 (OK=10 KO=0 ) 2024-11-21 01:14:47,429 INFO > Skip 2FA (OK=29 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Post-Login - stage 3 (OK=9 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI Enduser sessioncheck (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM uiconfig (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM version (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM privilege (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM features (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM login (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > GetUUid (OK=18 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM dashboard (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM managed user schema (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM user (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > GetOpenidConfig (OK=18 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI IDM oidcToken (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > CreatePolicy (OK=17 KO=0 ) 2024-11-21 01:14:47,429 INFO > userinfo (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Logout (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI-Logout Redirect 1 (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI AM revoke1 (OK=7 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI AM revoke2 (OK=7 KO=0 ) 2024-11-21 01:14:47,429 INFO > UI AM endsession (OK=8 KO=0 ) 2024-11-21 01:14:47,429 INFO > RootUserinfo (OK=22 KO=0 ) 2024-11-21 01:14:47,429 INFO > tokenUserinfo (OK=7 KO=0 ) 2024-11-21 01:14:47,430 INFO > restloginProgressiveProfileCallback (OK=4 KO=0 ) 2024-11-21 01:14:47,430 INFO > getIdToken (OK=2 KO=0 ) 2024-11-21 01:14:47,430 INFO > getIdToken Redirect 1 (OK=2 KO=0 ) 2024-11-21 01:14:47,430 INFO > createOrganization (OK=2 KO=0 ) 2024-11-21 01:14:47,430 INFO > queryOrganization (OK=2 KO=0 ) 2024-11-21 01:14:47,430 INFO > deleteOrganization (OK=2 KO=0 ) 2024-11-21 01:14:47,430 INFO ---- Errors -------------------------------------------------------------------- 2024-11-21 01:14:47,430 INFO > tokenUserinfo: No attribute named 'access_token' is defined 1 (100.0%) 2024-11-21 01:14:47,430 INFO 2024-11-21 01:14:47,430 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-21 01:14:47,430 INFO [- ] 0% 2024-11-21 01:14:47,430 INFO waiting: 469639 / active: 37 / done: 17 2024-11-21 01:14:47,430 INFO ================================================================================ 2024-11-21 01:14:47,430 INFO 2024-11-21 01:14:47,430 INFO 00:12:02.821 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:03.521 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:03.925 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:04.211 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:04.356 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:05.399 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:05.824 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:07.038 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO 00:12:07.297 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:14:47,430 INFO [...] 2024-11-21 01:14:55,617 INFO java.util.concurrent.RejectedExecutionException: Task io.gatling.core.actor.AtomicRunnableActorRef@6ef7ce19 rejected from java.util.concurrent.ThreadPoolExecutor@7f261f7[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 10490418] 2024-11-21 01:14:55,617 INFO at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) 2024-11-21 01:14:55,617 INFO at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) 2024-11-21 01:14:55,617 INFO at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365) 2024-11-21 01:14:55,617 INFO at scala.concurrent.impl.ExecutionContextImpl.execute(ExecutionContextImpl.scala:21) 2024-11-21 01:14:55,617 INFO at io.gatling.core.actor.AtomicRunnableActorRef.async(ActorSystem.scala:95) 2024-11-21 01:14:55,617 INFO at io.gatling.core.actor.AtomicRunnableActorRef.$bang(ActorSystem.scala:70) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Exit.execute(Exit.scala:29) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Action.$bang(Action.scala:42) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Action.$bang$(Action.scala:39) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Exit.$bang(Exit.scala:23) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitHere.$anonfun$execute$1(ExitHere.scala:45) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitHere.$anonfun$execute$1$adapted(ExitHere.scala:30) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Success.map(Validation.scala:41) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Validation.map$mcZ$sp(Validation.scala:28) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Validation.map$mcZ$sp$(Validation.scala:28) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Success.map$mcZ$sp(Validation.scala:40) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitHere.execute(ExitHere.scala:30) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Action.$bang(Action.scala:42) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Action.$bang$(Action.scala:39) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitHere.io$gatling$core$action$ChainableAction$$super$$bang(ExitHere.scala:24) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ChainableAction.$bang(Action.scala:75) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ChainableAction.$bang$(Action.scala:73) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitHere.$bang(ExitHere.scala:24) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ChainableAction.$bang(Action.scala:85) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ChainableAction.$bang$(Action.scala:73) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.builder.SessionHookBuilder$$anon$1.io$gatling$core$action$ExitableAction$$super$$bang(SessionHookBuilder.scala:28) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitableAction.$bang(Action.scala:111) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitableAction.$bang$(Action.scala:108) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.builder.SessionHookBuilder$$anon$1.$bang(SessionHookBuilder.scala:28) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.If.$anonfun$execute$1(If.scala:44) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.If.$anonfun$execute$1$adapted(If.scala:42) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Success.map(Validation.scala:41) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Validation.map$mcZ$sp(Validation.scala:28) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Validation.map$mcZ$sp$(Validation.scala:28) 2024-11-21 01:14:55,618 INFO at io.gatling.commons.validation.Success.map$mcZ$sp(Validation.scala:40) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.If.execute(If.scala:42) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Action.$bang(Action.scala:42) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.Action.$bang$(Action.scala:39) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.If.io$gatling$core$action$ChainableAction$$super$$bang(If.scala:24) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ChainableAction.$bang(Action.scala:75) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ChainableAction.$bang$(Action.scala:73) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.If.io$gatling$core$action$ExitableAction$$super$$bang(If.scala:24) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitableAction.$bang(Action.scala:111) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.ExitableAction.$bang$(Action.scala:108) 2024-11-21 01:14:55,618 INFO at io.gatling.core.action.If.$bang(If.scala:24) 2024-11-21 01:14:55,618 INFO at io.gatling.http.engine.response.RootNextExecutor.executeNextOnCrash(NextExecutor.scala:46) 2024-11-21 01:14:55,618 INFO at io.gatling.http.engine.response.DefaultResponseProcessor.onComplete(ResponseProcessor.scala:160) 2024-11-21 01:14:55,618 INFO at io.gatling.http.engine.GatlingHttpListener.onThrowable(GatlingHttpListener.scala:237) 2024-11-21 01:14:55,618 INFO at io.gatling.http.client.impl.HttpAppHandler.crash(HttpAppHandler.java:83) 2024-11-21 01:14:55,618 INFO at io.gatling.http.client.impl.HttpAppHandler.channelInactive(HttpAppHandler.java:265) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274) 2024-11-21 01:14:55,618 INFO at io.netty.handler.stream.ChunkedWriteHandler.channelInactive(ChunkedWriteHandler.java:152) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274) 2024-11-21 01:14:55,618 INFO at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) 2024-11-21 01:14:55,618 INFO at io.netty.handler.codec.http.HttpContentDecoder.channelInactive(HttpContentDecoder.java:235) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274) 2024-11-21 01:14:55,618 INFO at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelInactive(CombinedChannelDuplexHandler.java:418) 2024-11-21 01:14:55,618 INFO at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:412) 2024-11-21 01:14:55,618 INFO at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:377) 2024-11-21 01:14:55,618 INFO at io.netty.handler.codec.http.HttpClientCodec$Decoder.channelInactive(HttpClientCodec.java:410) 2024-11-21 01:14:55,618 INFO at io.netty.channel.CombinedChannelDuplexHandler.channelInactive(CombinedChannelDuplexHandler.java:221) 2024-11-21 01:14:55,618 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274) 2024-11-21 01:14:55,619 INFO at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:412) 2024-11-21 01:14:55,619 INFO at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:377) 2024-11-21 01:14:55,619 INFO at io.netty.handler.ssl.SslHandler.channelInactive(SslHandler.java:1172) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274) 2024-11-21 01:14:55,619 INFO at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1352) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:301) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281) 2024-11-21 01:14:55,619 INFO at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:850) 2024-11-21 01:14:55,619 INFO at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:811) 2024-11-21 01:14:55,619 INFO at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) 2024-11-21 01:14:55,619 INFO at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) 2024-11-21 01:14:55,619 INFO at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) 2024-11-21 01:14:55,619 INFO at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:408) 2024-11-21 01:14:55,619 INFO at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) 2024-11-21 01:14:55,619 INFO at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 2024-11-21 01:14:55,619 INFO at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 2024-11-21 01:14:55,619 INFO at java.base/java.lang.Thread.run(Thread.java:840) 2024-11-21 01:14:55,619 INFO 01:11:57.887 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'ReadPolicy' failed for user 440022: j.i.IOException: Premature close 2024-11-21 01:14:55,619 INFO 01:11:57.888 [ERROR] i.g.c.a.ExitHere - 'exitHere-103' crashed with 'j.u.c.RejectedExecutionException: Task io.gatling.core.actor.AtomicRunnableActorRef@6ef7ce19 rejected from java.util.concurrent.ThreadPoolExecutor@7f261f7[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 10490418]', forwarding to the next one 2024-11-21 01:14:55,619 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 01:14:55,619 INFO [INFO] BUILD SUCCESS 2024-11-21 01:14:55,619 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 01:14:55,619 INFO [INFO] Total time: 01:00 h 2024-11-21 01:14:55,619 INFO [INFO] Finished at: 2024-11-21T01:11:58Z 2024-11-21 01:14:55,619 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 01:14:55,619 INFO 2024-11-21 01:11:58,451 INFO Gatling simulation run ended successfully 2024-11-21 01:14:55,619 INFO 2024-11-21 01:11:58,451 DEBUG No archive name provided. No archive will be created 2024-11-21 01:14:55,619 INFO ________________________________________________________________________________ [2024-11-21 01:14:55] benchmark-130 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-21 01:14:55,619 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-130/stderr.txt is small (0 lines), printing all lines: 2024-11-21 01:14:55,619 DEBUG ----- output ----- 2024-11-21 01:14:55,619 DEBUG 2024-11-21 01:14:55,619 INFO ________________________________________________________________________________ [2024-11-21 01:14:55] benchmark-130 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 01:16:05] benchmark-130 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-21 01:16:05] benchmark-130 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped