--Task-- name: benchmark-80 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates below loop: False interval: None dependencies: [] wait_for: ['benchmark-70'] preceding_task: benchmark-70 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 80} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-13 10:38:11] benchmark-80 pre : N/A ________________________________________________________________________________ 2024-11-13 10:38:11 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-13 10:38:11 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-80/stdout.txt Pod log : /results/orders/benchmark-80 2024-11-13 10:38:11,019 INFO 2024-11-13 10:38:11,019 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-13 10:38:11,019 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 10:38:11,307 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 10:38:11,307 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:11,307 DEBUG --- stdout --- 2024-11-13 10:38:11,307 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 10:38:11,307 DEBUG --- stderr --- 2024-11-13 10:38:11,307 DEBUG ________________________________________________________________________________ [2024-11-13 10:38:11] benchmark-80 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-13 10:38:11,307 INFO 2024-11-13 10:38:11,307 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-13 10:38:11,307 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 10:38:11,593 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 10:38:11,593 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:11,593 DEBUG --- stdout --- 2024-11-13 10:38:11,593 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 10:38:11,593 DEBUG --- stderr --- 2024-11-13 10:38:11,593 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-80" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-13 10:38:11] benchmark-80 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-13 10:38:11,594 INFO 2024-11-13 10:38:11,594 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-13 10:38:11,594 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 10:38:11,879 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 10:38:11,879 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:11,879 DEBUG --- stdout --- 2024-11-13 10:38:11,880 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 10:38:11,880 DEBUG --- stderr --- 2024-11-13 10:38:11,880 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/order.json { "name": "benchmark-80", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-80\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-80" } ________________________________________________________________________________ [2024-11-13 10:38:11] benchmark-80 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2024-11-13 10:38:11,883 INFO 2024-11-13 10:38:11,883 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-13 10:38:11,883 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-13 10:38:12,110 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-13 10:38:12,111 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:12,111 DEBUG --- stdout --- 2024-11-13 10:38:12,111 DEBUG WAITING 2024-11-13 10:38:12,111 DEBUG --- stderr --- 2024-11-13 10:38:12,111 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 31 0 --:--:-- --:--:-- --:--:-- 31 ________________________________________________________________________________ [2024-11-13 10:38:12] benchmark-80 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-13 10:38:12,111 INFO 2024-11-13 10:38:12,111 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-13 10:38:12,111 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 10:38:12,398 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 10:38:12,398 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:12,398 DEBUG --- stdout --- 2024-11-13 10:38:12,398 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 10:38:12,398 DEBUG --- stderr --- 2024-11-13 10:38:12,398 DEBUG 2024-11-13 10:38:12,399 INFO 2024-11-13 10:38:12,399 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-80/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-13 10:38:12,399 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-13 10:38:13,802 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:13,802 DEBUG --- stdout --- 2024-11-13 10:38:13,802 DEBUG 2024-11-13 10:38:13,802 DEBUG --- stderr --- 2024-11-13 10:38:13,802 DEBUG Order has been successfully forwarded to overseer 2024-11-13 10:38:13 - INFO: Check if Gatling simulation started successfully 2024-11-13 10:38:13,802 INFO 2024-11-13 10:38:13,802 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-13 10:38:13,802 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 10:38:14,086 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 10:38:14,086 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:14,086 DEBUG --- stdout --- 2024-11-13 10:38:14,086 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 10:38:14,086 DEBUG --- stderr --- 2024-11-13 10:38:14,086 DEBUG 2024-11-13 10:38:14,086 INFO 2024-11-13 10:38:14,086 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- head --lines 5000 /results/orders/benchmark-80/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-13 10:38:14,086 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-13 10:38:14,833 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-13 10:38:20,588 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-13 10:38:26,341 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-13 10:38:26,341 INFO [loop_until]: OK (rc = 0) 2024-11-13 10:38:26,341 DEBUG --- stdout --- 2024-11-13 10:38:26,341 DEBUG 2024-11-13 10:38:14,558 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpg2w2mawd 2024-11-13 10:38:14,560 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-80" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=**** [INFO] Scanning for projects... [INFO] [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- [INFO] Building pyrock-gatling-simulation 3.12.0 [INFO] from pom.xml [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> [INFO] [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- [INFO] skip non existing resourceDirectory /tmp/tmpg2w2mawd/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/tmpg2w2mawd/target/test-classes ... [INFO] compile in 6.7 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-13 10:38:26,341 DEBUG --- stderr --- 2024-11-13 10:38:26,341 DEBUG ________________________________________________________________________________ [2024-11-13 10:38:26] benchmark-80 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 03s, retry Order is running since 22m 03s, retry Order is running since 24m 03s, retry Order is running since 26m 04s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 06s, retry Order is running since 40m 06s, retry Order is running since 42m 06s, 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 07s, retry Order is running since 52m 08s, retry Order is running since 54m 08s, retry Order is running since 56m 08s, retry Order is running since 58m 09s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-13 11:38:35] benchmark-80 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-13 11:38:35,812 INFO 2024-11-13 11:38:35,812 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-13 11:38:35,812 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:36,145 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:36,145 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:36,145 DEBUG --- stdout --- 2024-11-13 11:38:36,145 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:36,145 DEBUG --- stderr --- 2024-11-13 11:38:36,145 DEBUG 2024-11-13 11:38:36,146 INFO 2024-11-13 11:38:36,146 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-13 11:38:36,146 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-13 11:38:36,950 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:36,950 DEBUG --- stdout --- 2024-11-13 11:38:36,950 DEBUG 2024-11-13 11:38:36,950 DEBUG --- stderr --- 2024-11-13 11:38:36,950 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-13 11:38:36] benchmark-80 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-13 11:38:36 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/order.json 2024-11-13 11:38:36,951 INFO 2024-11-13 11:38:36,951 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-13 11:38:36,951 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:37,234 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:37,234 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:37,234 DEBUG --- stdout --- 2024-11-13 11:38:37,234 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:37,234 DEBUG --- stderr --- 2024-11-13 11:38:37,235 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-13 11:38:37,235 INFO 2024-11-13 11:38:37,235 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-13 11:38:37,235 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:37,517 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:37,517 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:37,517 DEBUG --- stdout --- 2024-11-13 11:38:37,517 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:37,517 DEBUG --- stderr --- 2024-11-13 11:38:37,517 DEBUG 2024-11-13 11:38:37,518 INFO 2024-11-13 11:38:37,518 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-80/rc.txt" ]; then echo "/results/orders/benchmark-80/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-80/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/rc.txt file found" 2024-11-13 11:38:37,518 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-13 11:38:38,339 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-13 11:38:38,339 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:38,339 DEBUG --- stdout --- 2024-11-13 11:38:38,339 DEBUG /results/orders/benchmark-80/rc.txt file found 2024-11-13 11:38:38,339 DEBUG --- stderr --- 2024-11-13 11:38:38,339 DEBUG 2024-11-13 11:38:38,339 INFO 2024-11-13 11:38:38,339 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-13 11:38:38,339 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:38,622 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:38,622 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:38,622 DEBUG --- stdout --- 2024-11-13 11:38:38,622 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:38,622 DEBUG --- stderr --- 2024-11-13 11:38:38,622 DEBUG 2024-11-13 11:38:38,622 INFO 2024-11-13 11:38:38,623 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-80/rc.txt 2024-11-13 11:38:39,447 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-13 11:38:39,447 DEBUG --- stdout --- 2024-11-13 11:38:39,447 DEBUG 4 /results/orders/benchmark-80/rc.txt 2024-11-13 11:38:39,447 DEBUG --- stderr --- 2024-11-13 11:38:39,447 DEBUG 2024-11-13 11:38:39,447 INFO - Download file (size 4k) 2024-11-13 11:38:39,447 INFO 2024-11-13 11:38:39,447 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-13 11:38:39,447 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:39,730 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:39,731 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:39,731 DEBUG --- stdout --- 2024-11-13 11:38:39,731 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:39,731 DEBUG --- stderr --- 2024-11-13 11:38:39,731 DEBUG source : /results/orders/benchmark-80/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/rc.txt 2024-11-13 11:38:39,731 INFO 2024-11-13 11:38:39,731 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-13 11:38:39,731 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:40,019 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:40,019 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:40,019 DEBUG --- stdout --- 2024-11-13 11:38:40,019 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:40,019 DEBUG --- stderr --- 2024-11-13 11:38:40,019 DEBUG 2024-11-13 11:38:40,020 INFO 2024-11-13 11:38:40,020 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/rc.txt 2024-11-13 11:38:40,020 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-13 11:38:40,807 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:40,807 DEBUG --- stdout --- 2024-11-13 11:38:40,807 DEBUG tar: Removing leading `/' from member names 2024-11-13 11:38:40,807 DEBUG --- stderr --- 2024-11-13 11:38:40,808 DEBUG 2024-11-13 11:38:40,808 INFO 2024-11-13 11:38:40,808 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-13 11:38:40,808 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:41,093 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:41,093 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:41,093 DEBUG --- stdout --- 2024-11-13 11:38:41,093 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:41,093 DEBUG --- stderr --- 2024-11-13 11:38:41,093 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-13 11:38:41,093 INFO 2024-11-13 11:38:41,093 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-13 11:38:41,093 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:41,376 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:41,376 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:41,376 DEBUG --- stdout --- 2024-11-13 11:38:41,376 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:41,376 DEBUG --- stderr --- 2024-11-13 11:38:41,376 DEBUG 2024-11-13 11:38:41,377 INFO 2024-11-13 11:38:41,377 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-80/stderr.txt" ]; then echo "/results/orders/benchmark-80/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-80/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/stderr.txt file found" 2024-11-13 11:38:41,377 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-13 11:38:42,192 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-13 11:38:42,192 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:42,192 DEBUG --- stdout --- 2024-11-13 11:38:42,192 DEBUG /results/orders/benchmark-80/stderr.txt file found 2024-11-13 11:38:42,192 DEBUG --- stderr --- 2024-11-13 11:38:42,192 DEBUG 2024-11-13 11:38:42,192 INFO 2024-11-13 11:38:42,192 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-13 11:38:42,192 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:42,477 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:42,477 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:42,477 DEBUG --- stdout --- 2024-11-13 11:38:42,477 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:42,477 DEBUG --- stderr --- 2024-11-13 11:38:42,477 DEBUG 2024-11-13 11:38:42,477 INFO 2024-11-13 11:38:42,478 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-80/stderr.txt 2024-11-13 11:38:43,318 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-13 11:38:43,318 DEBUG --- stdout --- 2024-11-13 11:38:43,318 DEBUG 0 /results/orders/benchmark-80/stderr.txt 2024-11-13 11:38:43,318 DEBUG --- stderr --- 2024-11-13 11:38:43,318 DEBUG 2024-11-13 11:38:43,318 INFO - Download file (size 0k) 2024-11-13 11:38:43,318 INFO 2024-11-13 11:38:43,318 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-13 11:38:43,318 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:43,599 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:43,599 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:43,599 DEBUG --- stdout --- 2024-11-13 11:38:43,600 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:43,600 DEBUG --- stderr --- 2024-11-13 11:38:43,600 DEBUG source : /results/orders/benchmark-80/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/stderr.txt 2024-11-13 11:38:43,600 INFO 2024-11-13 11:38:43,600 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-13 11:38:43,600 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:43,885 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:43,885 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:43,885 DEBUG --- stdout --- 2024-11-13 11:38:43,885 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:43,885 DEBUG --- stderr --- 2024-11-13 11:38:43,885 DEBUG 2024-11-13 11:38:43,886 INFO 2024-11-13 11:38:43,886 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/stderr.txt 2024-11-13 11:38:43,886 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-13 11:38:44,675 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:44,675 DEBUG --- stdout --- 2024-11-13 11:38:44,675 DEBUG tar: Removing leading `/' from member names 2024-11-13 11:38:44,675 DEBUG --- stderr --- 2024-11-13 11:38:44,675 DEBUG 2024-11-13 11:38:44,675 INFO 2024-11-13 11:38:44,675 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-13 11:38:44,675 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:44,957 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:44,957 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:44,957 DEBUG --- stdout --- 2024-11-13 11:38:44,957 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:44,957 DEBUG --- stderr --- 2024-11-13 11:38:44,957 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-13 11:38:44,958 INFO 2024-11-13 11:38:44,958 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-13 11:38:44,958 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:45,242 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:45,242 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:45,242 DEBUG --- stdout --- 2024-11-13 11:38:45,242 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:45,242 DEBUG --- stderr --- 2024-11-13 11:38:45,242 DEBUG 2024-11-13 11:38:45,243 INFO 2024-11-13 11:38:45,243 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-80/stdout.txt" ]; then echo "/results/orders/benchmark-80/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-80/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/stdout.txt file found" 2024-11-13 11:38:45,243 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-13 11:38:46,070 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-13 11:38:46,070 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:46,070 DEBUG --- stdout --- 2024-11-13 11:38:46,070 DEBUG /results/orders/benchmark-80/stdout.txt file found 2024-11-13 11:38:46,070 DEBUG --- stderr --- 2024-11-13 11:38:46,070 DEBUG 2024-11-13 11:38:46,070 INFO 2024-11-13 11:38:46,070 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-13 11:38:46,070 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:46,355 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:46,355 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:46,355 DEBUG --- stdout --- 2024-11-13 11:38:46,355 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:46,355 DEBUG --- stderr --- 2024-11-13 11:38:46,355 DEBUG 2024-11-13 11:38:46,355 INFO 2024-11-13 11:38:46,355 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-80/stdout.txt 2024-11-13 11:38:47,171 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-13 11:38:47,171 DEBUG --- stdout --- 2024-11-13 11:38:47,171 DEBUG 6764 /results/orders/benchmark-80/stdout.txt 2024-11-13 11:38:47,171 DEBUG --- stderr --- 2024-11-13 11:38:47,171 DEBUG 2024-11-13 11:38:47,171 INFO - Download file (size 6764k) 2024-11-13 11:38:47,172 INFO 2024-11-13 11:38:47,172 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-13 11:38:47,172 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:47,458 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:47,458 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:47,458 DEBUG --- stdout --- 2024-11-13 11:38:47,458 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:47,458 DEBUG --- stderr --- 2024-11-13 11:38:47,458 DEBUG source : /results/orders/benchmark-80/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/stdout.txt 2024-11-13 11:38:47,458 INFO 2024-11-13 11:38:47,458 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-13 11:38:47,458 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:47,741 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:47,741 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:47,741 DEBUG --- stdout --- 2024-11-13 11:38:47,741 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:47,741 DEBUG --- stderr --- 2024-11-13 11:38:47,741 DEBUG 2024-11-13 11:38:47,742 INFO 2024-11-13 11:38:47,742 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/stdout.txt 2024-11-13 11:38:47,742 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-13 11:38:49,098 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:49,098 DEBUG --- stdout --- 2024-11-13 11:38:49,098 DEBUG tar: Removing leading `/' from member names 2024-11-13 11:38:49,098 DEBUG --- stderr --- 2024-11-13 11:38:49,098 DEBUG ________________________________________________________________________________ [2024-11-13 11:38:49] benchmark-80 show_cmd : Display order command ________________________________________________________________________________ 2024-11-13 11:38:49,099 INFO 2024-11-13 11:38:49,099 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-13 11:38:49,099 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:49,381 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:49,381 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:49,381 DEBUG --- stdout --- 2024-11-13 11:38:49,381 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:49,381 DEBUG --- stderr --- 2024-11-13 11:38:49,381 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-13 11:38:49,382 INFO 2024-11-13 11:38:49,382 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-13 11:38:49,382 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:49,666 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:49,666 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:49,666 DEBUG --- stdout --- 2024-11-13 11:38:49,666 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:49,666 DEBUG --- stderr --- 2024-11-13 11:38:49,666 DEBUG 2024-11-13 11:38:49,667 INFO 2024-11-13 11:38:49,667 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-80/cmd.txt" ]; then echo "/results/orders/benchmark-80/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-80/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-80/cmd.txt file found" 2024-11-13 11:38:49,667 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-13 11:38:50,496 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-13 11:38:50,496 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:50,496 DEBUG --- stdout --- 2024-11-13 11:38:50,496 DEBUG /results/orders/benchmark-80/cmd.txt file found 2024-11-13 11:38:50,496 DEBUG --- stderr --- 2024-11-13 11:38:50,497 DEBUG 2024-11-13 11:38:50,497 INFO 2024-11-13 11:38:50,497 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-13 11:38:50,497 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:50,787 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:50,787 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:50,787 DEBUG --- stdout --- 2024-11-13 11:38:50,787 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:50,787 DEBUG --- stderr --- 2024-11-13 11:38:50,787 DEBUG 2024-11-13 11:38:50,787 INFO 2024-11-13 11:38:50,787 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-80/cmd.txt 2024-11-13 11:38:51,609 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-13 11:38:51,609 DEBUG --- stdout --- 2024-11-13 11:38:51,609 DEBUG 4 /results/orders/benchmark-80/cmd.txt 2024-11-13 11:38:51,609 DEBUG --- stderr --- 2024-11-13 11:38:51,609 DEBUG 2024-11-13 11:38:51,609 INFO - Download file (size 4k) 2024-11-13 11:38:51,609 INFO 2024-11-13 11:38:51,609 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-13 11:38:51,609 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:51,892 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:51,892 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:51,892 DEBUG --- stdout --- 2024-11-13 11:38:51,892 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:51,892 DEBUG --- stderr --- 2024-11-13 11:38:51,892 DEBUG source : /results/orders/benchmark-80/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/cmd.txt 2024-11-13 11:38:51,892 INFO 2024-11-13 11:38:51,892 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-13 11:38:51,892 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-13 11:38:52,175 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-13 11:38:52,175 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:52,175 DEBUG --- stdout --- 2024-11-13 11:38:52,175 DEBUG overseer-0-6644bb6697-rchxr 2024-11-13 11:38:52,175 DEBUG --- stderr --- 2024-11-13 11:38:52,175 DEBUG 2024-11-13 11:38:52,176 INFO 2024-11-13 11:38:52,176 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-80/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/cmd.txt 2024-11-13 11:38:52,176 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-13 11:38:52,962 INFO [loop_until]: OK (rc = 0) 2024-11-13 11:38:52,962 DEBUG --- stdout --- 2024-11-13 11:38:52,962 DEBUG tar: Removing leading `/' from member names 2024-11-13 11:38:52,962 DEBUG --- stderr --- 2024-11-13 11:38:52,962 DEBUG 2024-11-13 11:38:52,962 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/cmd.txt is small (1 lines), printing all lines: 2024-11-13 11:38:52,962 DEBUG ----- output ----- 2024-11-13 11:38:52,962 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-80" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=Pa_ssw0rd" 2024-11-13 11:38:52,962 INFO ________________________________________________________________________________ [2024-11-13 11:38:52] benchmark-80 show_rc : Display rc order ________________________________________________________________________________ 2024-11-13 11:38:52,963 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/rc.txt is small (1 lines), printing all lines: 2024-11-13 11:38:52,963 DEBUG ----- output ----- 2024-11-13 11:38:52,963 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-13 11:38:52,963 INFO ________________________________________________________________________________ [2024-11-13 11:38:52] benchmark-80 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-13 11:38:52,971 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-80/stdout.txt is 76017 lines): 2024-11-13 11:38:52,971 DEBUG ----- output ----- 2024-11-13 11:38:52,971 INFO 2024-11-13 10:38:14,558 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpg2w2mawd 2024-11-13 11:38:52,971 INFO 2024-11-13 10:38:14,560 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-80" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self80- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=80 -Duser_password=**** 2024-11-13 11:38:52,971 INFO [INFO] Scanning for projects... 2024-11-13 11:38:52,971 INFO [INFO] 2024-11-13 11:38:52,971 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-13 11:38:52,971 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-13 11:38:52,971 INFO [INFO] from pom.xml 2024-11-13 11:38:52,971 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-13 11:38:52,971 INFO [INFO] 2024-11-13 11:38:52,971 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-13 11:38:52,971 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-13 11:38:52,972 INFO [INFO] skip non existing resourceDirectory /tmp/tmpg2w2mawd/src/main/resources 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-13 11:38:52,972 INFO [INFO] No sources to compile 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-13 11:38:52,972 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-13 11:38:52,972 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-13 11:38:52,972 INFO [INFO] compiling 38 Scala sources to /tmp/tmpg2w2mawd/target/test-classes ... 2024-11-13 11:38:52,972 INFO [INFO] compile in 6.7 s 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] 2024-11-13 11:38:52,972 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-13 11:38:52,972 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-13 11:38:52,972 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-13 11:38:52,972 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-13 11:38:52,972 INFO 2024-11-13 11:38:52,972 INFO ================================================================================ 2024-11-13 11:38:52,972 INFO 2024-11-13 10:38:30 GMT 5s elapsed 2024-11-13 11:38:52,972 INFO ---- Requests ------------------------------------------------------------------ 2024-11-13 11:38:52,972 INFO > Global (OK=452 KO=0 ) 2024-11-13 11:38:52,972 INFO > restLoginInitiate (OK=33 KO=0 ) 2024-11-13 11:38:52,972 INFO > restLoginUsernamePasswordCallback (OK=31 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Post-Login - stage 1 (OK=12 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=12 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI AM idFromSession (OK=12 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI AM validateGoto (OK=12 KO=0 ) 2024-11-13 11:38:52,972 INFO > User Authorize PKCE stage (OK=40 KO=0 ) 2024-11-13 11:38:52,972 INFO > User AccessToken PKCE stage (OK=39 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Post-Login - stage 2 (OK=11 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI Enduser appAuthHelper2 (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI Enduser appAuthHelper1 (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Post-Login - stage 3 (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI Enduser sessioncheck (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM uiconfig (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM version (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM privilege (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM features (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM login (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM managed user schema (OK=9 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM user (OK=9 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM dashboard (OK=10 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI IDM oidcToken (OK=9 KO=0 ) 2024-11-13 11:38:52,972 INFO > userinfo (OK=8 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Logout (OK=8 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI-Logout Redirect 1 (OK=8 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI AM endsession (OK=8 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI AM revoke2 (OK=8 KO=0 ) 2024-11-13 11:38:52,972 INFO > UI AM revoke1 (OK=8 KO=0 ) 2024-11-13 11:38:52,972 INFO > Skip 2FA (OK=14 KO=0 ) 2024-11-13 11:38:52,972 INFO > GetUUid (OK=9 KO=0 ) 2024-11-13 11:38:52,972 INFO > GetOpenidConfig (OK=9 KO=0 ) 2024-11-13 11:38:52,972 INFO > CreatePolicy (OK=9 KO=0 ) 2024-11-13 11:38:52,972 INFO > tokenUserinfo (OK=5 KO=0 ) 2024-11-13 11:38:52,972 INFO > restloginProgressiveProfileCallback (OK=1 KO=0 ) 2024-11-13 11:38:52,973 INFO > getIdToken (OK=1 KO=0 ) 2024-11-13 11:38:52,973 INFO > getIdToken Redirect 1 (OK=1 KO=0 ) 2024-11-13 11:38:52,973 INFO > createOrganization (OK=1 KO=0 ) 2024-11-13 11:38:52,973 INFO > queryOrganization (OK=1 KO=0 ) 2024-11-13 11:38:52,973 INFO > deleteOrganization (OK=1 KO=0 ) 2024-11-13 11:38:52,973 INFO > RootUserinfo (OK=3 KO=0 ) 2024-11-13 11:38:52,973 INFO 2024-11-13 11:38:52,973 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-13 11:38:52,973 INFO [- ] 0% 2024-11-13 11:38:52,973 INFO waiting: 289188 / active: 19 / done: 14 2024-11-13 11:38:52,973 INFO ================================================================================ 2024-11-13 11:38:52,973 INFO 2024-11-13 11:38:52,973 INFO 10:38:31.337 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-13 11:38:52,973 INFO 10:38:34.350 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-13 11:38:52,973 INFO 10:38:35.077 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-13 11:38:52,973 INFO 10:38:35.496 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-13 11:38:52,973 INFO 2024-11-13 11:38:52,973 INFO ================================================================================ 2024-11-13 11:38:52,973 INFO 2024-11-13 10:38:35 GMT 10s elapsed 2024-11-13 11:38:52,973 INFO ---- Requests ------------------------------------------------------------------ 2024-11-13 11:38:52,973 INFO > Global (OK=1737 KO=0 ) 2024-11-13 11:38:52,973 INFO > restLoginInitiate (OK=128 KO=0 ) 2024-11-13 11:38:52,973 INFO > restLoginUsernamePasswordCallback (OK=125 KO=0 ) 2024-11-13 11:38:52,973 INFO > UI-Post-Login - stage 1 (OK=39 KO=0 ) 2024-11-13 11:38:52,973 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=38 KO=0 ) 2024-11-13 11:38:52,973 INFO [...] 2024-11-13 11:38:52,984 INFO ========================= 2024-11-13 11:38:52,984 INFO Session: 2024-11-13 11:38:52,984 INFO Session(idc.benchmark.Mix2024,286823,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.122182, randomPolicyName -> testPolicy754915, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1de15142, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.3, password -> Pa_ssw0rd, fake-ip -> 43.191.98.89, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@62fcd039),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fe2d869a0e0@118bfb13,io.netty.channel.epoll.EpollEventLoop@1eb6749b) 2024-11-13 11:38:52,984 INFO ========================= 2024-11-13 11:38:52,984 INFO HTTP request: 2024-11-13 11:38:52,984 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-13 11:38:52,984 INFO headers: 2024-11-13 11:38:52,984 INFO accept: application/json 2024-11-13 11:38:52,984 INFO content-type: application/json 2024-11-13 11:38:52,984 INFO user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.3 2024-11-13 11:38:52,984 INFO X-Forwarded-For: 43.191.98.89 2024-11-13 11:38:52,984 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-13 11:38:52,984 INFO content-length: 0 2024-11-13 11:38:52,984 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-13 11:38:52,984 INFO ========================= 2024-11-13 11:38:52,984 INFO HTTP response: 2024-11-13 11:38:52,984 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-13 11:38:52,984 INFO 11:38:25.499 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-13 11:38:52,984 INFO 11:38:25.499 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-13 11:38:52,984 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-13 11:38:52,984 INFO Request: 2024-11-13 11:38:52,985 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO Session: 2024-11-13 11:38:52,985 INFO Session(idc.benchmark.Mix2024,286824,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.59263, randomPolicyName -> testPolicy249907, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@120d489b, fake-user-agent -> Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9, password -> Pa_ssw0rd, fake-ip -> 73.247.168.87, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@efa6e02),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fe2d869a0e0@118bfb13,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO HTTP request: 2024-11-13 11:38:52,985 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-13 11:38:52,985 INFO headers: 2024-11-13 11:38:52,985 INFO accept: application/json 2024-11-13 11:38:52,985 INFO content-type: application/json 2024-11-13 11:38:52,985 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9 2024-11-13 11:38:52,985 INFO X-Forwarded-For: 73.247.168.87 2024-11-13 11:38:52,985 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-13 11:38:52,985 INFO content-length: 0 2024-11-13 11:38:52,985 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO HTTP response: 2024-11-13 11:38:52,985 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-13 11:38:52,985 INFO 11:38:25.499 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-13 11:38:52,985 INFO 11:38:25.500 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request ' UI IDM features' failed for user 286779: j.i.IOException: Premature close 2024-11-13 11:38:52,985 INFO 11:38:25.500 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-13 11:38:52,985 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-13 11:38:52,985 INFO Request: 2024-11-13 11:38:52,985 INFO UI IDM features: KO j.i.IOException: Premature close 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO Session: 2024-11-13 11:38:52,985 INFO Session(idc.benchmark.Mix2024,286779,HashMap(access_token -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmNmE1OWY3ZC1lOGY0LTQ3MzItYTNhYi0zNTJlOWJhOTMxMTMiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiYTA2NGI3YzctNmJiYS00Y2MwLTg3ZTgtM2RhY2IxODliOTNkLTQ4MDYxMzczIiwic3VibmFtZSI6ImY2YTU5ZjdkLWU4ZjQtNDczMi1hM2FiLTM1MmU5YmE5MzExMyIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6IlAtSFhEZDh6Y0s0UGZZNVZ3ZVpWU0VBdDByayIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTQ5NzkwNSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbIm9wZW5pZCIsImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTQ5NzkwNCwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1MDE1MDUsImlhdCI6MTczMTQ5NzkwNSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiU001R2NMN245NTJsdXoyaWM1TFFRTUd6UGxNIn0.8IycgNzjRDq1u8tVxlQ1Uo0X9zBOiZfCB1uYb_1uYHU, username -> user.186852, access_token_2 -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmNmE1OWY3ZC1lOGY0LTQ3MzItYTNhYi0zNTJlOWJhOTMxMTMiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMGIzOGU2MjYtMDhkZC00YzdhLTliN2ItMGQxMTUzYWM3NjdkLTQ4MDQyOTQwIiwic3VibmFtZSI6ImY2YTU5ZjdkLWU4ZjQtNDczMi1hM2FiLTM1MmU5YmE5MzExMyIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6InRVdW1ieEYxOUNTQTU3ODhtSk8wd1VKYXZMTSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTQ5NzkwNSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTQ5NzkwNCwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1MDE1MDUsImlhdCI6MTczMTQ5NzkwNSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoibDF5Nnl1SlFGbHhweHJSVjBUdFlhM3F5TjAwIn0.mpkJPHtb177CVcxAffAgNeHdpgZ4_vQ-yTI5EyxfwFI, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3a359ef0, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, authcode -> GVG4nWA08nuRr5UpJ_y5zXgonXw, callbacks -> {"tokenId":"E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1731497904886), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731497904886))), user_uuid -> f6a59f7d-e8f4-4732-a3ab-352e9ba93113, password -> Pa_ssw0rd, challenge -> PLUe-CFrTgaDDKcTWfmM7fpqVWSWz_oE6iujPtXZEcc, gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, fake-ip -> 42.42.42.42, verifier -> LTgyMTMyMzkxMzQ1MDA4MTEyODE, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@4676bba6, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@136235a6, tokenId -> E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/602.1.50 (KHTML, like Gecko) CriOS/56.0.2924.75 Mobile/14E5239e Safari/602.1),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fe2d869a0e0@118bfb13,io.netty.channel.epoll.EpollEventLoop@650eab8) 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO HTTP request: 2024-11-13 11:38:52,985 INFO GET https://openam-perf-benchmark.forgeblocks.com/openidm/info/features?_queryFilter=true 2024-11-13 11:38:52,985 INFO headers: 2024-11-13 11:38:52,985 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-13 11:38:52,985 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-13 11:38:52,985 INFO Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmNmE1OWY3ZC1lOGY0LTQ3MzItYTNhYi0zNTJlOWJhOTMxMTMiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMGIzOGU2MjYtMDhkZC00YzdhLTliN2ItMGQxMTUzYWM3NjdkLTQ4MDQyOTQwIiwic3VibmFtZSI6ImY2YTU5ZjdkLWU4ZjQtNDczMi1hM2FiLTM1MmU5YmE5MzExMyIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6InRVdW1ieEYxOUNTQTU3ODhtSk8wd1VKYXZMTSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTQ5NzkwNSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTQ5NzkwNCwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1MDE1MDUsImlhdCI6MTczMTQ5NzkwNSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoibDF5Nnl1SlFGbHhweHJSVjBUdFlhM3F5TjAwIn0.mpkJPHtb177CVcxAffAgNeHdpgZ4_vQ-yTI5EyxfwFI 2024-11-13 11:38:52,985 INFO Accept-Api-Version: 2024-11-13 11:38:52,985 INFO accept: */* 2024-11-13 11:38:52,985 INFO cookie: amlbcookie=01; 9b75a55744995d0=E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-13 11:38:52,985 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-13 11:38:52,985 INFO cookies: 2024-11-13 11:38:52,985 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-13 11:38:52,985 INFO 9b75a55744995d0=E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO HTTP response: 2024-11-13 11:38:52,985 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-13 11:38:52,985 INFO 11:38:25.500 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request ' UI IDM privilege' failed for user 286779: j.i.IOException: Premature close 2024-11-13 11:38:52,985 INFO 11:38:25.500 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-13 11:38:52,985 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-13 11:38:52,985 INFO Request: 2024-11-13 11:38:52,985 INFO UI IDM privilege: KO j.i.IOException: Premature close 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO Session: 2024-11-13 11:38:52,985 INFO Session(idc.benchmark.Mix2024,286779,HashMap(access_token -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmNmE1OWY3ZC1lOGY0LTQ3MzItYTNhYi0zNTJlOWJhOTMxMTMiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiYTA2NGI3YzctNmJiYS00Y2MwLTg3ZTgtM2RhY2IxODliOTNkLTQ4MDYxMzczIiwic3VibmFtZSI6ImY2YTU5ZjdkLWU4ZjQtNDczMi1hM2FiLTM1MmU5YmE5MzExMyIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6IlAtSFhEZDh6Y0s0UGZZNVZ3ZVpWU0VBdDByayIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTQ5NzkwNSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbIm9wZW5pZCIsImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTQ5NzkwNCwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1MDE1MDUsImlhdCI6MTczMTQ5NzkwNSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiU001R2NMN245NTJsdXoyaWM1TFFRTUd6UGxNIn0.8IycgNzjRDq1u8tVxlQ1Uo0X9zBOiZfCB1uYb_1uYHU, username -> user.186852, access_token_2 -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmNmE1OWY3ZC1lOGY0LTQ3MzItYTNhYi0zNTJlOWJhOTMxMTMiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMGIzOGU2MjYtMDhkZC00YzdhLTliN2ItMGQxMTUzYWM3NjdkLTQ4MDQyOTQwIiwic3VibmFtZSI6ImY2YTU5ZjdkLWU4ZjQtNDczMi1hM2FiLTM1MmU5YmE5MzExMyIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6InRVdW1ieEYxOUNTQTU3ODhtSk8wd1VKYXZMTSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTQ5NzkwNSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTQ5NzkwNCwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1MDE1MDUsImlhdCI6MTczMTQ5NzkwNSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoibDF5Nnl1SlFGbHhweHJSVjBUdFlhM3F5TjAwIn0.mpkJPHtb177CVcxAffAgNeHdpgZ4_vQ-yTI5EyxfwFI, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3a359ef0, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, authcode -> GVG4nWA08nuRr5UpJ_y5zXgonXw, callbacks -> {"tokenId":"E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1731497904886), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731497904886))), user_uuid -> f6a59f7d-e8f4-4732-a3ab-352e9ba93113, password -> Pa_ssw0rd, challenge -> PLUe-CFrTgaDDKcTWfmM7fpqVWSWz_oE6iujPtXZEcc, gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, fake-ip -> 42.42.42.42, verifier -> LTgyMTMyMzkxMzQ1MDA4MTEyODE, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@4676bba6, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@136235a6, tokenId -> E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/602.1.50 (KHTML, like Gecko) CriOS/56.0.2924.75 Mobile/14E5239e Safari/602.1),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fe2d869a0e0@118bfb13,io.netty.channel.epoll.EpollEventLoop@650eab8) 2024-11-13 11:38:52,985 INFO ========================= 2024-11-13 11:38:52,985 INFO HTTP request: 2024-11-13 11:38:52,985 INFO POST https://openam-perf-benchmark.forgeblocks.com/openidm/privilege?_action=listPrivileges 2024-11-13 11:38:52,985 INFO headers: 2024-11-13 11:38:52,985 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-13 11:38:52,985 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-13 11:38:52,985 INFO Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmNmE1OWY3ZC1lOGY0LTQ3MzItYTNhYi0zNTJlOWJhOTMxMTMiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMGIzOGU2MjYtMDhkZC00YzdhLTliN2ItMGQxMTUzYWM3NjdkLTQ4MDQyOTQwIiwic3VibmFtZSI6ImY2YTU5ZjdkLWU4ZjQtNDczMi1hM2FiLTM1MmU5YmE5MzExMyIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6InRVdW1ieEYxOUNTQTU3ODhtSk8wd1VKYXZMTSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTQ5NzkwNSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTQ5NzkwNCwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1MDE1MDUsImlhdCI6MTczMTQ5NzkwNSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoibDF5Nnl1SlFGbHhweHJSVjBUdFlhM3F5TjAwIn0.mpkJPHtb177CVcxAffAgNeHdpgZ4_vQ-yTI5EyxfwFI 2024-11-13 11:38:52,985 INFO Accept-Api-Version: 2024-11-13 11:38:52,985 INFO accept: */* 2024-11-13 11:38:52,986 INFO cookie: amlbcookie=01; 9b75a55744995d0=E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-13 11:38:52,986 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-13 11:38:52,986 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-13 11:38:52,986 INFO content-length: 0 2024-11-13 11:38:52,986 INFO cookies: 2024-11-13 11:38:52,986 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-13 11:38:52,986 INFO 9b75a55744995d0=E_25C9VF2wqD0_nDH9q0lMgWi3U.*AAJTSQACMDIAAlNLABxqcW5RdzMvWlhxVFlqRllRQ09xcFdQV2dYbXc9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-13 11:38:52,986 INFO ========================= 2024-11-13 11:38:52,986 INFO HTTP response: 2024-11-13 11:38:52,986 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-13 11:38:52,986 INFO [INFO] ------------------------------------------------------------------------ 2024-11-13 11:38:52,986 INFO [INFO] BUILD SUCCESS 2024-11-13 11:38:52,986 INFO [INFO] ------------------------------------------------------------------------ 2024-11-13 11:38:52,986 INFO [INFO] Total time: 01:00 h 2024-11-13 11:38:52,986 INFO [INFO] Finished at: 2024-11-13T11:38:25Z 2024-11-13 11:38:52,986 INFO [INFO] ------------------------------------------------------------------------ 2024-11-13 11:38:52,986 INFO 2024-11-13 11:38:25,600 INFO Gatling simulation run ended successfully 2024-11-13 11:38:52,986 INFO 2024-11-13 11:38:25,600 DEBUG No archive name provided. No archive will be created 2024-11-13 11:38:52,986 INFO ________________________________________________________________________________ [2024-11-13 11:38:52] benchmark-80 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-13 11:38:52,986 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/06_benchmark-80/stderr.txt is small (0 lines), printing all lines: 2024-11-13 11:38:52,986 DEBUG ----- output ----- 2024-11-13 11:38:52,986 DEBUG 2024-11-13 11:38:52,986 INFO ________________________________________________________________________________ [2024-11-13 11:38:52] benchmark-80 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-11-13 11:38:53] benchmark-80 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-13 11:38:53] benchmark-80 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped