--Task-- name: benchmark-120 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates below loop: False interval: None dependencies: [] wait_for: ['benchmark-100'] preceding_task: benchmark-100 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 120} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-20 23:11:01] benchmark-120 pre : N/A ________________________________________________________________________________ 2024-11-20 23:11:01 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-20 23:11:01 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-120/stdout.txt Pod log : /results/orders/benchmark-120 2024-11-20 23:11:01,723 INFO 2024-11-20 23:11:01,723 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-20 23:11:01,723 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 23:11:01,994 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 23:11:01,994 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:01,994 DEBUG --- stdout --- 2024-11-20 23:11:01,994 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 23:11:01,994 DEBUG --- stderr --- 2024-11-20 23:11:01,994 DEBUG ________________________________________________________________________________ [2024-11-20 23:11:01] benchmark-120 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-20 23:11:01,995 INFO 2024-11-20 23:11:01,995 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-20 23:11:01,995 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 23:11:02,269 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 23:11:02,269 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:02,269 DEBUG --- stdout --- 2024-11-20 23:11:02,269 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 23:11:02,269 DEBUG --- stderr --- 2024-11-20 23:11:02,269 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-120" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-20 23:11:02] benchmark-120 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-20 23:11:02,270 INFO 2024-11-20 23:11:02,270 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-20 23:11:02,270 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 23:11:02,542 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 23:11:02,542 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:02,542 DEBUG --- stdout --- 2024-11-20 23:11:02,542 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 23:11:02,542 DEBUG --- stderr --- 2024-11-20 23:11:02,542 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/order.json { "name": "benchmark-120", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-120\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-120" } ________________________________________________________________________________ [2024-11-20 23:11:02] benchmark-120 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2024-11-20 23:11:02,545 INFO 2024-11-20 23:11:02,545 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-20 23:11:02,545 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-20 23:11:02,805 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-20 23:11:02,805 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:02,805 DEBUG --- stdout --- 2024-11-20 23:11:02,806 DEBUG WAITING 2024-11-20 23:11:02,806 DEBUG --- stderr --- 2024-11-20 23:11:02,806 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 27 0 --:--:-- --:--:-- --:--:-- 27 ________________________________________________________________________________ [2024-11-20 23:11:02] benchmark-120 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-20 23:11:02,806 INFO 2024-11-20 23:11:02,806 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-20 23:11:02,806 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 23:11:03,079 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 23:11:03,079 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:03,079 DEBUG --- stdout --- 2024-11-20 23:11:03,079 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 23:11:03,079 DEBUG --- stderr --- 2024-11-20 23:11:03,079 DEBUG 2024-11-20 23:11:03,079 INFO 2024-11-20 23:11:03,079 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-20 23:11:03,079 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-20 23:11:04,424 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:04,424 DEBUG --- stdout --- 2024-11-20 23:11:04,424 DEBUG 2024-11-20 23:11:04,424 DEBUG --- stderr --- 2024-11-20 23:11:04,424 DEBUG Order has been successfully forwarded to overseer 2024-11-20 23:11:04 - INFO: Check if Gatling simulation started successfully 2024-11-20 23:11:04,425 INFO 2024-11-20 23:11:04,425 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-20 23:11:04,425 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-20 23:11:04,697 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-20 23:11:04,697 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:04,697 DEBUG --- stdout --- 2024-11-20 23:11:04,697 DEBUG overseer-0-6644bb6697-rchxr 2024-11-20 23:11:04,697 DEBUG --- stderr --- 2024-11-20 23:11:04,697 DEBUG 2024-11-20 23:11:04,698 INFO 2024-11-20 23:11:04,698 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-120/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-20 23:11:04,698 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-20 23:11:05,406 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-20 23:11:11,125 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-20 23:11:16,847 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-20 23:11:16,847 INFO [loop_until]: OK (rc = 0) 2024-11-20 23:11:16,847 DEBUG --- stdout --- 2024-11-20 23:11:16,847 DEBUG 2024-11-20 23:11:05,424 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpvgh_5fg2 2024-11-20 23:11:05,426 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-120" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=**** [INFO] Scanning for projects... [INFO] [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- [INFO] Building pyrock-gatling-simulation 3.12.0 [INFO] from pom.xml [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> [INFO] [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- [INFO] skip non existing resourceDirectory /tmp/tmpvgh_5fg2/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/tmpvgh_5fg2/target/test-classes ... [INFO] compile in 6.8 s [INFO] [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< [INFO] [INFO] [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- [INFO] Running simulation com.forgerock.pyrock.Loadtest. Gatling 3.13.1 is available! (you're using 3.12.0) System property think_time_multiplier not set. No think time emulation will be done in the simulation. Simulation com.forgerock.pyrock.Loadtest started... 2024-11-20 23:11:16,847 DEBUG --- stderr --- 2024-11-20 23:11:16,848 DEBUG ________________________________________________________________________________ [2024-11-20 23:11:16] benchmark-120 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, 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 06s, 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 08s, 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 00:11:25] benchmark-120 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-21 00:11:25,780 INFO 2024-11-21 00:11:25,780 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:25,780 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:26,079 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:26,079 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:26,079 DEBUG --- stdout --- 2024-11-21 00:11:26,079 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:26,079 DEBUG --- stderr --- 2024-11-21 00:11:26,079 DEBUG 2024-11-21 00:11:26,079 INFO 2024-11-21 00:11:26,079 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 00:11:26,079 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 00:11:26,837 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:26,837 DEBUG --- stdout --- 2024-11-21 00:11:26,837 DEBUG 2024-11-21 00:11:26,837 DEBUG --- stderr --- 2024-11-21 00:11:26,837 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-21 00:11:26] benchmark-120 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-21 00:11:26 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/order.json 2024-11-21 00:11:26,837 INFO 2024-11-21 00:11:26,837 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:26,837 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:27,108 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:27,108 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:27,108 DEBUG --- stdout --- 2024-11-21 00:11:27,108 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:27,108 DEBUG --- stderr --- 2024-11-21 00:11:27,108 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 00:11:27,108 INFO 2024-11-21 00:11:27,108 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:27,108 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:27,382 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:27,382 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:27,382 DEBUG --- stdout --- 2024-11-21 00:11:27,382 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:27,382 DEBUG --- stderr --- 2024-11-21 00:11:27,382 DEBUG 2024-11-21 00:11:27,383 INFO 2024-11-21 00:11:27,383 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-120/rc.txt" ]; then echo "/results/orders/benchmark-120/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-120/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/rc.txt file found" 2024-11-21 00:11:27,383 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 00:11:28,164 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 00:11:28,164 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:28,164 DEBUG --- stdout --- 2024-11-21 00:11:28,164 DEBUG /results/orders/benchmark-120/rc.txt file found 2024-11-21 00:11:28,164 DEBUG --- stderr --- 2024-11-21 00:11:28,164 DEBUG 2024-11-21 00:11:28,165 INFO 2024-11-21 00:11:28,165 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:28,165 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:28,436 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:28,436 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:28,436 DEBUG --- stdout --- 2024-11-21 00:11:28,436 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:28,436 DEBUG --- stderr --- 2024-11-21 00:11:28,436 DEBUG 2024-11-21 00:11:28,436 INFO 2024-11-21 00:11:28,437 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-120/rc.txt 2024-11-21 00:11:29,220 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 00:11:29,220 DEBUG --- stdout --- 2024-11-21 00:11:29,220 DEBUG 4 /results/orders/benchmark-120/rc.txt 2024-11-21 00:11:29,220 DEBUG --- stderr --- 2024-11-21 00:11:29,220 DEBUG 2024-11-21 00:11:29,221 INFO - Download file (size 4k) 2024-11-21 00:11:29,221 INFO 2024-11-21 00:11:29,221 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:29,221 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:29,495 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:29,495 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:29,495 DEBUG --- stdout --- 2024-11-21 00:11:29,495 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:29,495 DEBUG --- stderr --- 2024-11-21 00:11:29,495 DEBUG source : /results/orders/benchmark-120/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/rc.txt 2024-11-21 00:11:29,495 INFO 2024-11-21 00:11:29,495 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:29,495 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:29,767 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:29,768 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:29,768 DEBUG --- stdout --- 2024-11-21 00:11:29,768 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:29,768 DEBUG --- stderr --- 2024-11-21 00:11:29,768 DEBUG 2024-11-21 00:11:29,768 INFO 2024-11-21 00:11:29,768 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-120/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/rc.txt 2024-11-21 00:11:29,768 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 00:11:30,509 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:30,509 DEBUG --- stdout --- 2024-11-21 00:11:30,509 DEBUG tar: Removing leading `/' from member names 2024-11-21 00:11:30,509 DEBUG --- stderr --- 2024-11-21 00:11:30,509 DEBUG 2024-11-21 00:11:30,509 INFO 2024-11-21 00:11:30,509 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:30,509 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:30,781 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:30,781 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:30,781 DEBUG --- stdout --- 2024-11-21 00:11:30,781 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:30,781 DEBUG --- stderr --- 2024-11-21 00:11:30,781 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 00:11:30,781 INFO 2024-11-21 00:11:30,781 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:30,781 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:31,053 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:31,053 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:31,053 DEBUG --- stdout --- 2024-11-21 00:11:31,053 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:31,053 DEBUG --- stderr --- 2024-11-21 00:11:31,053 DEBUG 2024-11-21 00:11:31,054 INFO 2024-11-21 00:11:31,054 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-120/stderr.txt" ]; then echo "/results/orders/benchmark-120/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-120/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/stderr.txt file found" 2024-11-21 00:11:31,054 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 00:11:31,841 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 00:11:31,841 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:31,841 DEBUG --- stdout --- 2024-11-21 00:11:31,841 DEBUG /results/orders/benchmark-120/stderr.txt file found 2024-11-21 00:11:31,841 DEBUG --- stderr --- 2024-11-21 00:11:31,841 DEBUG 2024-11-21 00:11:31,841 INFO 2024-11-21 00:11:31,841 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:31,841 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:32,114 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:32,114 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:32,115 DEBUG --- stdout --- 2024-11-21 00:11:32,115 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:32,115 DEBUG --- stderr --- 2024-11-21 00:11:32,115 DEBUG 2024-11-21 00:11:32,115 INFO 2024-11-21 00:11:32,115 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-120/stderr.txt 2024-11-21 00:11:32,902 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 00:11:32,902 DEBUG --- stdout --- 2024-11-21 00:11:32,902 DEBUG 0 /results/orders/benchmark-120/stderr.txt 2024-11-21 00:11:32,902 DEBUG --- stderr --- 2024-11-21 00:11:32,902 DEBUG 2024-11-21 00:11:32,902 INFO - Download file (size 0k) 2024-11-21 00:11:32,903 INFO 2024-11-21 00:11:32,903 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 00:11:32,903 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:33,176 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:33,176 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:33,176 DEBUG --- stdout --- 2024-11-21 00:11:33,176 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:33,176 DEBUG --- stderr --- 2024-11-21 00:11:33,176 DEBUG source : /results/orders/benchmark-120/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stderr.txt 2024-11-21 00:11:33,176 INFO 2024-11-21 00:11:33,176 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:33,176 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:33,449 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:33,449 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:33,449 DEBUG --- stdout --- 2024-11-21 00:11:33,449 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:33,449 DEBUG --- stderr --- 2024-11-21 00:11:33,449 DEBUG 2024-11-21 00:11:33,450 INFO 2024-11-21 00:11:33,450 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-120/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stderr.txt 2024-11-21 00:11:33,450 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 00:11:34,199 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:34,199 DEBUG --- stdout --- 2024-11-21 00:11:34,199 DEBUG tar: Removing leading `/' from member names 2024-11-21 00:11:34,199 DEBUG --- stderr --- 2024-11-21 00:11:34,199 DEBUG 2024-11-21 00:11:34,199 INFO 2024-11-21 00:11:34,199 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:34,199 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:34,471 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:34,471 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:34,471 DEBUG --- stdout --- 2024-11-21 00:11:34,471 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:34,471 DEBUG --- stderr --- 2024-11-21 00:11:34,471 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 00:11:34,472 INFO 2024-11-21 00:11:34,472 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:34,472 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:34,746 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:34,746 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:34,746 DEBUG --- stdout --- 2024-11-21 00:11:34,746 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:34,746 DEBUG --- stderr --- 2024-11-21 00:11:34,746 DEBUG 2024-11-21 00:11:34,747 INFO 2024-11-21 00:11:34,747 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-120/stdout.txt" ]; then echo "/results/orders/benchmark-120/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-120/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/stdout.txt file found" 2024-11-21 00:11:34,747 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 00:11:35,528 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 00:11:35,529 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:35,529 DEBUG --- stdout --- 2024-11-21 00:11:35,529 DEBUG /results/orders/benchmark-120/stdout.txt file found 2024-11-21 00:11:35,529 DEBUG --- stderr --- 2024-11-21 00:11:35,529 DEBUG 2024-11-21 00:11:35,529 INFO 2024-11-21 00:11:35,529 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 00:11:35,529 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:35,814 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:35,815 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:35,815 DEBUG --- stdout --- 2024-11-21 00:11:35,815 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:35,815 DEBUG --- stderr --- 2024-11-21 00:11:35,815 DEBUG 2024-11-21 00:11:35,815 INFO 2024-11-21 00:11:35,815 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-120/stdout.txt 2024-11-21 00:11:36,590 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 00:11:36,591 DEBUG --- stdout --- 2024-11-21 00:11:36,592 DEBUG 7964 /results/orders/benchmark-120/stdout.txt 2024-11-21 00:11:36,592 DEBUG --- stderr --- 2024-11-21 00:11:36,592 DEBUG 2024-11-21 00:11:36,592 INFO - Download file (size 7964k) 2024-11-21 00:11:36,592 INFO 2024-11-21 00:11:36,592 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:36,592 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:36,867 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:36,867 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:36,867 DEBUG --- stdout --- 2024-11-21 00:11:36,867 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:36,867 DEBUG --- stderr --- 2024-11-21 00:11:36,867 DEBUG source : /results/orders/benchmark-120/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stdout.txt 2024-11-21 00:11:36,867 INFO 2024-11-21 00:11:36,867 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:36,867 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:37,138 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:37,138 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:37,138 DEBUG --- stdout --- 2024-11-21 00:11:37,138 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:37,138 DEBUG --- stderr --- 2024-11-21 00:11:37,138 DEBUG 2024-11-21 00:11:37,138 INFO 2024-11-21 00:11:37,138 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-120/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stdout.txt 2024-11-21 00:11:37,138 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 00:11:38,468 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:38,468 DEBUG --- stdout --- 2024-11-21 00:11:38,468 DEBUG tar: Removing leading `/' from member names 2024-11-21 00:11:38,468 DEBUG --- stderr --- 2024-11-21 00:11:38,468 DEBUG ________________________________________________________________________________ [2024-11-21 00:11:38] benchmark-120 show_cmd : Display order command ________________________________________________________________________________ 2024-11-21 00:11:38,469 INFO 2024-11-21 00:11:38,469 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:38,469 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:38,754 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:38,755 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:38,755 DEBUG --- stdout --- 2024-11-21 00:11:38,755 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:38,755 DEBUG --- stderr --- 2024-11-21 00:11:38,755 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 00:11:38,755 INFO 2024-11-21 00:11:38,755 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:38,755 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:39,054 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:39,055 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:39,055 DEBUG --- stdout --- 2024-11-21 00:11:39,055 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:39,055 DEBUG --- stderr --- 2024-11-21 00:11:39,055 DEBUG 2024-11-21 00:11:39,055 INFO 2024-11-21 00:11:39,055 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-120/cmd.txt" ]; then echo "/results/orders/benchmark-120/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-120/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-120/cmd.txt file found" 2024-11-21 00:11:39,055 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 00:11:39,841 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 00:11:39,841 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:39,841 DEBUG --- stdout --- 2024-11-21 00:11:39,841 DEBUG /results/orders/benchmark-120/cmd.txt file found 2024-11-21 00:11:39,841 DEBUG --- stderr --- 2024-11-21 00:11:39,841 DEBUG 2024-11-21 00:11:39,841 INFO 2024-11-21 00:11:39,841 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:39,841 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:40,133 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:40,133 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:40,133 DEBUG --- stdout --- 2024-11-21 00:11:40,133 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:40,133 DEBUG --- stderr --- 2024-11-21 00:11:40,133 DEBUG 2024-11-21 00:11:40,133 INFO 2024-11-21 00:11:40,133 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-120/cmd.txt 2024-11-21 00:11:40,913 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 00:11:40,913 DEBUG --- stdout --- 2024-11-21 00:11:40,913 DEBUG 4 /results/orders/benchmark-120/cmd.txt 2024-11-21 00:11:40,913 DEBUG --- stderr --- 2024-11-21 00:11:40,913 DEBUG 2024-11-21 00:11:40,913 INFO - Download file (size 4k) 2024-11-21 00:11:40,913 INFO 2024-11-21 00:11:40,913 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:40,913 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:41,186 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:41,186 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:41,186 DEBUG --- stdout --- 2024-11-21 00:11:41,186 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:41,186 DEBUG --- stderr --- 2024-11-21 00:11:41,186 DEBUG source : /results/orders/benchmark-120/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/cmd.txt 2024-11-21 00:11:41,186 INFO 2024-11-21 00:11:41,186 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:41,186 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 00:11:41,457 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 00:11:41,457 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:41,457 DEBUG --- stdout --- 2024-11-21 00:11:41,458 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 00:11:41,458 DEBUG --- stderr --- 2024-11-21 00:11:41,458 DEBUG 2024-11-21 00:11:41,458 INFO 2024-11-21 00:11:41,458 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-120/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/cmd.txt 2024-11-21 00:11:41,458 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 00:11:42,204 INFO [loop_until]: OK (rc = 0) 2024-11-21 00:11:42,204 DEBUG --- stdout --- 2024-11-21 00:11:42,204 DEBUG tar: Removing leading `/' from member names 2024-11-21 00:11:42,204 DEBUG --- stderr --- 2024-11-21 00:11:42,204 DEBUG 2024-11-21 00:11:42,204 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/cmd.txt is small (1 lines), printing all lines: 2024-11-21 00:11:42,204 DEBUG ----- output ----- 2024-11-21 00:11:42,204 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-120" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=Pa_ssw0rd" 2024-11-21 00:11:42,204 INFO ________________________________________________________________________________ [2024-11-21 00:11:42] benchmark-120 show_rc : Display rc order ________________________________________________________________________________ 2024-11-21 00:11:42,204 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/rc.txt is small (1 lines), printing all lines: 2024-11-21 00:11:42,204 DEBUG ----- output ----- 2024-11-21 00:11:42,204 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-21 00:11:42,204 INFO ________________________________________________________________________________ [2024-11-21 00:11:42] benchmark-120 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-21 00:11:42,214 DEBUG [print_head_tail]: Print head (100 lines) and tail (100 lines) of input file (/mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stdout.txt is 83778 lines): 2024-11-21 00:11:42,215 DEBUG ----- output ----- 2024-11-21 00:11:42,215 INFO 2024-11-20 23:11:05,424 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpvgh_5fg2 2024-11-21 00:11:42,215 INFO 2024-11-20 23:11:05,426 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-120" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self120- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=120 -Duser_password=**** 2024-11-21 00:11:42,215 INFO [INFO] Scanning for projects... 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-21 00:11:42,215 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-21 00:11:42,215 INFO [INFO] from pom.xml 2024-11-21 00:11:42,215 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-21 00:11:42,215 INFO [INFO] skip non existing resourceDirectory /tmp/tmpvgh_5fg2/src/main/resources 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-21 00:11:42,215 INFO [INFO] No sources to compile 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-21 00:11:42,215 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-21 00:11:42,215 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-21 00:11:42,215 INFO [INFO] compiling 38 Scala sources to /tmp/tmpvgh_5fg2/target/test-classes ... 2024-11-21 00:11:42,215 INFO [INFO] compile in 6.8 s 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] 2024-11-21 00:11:42,215 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-21 00:11:42,215 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-21 00:11:42,215 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-21 00:11:42,215 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-21 00:11:42,215 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-21 00:11:42,215 INFO 23:11:18.699 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,215 INFO 2024-11-21 00:11:42,215 INFO ================================================================================ 2024-11-21 00:11:42,215 INFO 2024-11-20 23:11:21 GMT 4s elapsed 2024-11-21 00:11:42,215 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 00:11:42,215 INFO > Global (OK=552 KO=0 ) 2024-11-21 00:11:42,215 INFO > restLoginInitiate (OK=47 KO=0 ) 2024-11-21 00:11:42,215 INFO > restLoginUsernamePasswordCallback (OK=46 KO=0 ) 2024-11-21 00:11:42,215 INFO > User Authorize PKCE stage (OK=50 KO=0 ) 2024-11-21 00:11:42,215 INFO > User AccessToken PKCE stage (OK=50 KO=0 ) 2024-11-21 00:11:42,215 INFO > tokenUserinfo (OK=6 KO=0 ) 2024-11-21 00:11:42,215 INFO > Skip 2FA (OK=24 KO=0 ) 2024-11-21 00:11:42,215 INFO > GetUUid (OK=18 KO=0 ) 2024-11-21 00:11:42,215 INFO > GetOpenidConfig (OK=18 KO=0 ) 2024-11-21 00:11:42,215 INFO > CreatePolicy (OK=18 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI-Post-Login - stage 1 (OK=12 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=12 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI AM idFromSession (OK=12 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI AM validateGoto (OK=12 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI-Post-Login - stage 2 (OK=11 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=10 KO=0 ) 2024-11-21 00:11:42,215 INFO > UI Enduser appAuthHelper2 (OK=10 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI Enduser appAuthHelper1 (OK=10 KO=0 ) 2024-11-21 00:11:42,216 INFO > restloginProgressiveProfileCallback (OK=4 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI-Post-Login - stage 3 (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI Enduser sessioncheck (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM uiconfig (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM version (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM features (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM privilege (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM login (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM managed user schema (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM dashboard (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM user (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI IDM oidcToken (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > userinfo (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI-Logout (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI-Logout Redirect 1 (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI AM revoke1 (OK=8 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI AM revoke2 (OK=8 KO=0 ) 2024-11-21 00:11:42,216 INFO > UI AM endsession (OK=9 KO=0 ) 2024-11-21 00:11:42,216 INFO > getIdToken (OK=3 KO=0 ) 2024-11-21 00:11:42,216 INFO > getIdToken Redirect 1 (OK=3 KO=0 ) 2024-11-21 00:11:42,216 INFO > RootUserinfo (OK=5 KO=0 ) 2024-11-21 00:11:42,216 INFO > createOrganization (OK=3 KO=0 ) 2024-11-21 00:11:42,216 INFO > queryOrganization (OK=2 KO=0 ) 2024-11-21 00:11:42,216 INFO > deleteOrganization (OK=2 KO=0 ) 2024-11-21 00:11:42,216 INFO > loginTreeWorkflow_restLoginInitiate (OK=2 KO=0 ) 2024-11-21 00:11:42,216 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=2 KO=0 ) 2024-11-21 00:11:42,216 INFO ---- Errors -------------------------------------------------------------------- 2024-11-21 00:11:42,216 INFO > tokenUserinfo: No attribute named 'access_token' is defined 1 (100.0%) 2024-11-21 00:11:42,216 INFO 2024-11-21 00:11:42,216 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-21 00:11:42,216 INFO [- ] 0% 2024-11-21 00:11:42,216 INFO waiting: 434920 / active: 31 / done: 19 2024-11-21 00:11:42,216 INFO ================================================================================ 2024-11-21 00:11:42,216 INFO 2024-11-21 00:11:42,216 INFO 23:11:21.376 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO 23:11:21.826 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO 23:11:22.930 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO 23:11:23.516 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO 23:11:24.175 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO 23:11:25.120 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO 23:11:25.662 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 00:11:42,216 INFO [...] 2024-11-21 00:11:42,229 INFO HTTP request: 2024-11-21 00:11:42,229 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate 2024-11-21 00:11:42,229 INFO headers: 2024-11-21 00:11:42,229 INFO accept: application/json 2024-11-21 00:11:42,229 INFO content-type: application/json 2024-11-21 00:11:42,229 INFO user-agent: Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/602.1.50 (KHTML, like Gecko) CriOS/56.0.2924.75 Mobile/14E5239e Safari/602.1 2024-11-21 00:11:42,229 INFO X-Forwarded-For: 243.251.10.165 2024-11-21 00:11:42,229 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 00:11:42,229 INFO content-length: 0 2024-11-21 00:11:42,229 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 00:11:42,229 INFO ========================= 2024-11-21 00:11:42,229 INFO HTTP response: 2024-11-21 00:11:42,229 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 00:11:42,229 INFO 00:11:16.219 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 431336: j.i.IOException: Premature close 2024-11-21 00:11:42,229 INFO 00:11:16.219 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-133' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 00:11:42,229 INFO 00:11:16.219 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-190' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 00:11:42,229 INFO 00:11:16.219 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 00:11:42,229 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 00:11:42,229 INFO Request: 2024-11-21 00:11:42,229 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 00:11:42,229 INFO ========================= 2024-11-21 00:11:42,229 INFO Session: 2024-11-21 00:11:42,229 INFO Session(idc.benchmark.Mix2024,431336,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.76876, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@2ffa8751, fake-user-agent -> Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36, password -> Pa_ssw0rd, fake-ip -> 73.203.109.46, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@75018c45),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fdf0c69a0e0@5b9edbc8,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-21 00:11:42,229 INFO ========================= 2024-11-21 00:11:42,229 INFO HTTP request: 2024-11-21 00:11:42,229 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate 2024-11-21 00:11:42,229 INFO headers: 2024-11-21 00:11:42,229 INFO accept: application/json 2024-11-21 00:11:42,229 INFO content-type: application/json 2024-11-21 00:11:42,229 INFO user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36 2024-11-21 00:11:42,229 INFO X-Forwarded-For: 73.203.109.46 2024-11-21 00:11:42,229 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 00:11:42,229 INFO content-length: 0 2024-11-21 00:11:42,229 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 00:11:42,229 INFO ========================= 2024-11-21 00:11:42,229 INFO HTTP response: 2024-11-21 00:11:42,229 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 00:11:42,229 INFO 00:11:16.222 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-190' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 00:11:42,229 INFO 00:11:16.223 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request ' UI IDM login' failed for user 431200: j.i.IOException: Premature close 2024-11-21 00:11:42,229 INFO 00:11:16.223 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 00:11:42,229 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 00:11:42,229 INFO Request: 2024-11-21 00:11:42,229 INFO UI IDM login: KO j.i.IOException: Premature close 2024-11-21 00:11:42,229 INFO ========================= 2024-11-21 00:11:42,230 INFO Session: 2024-11-21 00:11:42,230 INFO Session(idc.benchmark.Mix2024,431200,HashMap(access_token -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJkZWU3NDAzNS0zMjA3LTQ5YjctODliZS03ODEzZjAwZGUyZjEiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiNzMzNWU4ODEtZDhmZi00MmQ4LTkxNTAtMzIwOTc1NjQyZjlmLTUwNzI4ODEwIiwic3VibmFtZSI6ImRlZTc0MDM1LTMyMDctNDliNy04OWJlLTc4MTNmMDBkZTJmMSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6IjIwa0Y2azI0c21vTE11V2s4MFJ2Nlc5VDRqYyIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMjE0Nzg3NSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbIm9wZW5pZCIsImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMjE0Nzg3NSwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzIxNTE0NzUsImlhdCI6MTczMjE0Nzg3NSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoieHp3V0NfckNheDV3eFpZbWZpcnMycm1DY0JvIn0.PgveWtwS6EaYtJ53lhbULxS_6ep-VnNG_maw_EmGmCE, username -> user.51212, access_token_2 -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJkZWU3NDAzNS0zMjA3LTQ5YjctODliZS03ODEzZjAwZGUyZjEiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiNzMzNWU4ODEtZDhmZi00MmQ4LTkxNTAtMzIwOTc1NjQyZjlmLTUwNzI5OTQzIiwic3VibmFtZSI6ImRlZTc0MDM1LTMyMDctNDliNy04OWJlLTc4MTNmMDBkZTJmMSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6ImtkTjZOcGJJdkI5bmtPZUljby10UGNheEowRSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMjE0Nzg3NiwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMjE0Nzg3NSwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzIxNTE0NzYsImlhdCI6MTczMjE0Nzg3NiwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiYTd0SE9IOEQ3eTMzQ1NBMy1MTi1nemctbmdBIn0.Gv3ummqI1kYPBeuTmmW6-xD2DeKAVUkWeM3c57NsY8Q, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@7ccfc8f4, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, authcode -> XPsY-gxQBbrpGPERsK-dzww0VEM, callbacks -> {"tokenId":"lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1732147875406), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1732147875406))), user_uuid -> dee74035-3207-49b7-89be-7813f00de2f1, password -> Pa_ssw0rd, challenge -> pmrkm8RoyHM_2kTPy-_248FMzlurMNi6V7AaqI5QnSo, gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, fake-ip -> 131.93.46.15, verifier -> MjAxNjU2OTUwNTY1MTc2NDAxNA, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@27533c7d, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@4fb9c5e9, tokenId -> lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, 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),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fdf0c69a0e0@5b9edbc8,io.netty.channel.epoll.EpollEventLoop@636e8cc) 2024-11-21 00:11:42,230 INFO ========================= 2024-11-21 00:11:42,230 INFO HTTP request: 2024-11-21 00:11:42,230 INFO POST https://openam-perf-benchmark.forgeblocks.com/openidm/authentication?_action=login 2024-11-21 00:11:42,230 INFO headers: 2024-11-21 00:11:42,230 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 12_5_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36 2024-11-21 00:11:42,230 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-21 00:11:42,230 INFO Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJkZWU3NDAzNS0zMjA3LTQ5YjctODliZS03ODEzZjAwZGUyZjEiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiNzMzNWU4ODEtZDhmZi00MmQ4LTkxNTAtMzIwOTc1NjQyZjlmLTUwNzI5OTQzIiwic3VibmFtZSI6ImRlZTc0MDM1LTMyMDctNDliNy04OWJlLTc4MTNmMDBkZTJmMSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6ImtkTjZOcGJJdkI5bmtPZUljby10UGNheEowRSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMjE0Nzg3NiwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMjE0Nzg3NSwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzIxNTE0NzYsImlhdCI6MTczMjE0Nzg3NiwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiYTd0SE9IOEQ3eTMzQ1NBMy1MTi1nemctbmdBIn0.Gv3ummqI1kYPBeuTmmW6-xD2DeKAVUkWeM3c57NsY8Q 2024-11-21 00:11:42,230 INFO Accept-Api-Version: 2024-11-21 00:11:42,230 INFO accept: */* 2024-11-21 00:11:42,230 INFO cookie: amlbcookie=01; 9b75a55744995d0=lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-21 00:11:42,230 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-21 00:11:42,230 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 00:11:42,230 INFO content-length: 0 2024-11-21 00:11:42,230 INFO cookies: 2024-11-21 00:11:42,230 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 00:11:42,230 INFO 9b75a55744995d0=lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 00:11:42,230 INFO ========================= 2024-11-21 00:11:42,230 INFO HTTP response: 2024-11-21 00:11:42,230 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 00:11:42,230 INFO 00:11:16.224 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request ' UI IDM privilege' failed for user 431200: j.i.IOException: Premature close 2024-11-21 00:11:42,230 INFO 00:11:16.224 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 00:11:42,230 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 00:11:42,230 INFO Request: 2024-11-21 00:11:42,230 INFO UI IDM privilege: KO j.i.IOException: Premature close 2024-11-21 00:11:42,230 INFO ========================= 2024-11-21 00:11:42,230 INFO Session: 2024-11-21 00:11:42,230 INFO Session(idc.benchmark.Mix2024,431200,HashMap(access_token -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJkZWU3NDAzNS0zMjA3LTQ5YjctODliZS03ODEzZjAwZGUyZjEiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiNzMzNWU4ODEtZDhmZi00MmQ4LTkxNTAtMzIwOTc1NjQyZjlmLTUwNzI4ODEwIiwic3VibmFtZSI6ImRlZTc0MDM1LTMyMDctNDliNy04OWJlLTc4MTNmMDBkZTJmMSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6IjIwa0Y2azI0c21vTE11V2s4MFJ2Nlc5VDRqYyIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMjE0Nzg3NSwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbIm9wZW5pZCIsImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMjE0Nzg3NSwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzIxNTE0NzUsImlhdCI6MTczMjE0Nzg3NSwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoieHp3V0NfckNheDV3eFpZbWZpcnMycm1DY0JvIn0.PgveWtwS6EaYtJ53lhbULxS_6ep-VnNG_maw_EmGmCE, username -> user.51212, access_token_2 -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJkZWU3NDAzNS0zMjA3LTQ5YjctODliZS03ODEzZjAwZGUyZjEiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiNzMzNWU4ODEtZDhmZi00MmQ4LTkxNTAtMzIwOTc1NjQyZjlmLTUwNzI5OTQzIiwic3VibmFtZSI6ImRlZTc0MDM1LTMyMDctNDliNy04OWJlLTc4MTNmMDBkZTJmMSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6ImtkTjZOcGJJdkI5bmtPZUljby10UGNheEowRSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMjE0Nzg3NiwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMjE0Nzg3NSwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzIxNTE0NzYsImlhdCI6MTczMjE0Nzg3NiwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiYTd0SE9IOEQ3eTMzQ1NBMy1MTi1nemctbmdBIn0.Gv3ummqI1kYPBeuTmmW6-xD2DeKAVUkWeM3c57NsY8Q, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@7ccfc8f4, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, authcode -> XPsY-gxQBbrpGPERsK-dzww0VEM, callbacks -> {"tokenId":"lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1732147875406), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1732147875406))), user_uuid -> dee74035-3207-49b7-89be-7813f00de2f1, password -> Pa_ssw0rd, challenge -> pmrkm8RoyHM_2kTPy-_248FMzlurMNi6V7AaqI5QnSo, gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, fake-ip -> 131.93.46.15, verifier -> MjAxNjU2OTUwNTY1MTc2NDAxNA, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@27533c7d, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@4fb9c5e9, tokenId -> lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, 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),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007fdf0c69a0e0@5b9edbc8,io.netty.channel.epoll.EpollEventLoop@636e8cc) 2024-11-21 00:11:42,230 INFO ========================= 2024-11-21 00:11:42,230 INFO HTTP request: 2024-11-21 00:11:42,230 INFO POST https://openam-perf-benchmark.forgeblocks.com/openidm/privilege?_action=listPrivileges 2024-11-21 00:11:42,230 INFO headers: 2024-11-21 00:11:42,230 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 12_5_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36 2024-11-21 00:11:42,230 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-21 00:11:42,230 INFO Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJkZWU3NDAzNS0zMjA3LTQ5YjctODliZS03ODEzZjAwZGUyZjEiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiNzMzNWU4ODEtZDhmZi00MmQ4LTkxNTAtMzIwOTc1NjQyZjlmLTUwNzI5OTQzIiwic3VibmFtZSI6ImRlZTc0MDM1LTMyMDctNDliNy04OWJlLTc4MTNmMDBkZTJmMSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6ImtkTjZOcGJJdkI5bmtPZUljby10UGNheEowRSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMjE0Nzg3NiwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMjE0Nzg3NSwicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzIxNTE0NzYsImlhdCI6MTczMjE0Nzg3NiwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiYTd0SE9IOEQ3eTMzQ1NBMy1MTi1nemctbmdBIn0.Gv3ummqI1kYPBeuTmmW6-xD2DeKAVUkWeM3c57NsY8Q 2024-11-21 00:11:42,230 INFO Accept-Api-Version: 2024-11-21 00:11:42,230 INFO accept: */* 2024-11-21 00:11:42,230 INFO cookie: amlbcookie=01; 9b75a55744995d0=lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-21 00:11:42,230 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-21 00:11:42,230 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 00:11:42,230 INFO content-length: 0 2024-11-21 00:11:42,230 INFO cookies: 2024-11-21 00:11:42,230 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 00:11:42,230 INFO 9b75a55744995d0=lckPN_fZwqhkhLyzeVGUk1ymvvo.*AAJTSQACMDIAAlNLABxDWmUvd29NTjRsRDE2dU9DbW8vRzhuWk04cEk9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-21 00:11:42,230 INFO ========================= 2024-11-21 00:11:42,230 INFO HTTP response: 2024-11-21 00:11:42,230 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 00:11:42,230 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 00:11:42,230 INFO [INFO] BUILD SUCCESS 2024-11-21 00:11:42,230 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 00:11:42,230 INFO [INFO] Total time: 01:00 h 2024-11-21 00:11:42,230 INFO [INFO] Finished at: 2024-11-21T00:11:16Z 2024-11-21 00:11:42,230 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 00:11:42,230 INFO 2024-11-21 00:11:16,351 INFO Gatling simulation run ended successfully 2024-11-21 00:11:42,230 INFO 2024-11-21 00:11:16,351 DEBUG No archive name provided. No archive will be created 2024-11-21 00:11:42,230 INFO ________________________________________________________________________________ [2024-11-21 00:11:42] benchmark-120 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-21 00:11:42,231 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/05_benchmark-120/stderr.txt is small (0 lines), printing all lines: 2024-11-21 00:11:42,231 DEBUG ----- output ----- 2024-11-21 00:11:42,231 DEBUG 2024-11-21 00:11:42,231 INFO ________________________________________________________________________________ [2024-11-21 00:11:42] benchmark-120 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-11-21 00:11:42] benchmark-120 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-21 00:11:42] benchmark-120 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped