--Task-- name: benchmark-50 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates below loop: False interval: None dependencies: [] wait_for: ['benchmark-30'] preceding_task: benchmark-30 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self50-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 50} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-14 03:27:59] benchmark-50 pre : N/A ________________________________________________________________________________ 2024-11-14 03:27:59 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-14 03:27:59 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-50/stdout.txt Pod log : /results/orders/benchmark-50 2024-11-14 03:27:59,888 INFO 2024-11-14 03:27:59,888 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-14 03:27:59,888 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:28:00,432 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:28:00,432 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:00,432 DEBUG --- stdout --- 2024-11-14 03:28:00,432 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:28:00,432 DEBUG --- stderr --- 2024-11-14 03:28:00,432 DEBUG ________________________________________________________________________________ [2024-11-14 03:28:00] benchmark-50 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-14 03:28:00,433 INFO 2024-11-14 03:28:00,433 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-14 03:28:00,433 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:28:00,709 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:28:00,709 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:00,709 DEBUG --- stdout --- 2024-11-14 03:28:00,709 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:28:00,709 DEBUG --- stderr --- 2024-11-14 03:28:00,709 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-50" --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=self50- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=50 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-14 03:28:00] benchmark-50 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-14 03:28:00,710 INFO 2024-11-14 03:28:00,710 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-14 03:28:00,710 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:28:00,988 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:28:00,988 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:00,988 DEBUG --- stdout --- 2024-11-14 03:28:00,988 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:28:00,988 DEBUG --- stderr --- 2024-11-14 03:28:00,988 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/order.json { "name": "benchmark-50", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-50\" --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=self50- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=50 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-50" } ________________________________________________________________________________ [2024-11-14 03:28:00] benchmark-50 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-14 03:28:00,991 INFO 2024-11-14 03:28:00,991 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-14 03:28:00,991 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-14 03:28:01,208 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 03:28:01,208 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:01,208 DEBUG --- stdout --- 2024-11-14 03:28:01,208 DEBUG WAITING 2024-11-14 03:28:01,208 DEBUG --- stderr --- 2024-11-14 03:28:01,208 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 33 0 --:--:-- --:--:-- --:--:-- 33 ________________________________________________________________________________ [2024-11-14 03:28:01] benchmark-50 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-14 03:28:01,208 INFO 2024-11-14 03:28:01,208 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-14 03:28:01,208 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:28:01,483 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:28:01,483 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:01,483 DEBUG --- stdout --- 2024-11-14 03:28:01,483 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:28:01,483 DEBUG --- stderr --- 2024-11-14 03:28:01,483 DEBUG 2024-11-14 03:28:01,483 INFO 2024-11-14 03:28:01,483 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/03_benchmark-50/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-14 03:28:01,483 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 03:28:02,842 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:02,842 DEBUG --- stdout --- 2024-11-14 03:28:02,842 DEBUG 2024-11-14 03:28:02,842 DEBUG --- stderr --- 2024-11-14 03:28:02,842 DEBUG Order has been successfully forwarded to overseer 2024-11-14 03:28:02 - INFO: Check if Gatling simulation started successfully 2024-11-14 03:28:02,842 INFO 2024-11-14 03:28:02,842 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-14 03:28:02,842 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 03:28:03,118 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 03:28:03,118 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:03,118 DEBUG --- stdout --- 2024-11-14 03:28:03,118 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 03:28:03,118 DEBUG --- stderr --- 2024-11-14 03:28:03,118 DEBUG 2024-11-14 03:28:03,119 INFO 2024-11-14 03:28:03,119 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-50/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-14 03:28:03,119 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-14 03:28:03,852 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-14 03:28:09,587 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-14 03:28:15,316 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-14 03:28:15,316 INFO [loop_until]: OK (rc = 0) 2024-11-14 03:28:15,316 DEBUG --- stdout --- 2024-11-14 03:28:15,316 DEBUG 2024-11-14 03:28:03,588 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpgqmof8bn 2024-11-14 03:28:03,590 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-50" -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=self50- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=50 -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/tmpgqmof8bn/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/tmpgqmof8bn/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. 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-14 03:28:15,316 DEBUG --- stderr --- 2024-11-14 03:28:15,316 DEBUG ________________________________________________________________________________ [2024-11-14 03:28:15] benchmark-50 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 01s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 02s, retry Order is running since 22m 03s, retry Order is running since 24m 03s, retry Order is running since 26m 03s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 04s, retry Order is running since 34m 04s, retry Order is running since 36m 05s, retry Order is running since 38m 05s, retry Order is running since 40m 05s, retry Order is running since 42m 06s, retry Order is running since 44m 06s, retry Order is running since 46m 06s, retry Order is running since 48m 06s, retry Order is running since 50m 07s, retry Order is running since 52m 07s, retry Order is running since 54m 07s, retry Order is running since 56m 08s, retry Order is running since 58m 08s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-14 04:28:24] benchmark-50 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-14 04:28:24,048 INFO 2024-11-14 04:28:24,048 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-14 04:28:24,048 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:24,353 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:24,353 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:24,353 DEBUG --- stdout --- 2024-11-14 04:28:24,353 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:24,353 DEBUG --- stderr --- 2024-11-14 04:28:24,353 DEBUG 2024-11-14 04:28:24,353 INFO 2024-11-14 04:28:24,353 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-14 04:28:24,353 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 04:28:25,177 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:25,177 DEBUG --- stdout --- 2024-11-14 04:28:25,177 DEBUG 2024-11-14 04:28:25,177 DEBUG --- stderr --- 2024-11-14 04:28:25,177 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-14 04:28:25] benchmark-50 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-14 04:28:25 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/order.json 2024-11-14 04:28:25,177 INFO 2024-11-14 04:28:25,177 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-14 04:28:25,177 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:25,452 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:25,452 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:25,452 DEBUG --- stdout --- 2024-11-14 04:28:25,452 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:25,452 DEBUG --- stderr --- 2024-11-14 04:28:25,452 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 04:28:25,453 INFO 2024-11-14 04:28:25,453 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-14 04:28:25,453 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:25,728 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:25,729 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:25,729 DEBUG --- stdout --- 2024-11-14 04:28:25,729 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:25,729 DEBUG --- stderr --- 2024-11-14 04:28:25,729 DEBUG 2024-11-14 04:28:25,729 INFO 2024-11-14 04:28:25,729 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-50/rc.txt" ]; then echo "/results/orders/benchmark-50/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-50/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/rc.txt file found" 2024-11-14 04:28:25,729 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 04:28:26,518 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 04:28:26,518 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:26,518 DEBUG --- stdout --- 2024-11-14 04:28:26,518 DEBUG /results/orders/benchmark-50/rc.txt file found 2024-11-14 04:28:26,518 DEBUG --- stderr --- 2024-11-14 04:28:26,518 DEBUG 2024-11-14 04:28:26,518 INFO 2024-11-14 04:28:26,518 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-14 04:28:26,518 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:26,798 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:26,798 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:26,798 DEBUG --- stdout --- 2024-11-14 04:28:26,798 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:26,798 DEBUG --- stderr --- 2024-11-14 04:28:26,798 DEBUG 2024-11-14 04:28:26,798 INFO 2024-11-14 04:28:26,798 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-50/rc.txt 2024-11-14 04:28:27,618 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 04:28:27,618 DEBUG --- stdout --- 2024-11-14 04:28:27,618 DEBUG 4 /results/orders/benchmark-50/rc.txt 2024-11-14 04:28:27,618 DEBUG --- stderr --- 2024-11-14 04:28:27,618 DEBUG 2024-11-14 04:28:27,618 INFO - Download file (size 4k) 2024-11-14 04:28:27,618 INFO 2024-11-14 04:28:27,618 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-14 04:28:27,618 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:27,898 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:27,898 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:27,898 DEBUG --- stdout --- 2024-11-14 04:28:27,898 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:27,898 DEBUG --- stderr --- 2024-11-14 04:28:27,898 DEBUG source : /results/orders/benchmark-50/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/rc.txt 2024-11-14 04:28:27,899 INFO 2024-11-14 04:28:27,899 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-14 04:28:27,899 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:28,175 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:28,175 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:28,176 DEBUG --- stdout --- 2024-11-14 04:28:28,176 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:28,176 DEBUG --- stderr --- 2024-11-14 04:28:28,176 DEBUG 2024-11-14 04:28:28,176 INFO 2024-11-14 04:28:28,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-50/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/rc.txt 2024-11-14 04:28:28,176 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 04:28:28,935 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:28,935 DEBUG --- stdout --- 2024-11-14 04:28:28,935 DEBUG tar: Removing leading `/' from member names 2024-11-14 04:28:28,935 DEBUG --- stderr --- 2024-11-14 04:28:28,935 DEBUG 2024-11-14 04:28:28,936 INFO 2024-11-14 04:28:28,936 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-14 04:28:28,936 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:29,211 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:29,211 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:29,211 DEBUG --- stdout --- 2024-11-14 04:28:29,211 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:29,211 DEBUG --- stderr --- 2024-11-14 04:28:29,211 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 04:28:29,211 INFO 2024-11-14 04:28:29,211 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-14 04:28:29,211 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:29,491 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:29,491 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:29,491 DEBUG --- stdout --- 2024-11-14 04:28:29,491 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:29,491 DEBUG --- stderr --- 2024-11-14 04:28:29,491 DEBUG 2024-11-14 04:28:29,492 INFO 2024-11-14 04:28:29,492 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-50/stderr.txt" ]; then echo "/results/orders/benchmark-50/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-50/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/stderr.txt file found" 2024-11-14 04:28:29,492 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 04:28:30,286 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 04:28:30,287 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:30,287 DEBUG --- stdout --- 2024-11-14 04:28:30,287 DEBUG /results/orders/benchmark-50/stderr.txt file found 2024-11-14 04:28:30,287 DEBUG --- stderr --- 2024-11-14 04:28:30,287 DEBUG 2024-11-14 04:28:30,287 INFO 2024-11-14 04:28:30,287 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-14 04:28:30,287 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:30,564 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:30,565 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:30,565 DEBUG --- stdout --- 2024-11-14 04:28:30,565 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:30,565 DEBUG --- stderr --- 2024-11-14 04:28:30,565 DEBUG 2024-11-14 04:28:30,565 INFO 2024-11-14 04:28:30,565 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-50/stderr.txt 2024-11-14 04:28:31,360 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 04:28:31,360 DEBUG --- stdout --- 2024-11-14 04:28:31,360 DEBUG 0 /results/orders/benchmark-50/stderr.txt 2024-11-14 04:28:31,360 DEBUG --- stderr --- 2024-11-14 04:28:31,360 DEBUG 2024-11-14 04:28:31,360 INFO - Download file (size 0k) 2024-11-14 04:28:31,361 INFO 2024-11-14 04:28:31,361 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-14 04:28:31,361 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:31,635 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:31,635 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:31,635 DEBUG --- stdout --- 2024-11-14 04:28:31,635 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:31,635 DEBUG --- stderr --- 2024-11-14 04:28:31,635 DEBUG source : /results/orders/benchmark-50/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/stderr.txt 2024-11-14 04:28:31,635 INFO 2024-11-14 04:28:31,635 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-14 04:28:31,635 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:31,912 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:31,912 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:31,912 DEBUG --- stdout --- 2024-11-14 04:28:31,912 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:31,912 DEBUG --- stderr --- 2024-11-14 04:28:31,912 DEBUG 2024-11-14 04:28:31,913 INFO 2024-11-14 04:28:31,913 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-50/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/stderr.txt 2024-11-14 04:28:31,913 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 04:28:32,676 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:32,676 DEBUG --- stdout --- 2024-11-14 04:28:32,676 DEBUG tar: Removing leading `/' from member names 2024-11-14 04:28:32,676 DEBUG --- stderr --- 2024-11-14 04:28:32,676 DEBUG 2024-11-14 04:28:32,677 INFO 2024-11-14 04:28:32,677 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-14 04:28:32,677 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:32,951 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:32,951 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:32,951 DEBUG --- stdout --- 2024-11-14 04:28:32,951 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:32,951 DEBUG --- stderr --- 2024-11-14 04:28:32,951 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 04:28:32,951 INFO 2024-11-14 04:28:32,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-14 04:28:32,951 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:33,225 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:33,225 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:33,225 DEBUG --- stdout --- 2024-11-14 04:28:33,225 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:33,226 DEBUG --- stderr --- 2024-11-14 04:28:33,226 DEBUG 2024-11-14 04:28:33,226 INFO 2024-11-14 04:28:33,226 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-50/stdout.txt" ]; then echo "/results/orders/benchmark-50/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-50/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/stdout.txt file found" 2024-11-14 04:28:33,226 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 04:28:34,024 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 04:28:34,024 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:34,025 DEBUG --- stdout --- 2024-11-14 04:28:34,025 DEBUG /results/orders/benchmark-50/stdout.txt file found 2024-11-14 04:28:34,025 DEBUG --- stderr --- 2024-11-14 04:28:34,025 DEBUG 2024-11-14 04:28:34,026 INFO 2024-11-14 04:28:34,026 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-14 04:28:34,026 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:34,304 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:34,304 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:34,304 DEBUG --- stdout --- 2024-11-14 04:28:34,304 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:34,304 DEBUG --- stderr --- 2024-11-14 04:28:34,304 DEBUG 2024-11-14 04:28:34,304 INFO 2024-11-14 04:28:34,305 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-50/stdout.txt 2024-11-14 04:28:35,105 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 04:28:35,105 DEBUG --- stdout --- 2024-11-14 04:28:35,105 DEBUG 4184 /results/orders/benchmark-50/stdout.txt 2024-11-14 04:28:35,105 DEBUG --- stderr --- 2024-11-14 04:28:35,105 DEBUG 2024-11-14 04:28:35,105 INFO - Download file (size 4184k) 2024-11-14 04:28:35,106 INFO 2024-11-14 04:28:35,106 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-14 04:28:35,106 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:35,383 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:35,383 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:35,383 DEBUG --- stdout --- 2024-11-14 04:28:35,383 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:35,384 DEBUG --- stderr --- 2024-11-14 04:28:35,384 DEBUG source : /results/orders/benchmark-50/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/stdout.txt 2024-11-14 04:28:35,384 INFO 2024-11-14 04:28:35,384 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-14 04:28:35,384 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:35,659 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:35,659 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:35,659 DEBUG --- stdout --- 2024-11-14 04:28:35,659 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:35,659 DEBUG --- stderr --- 2024-11-14 04:28:35,659 DEBUG 2024-11-14 04:28:35,660 INFO 2024-11-14 04:28:35,660 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-50/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/stdout.txt 2024-11-14 04:28:35,660 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 04:28:36,911 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:36,911 DEBUG --- stdout --- 2024-11-14 04:28:36,911 DEBUG tar: Removing leading `/' from member names 2024-11-14 04:28:36,911 DEBUG --- stderr --- 2024-11-14 04:28:36,911 DEBUG ________________________________________________________________________________ [2024-11-14 04:28:36] benchmark-50 show_cmd : Display order command ________________________________________________________________________________ 2024-11-14 04:28:36,911 INFO 2024-11-14 04:28:36,911 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-14 04:28:36,911 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:37,187 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:37,187 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:37,187 DEBUG --- stdout --- 2024-11-14 04:28:37,187 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:37,187 DEBUG --- stderr --- 2024-11-14 04:28:37,187 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-14 04:28:37,187 INFO 2024-11-14 04:28:37,187 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-14 04:28:37,187 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:37,465 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:37,465 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:37,465 DEBUG --- stdout --- 2024-11-14 04:28:37,465 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:37,465 DEBUG --- stderr --- 2024-11-14 04:28:37,465 DEBUG 2024-11-14 04:28:37,465 INFO 2024-11-14 04:28:37,466 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-50/cmd.txt" ]; then echo "/results/orders/benchmark-50/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-50/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/cmd.txt file found" 2024-11-14 04:28:37,466 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-14 04:28:38,260 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-14 04:28:38,260 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:38,260 DEBUG --- stdout --- 2024-11-14 04:28:38,260 DEBUG /results/orders/benchmark-50/cmd.txt file found 2024-11-14 04:28:38,260 DEBUG --- stderr --- 2024-11-14 04:28:38,260 DEBUG 2024-11-14 04:28:38,260 INFO 2024-11-14 04:28:38,261 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-14 04:28:38,261 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:38,538 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:38,538 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:38,538 DEBUG --- stdout --- 2024-11-14 04:28:38,538 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:38,538 DEBUG --- stderr --- 2024-11-14 04:28:38,538 DEBUG 2024-11-14 04:28:38,538 INFO 2024-11-14 04:28:38,538 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-50/cmd.txt 2024-11-14 04:28:39,339 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-14 04:28:39,339 DEBUG --- stdout --- 2024-11-14 04:28:39,339 DEBUG 4 /results/orders/benchmark-50/cmd.txt 2024-11-14 04:28:39,339 DEBUG --- stderr --- 2024-11-14 04:28:39,339 DEBUG 2024-11-14 04:28:39,339 INFO - Download file (size 4k) 2024-11-14 04:28:39,339 INFO 2024-11-14 04:28:39,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-14 04:28:39,339 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:39,616 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:39,616 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:39,616 DEBUG --- stdout --- 2024-11-14 04:28:39,616 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:39,616 DEBUG --- stderr --- 2024-11-14 04:28:39,616 DEBUG source : /results/orders/benchmark-50/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/cmd.txt 2024-11-14 04:28:39,616 INFO 2024-11-14 04:28:39,616 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-14 04:28:39,616 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-14 04:28:39,894 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-14 04:28:39,894 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:39,894 DEBUG --- stdout --- 2024-11-14 04:28:39,894 DEBUG overseer-0-6644bb6697-rchxr 2024-11-14 04:28:39,894 DEBUG --- stderr --- 2024-11-14 04:28:39,894 DEBUG 2024-11-14 04:28:39,894 INFO 2024-11-14 04:28:39,894 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-50/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/cmd.txt 2024-11-14 04:28:39,894 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-14 04:28:40,652 INFO [loop_until]: OK (rc = 0) 2024-11-14 04:28:40,652 DEBUG --- stdout --- 2024-11-14 04:28:40,652 DEBUG tar: Removing leading `/' from member names 2024-11-14 04:28:40,652 DEBUG --- stderr --- 2024-11-14 04:28:40,652 DEBUG 2024-11-14 04:28:40,652 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/cmd.txt is small (1 lines), printing all lines: 2024-11-14 04:28:40,653 DEBUG ----- output ----- 2024-11-14 04:28:40,653 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-50" --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=self50- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=50 -Duser_password=Pa_ssw0rd" 2024-11-14 04:28:40,653 INFO ________________________________________________________________________________ [2024-11-14 04:28:40] benchmark-50 show_rc : Display rc order ________________________________________________________________________________ 2024-11-14 04:28:40,653 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/rc.txt is small (1 lines), printing all lines: 2024-11-14 04:28:40,653 DEBUG ----- output ----- 2024-11-14 04:28:40,653 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-14 04:28:40,653 INFO ________________________________________________________________________________ [2024-11-14 04:28:40] benchmark-50 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-14 04:28:40,658 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/03_benchmark-50/stdout.txt is 52349 lines): 2024-11-14 04:28:40,658 DEBUG ----- output ----- 2024-11-14 04:28:40,658 INFO 2024-11-14 03:28:03,588 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpgqmof8bn 2024-11-14 04:28:40,659 INFO 2024-11-14 03:28:03,590 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-50" -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=self50- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=50 -Duser_password=**** 2024-11-14 04:28:40,659 INFO [INFO] Scanning for projects... 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-14 04:28:40,659 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-14 04:28:40,659 INFO [INFO] from pom.xml 2024-11-14 04:28:40,659 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-14 04:28:40,659 INFO [INFO] skip non existing resourceDirectory /tmp/tmpgqmof8bn/src/main/resources 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-14 04:28:40,659 INFO [INFO] No sources to compile 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-14 04:28:40,659 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-14 04:28:40,659 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-14 04:28:40,659 INFO [INFO] compiling 38 Scala sources to /tmp/tmpgqmof8bn/target/test-classes ... 2024-11-14 04:28:40,659 INFO [INFO] compile in 6.7 s 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] 2024-11-14 04:28:40,659 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-14 04:28:40,659 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-14 04:28:40,659 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-14 04:28:40,659 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-14 04:28:40,659 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-14 04:28:40,659 INFO 03:28:19.189 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-14 04:28:40,659 INFO 2024-11-14 04:28:40,659 INFO ================================================================================ 2024-11-14 04:28:40,659 INFO 2024-11-14 03:28:19 GMT 5s elapsed 2024-11-14 04:28:40,659 INFO ---- Requests ------------------------------------------------------------------ 2024-11-14 04:28:40,659 INFO > Global (OK=198 KO=0 ) 2024-11-14 04:28:40,659 INFO > restLoginInitiate (OK=20 KO=0 ) 2024-11-14 04:28:40,659 INFO > restLoginUsernamePasswordCallback (OK=19 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI-Post-Login - stage 1 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI AM idFromSession (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI AM validateGoto (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > User Authorize PKCE stage (OK=21 KO=0 ) 2024-11-14 04:28:40,659 INFO > User AccessToken PKCE stage (OK=21 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI-Post-Login - stage 2 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI Enduser appAuthHelper1 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI Enduser appAuthHelper2 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI-Post-Login - stage 3 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI Enduser sessioncheck (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI IDM uiconfig (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI IDM version (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > Skip 2FA (OK=9 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI IDM login (OK=3 KO=0 ) 2024-11-14 04:28:40,659 INFO > UI IDM features (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI IDM privilege (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI IDM dashboard (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI IDM managed user schema (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI IDM user (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI IDM oidcToken (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > userinfo (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > RootUserinfo (OK=5 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI-Logout (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI-Logout Redirect 1 (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI AM revoke2 (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI AM endsession (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI AM revoke1 (OK=3 KO=0 ) 2024-11-14 04:28:40,660 INFO > GetUUid (OK=6 KO=0 ) 2024-11-14 04:28:40,660 INFO > GetOpenidConfig (OK=6 KO=0 ) 2024-11-14 04:28:40,660 INFO > CreatePolicy (OK=6 KO=0 ) 2024-11-14 04:28:40,660 INFO > tokenUserinfo (OK=6 KO=0 ) 2024-11-14 04:28:40,660 INFO > getIdToken (OK=1 KO=0 ) 2024-11-14 04:28:40,660 INFO ---- Errors -------------------------------------------------------------------- 2024-11-14 04:28:40,660 INFO > tokenUserinfo: No attribute named 'access_token' is defined 1 (100.0%) 2024-11-14 04:28:40,660 INFO 2024-11-14 04:28:40,660 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-14 04:28:40,660 INFO [- ] 0% 2024-11-14 04:28:40,660 INFO waiting: 180789 / active: 10 / done: 10 2024-11-14 04:28:40,660 INFO ================================================================================ 2024-11-14 04:28:40,660 INFO 2024-11-14 04:28:40,660 INFO 2024-11-14 04:28:40,660 INFO ================================================================================ 2024-11-14 04:28:40,660 INFO 2024-11-14 03:28:24 GMT 10s elapsed 2024-11-14 04:28:40,660 INFO ---- Requests ------------------------------------------------------------------ 2024-11-14 04:28:40,660 INFO > Global (OK=1021 KO=0 ) 2024-11-14 04:28:40,660 INFO > restLoginInitiate (OK=81 KO=0 ) 2024-11-14 04:28:40,660 INFO > restLoginUsernamePasswordCallback (OK=80 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI-Post-Login - stage 1 (OK=20 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=20 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI AM idFromSession (OK=20 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI AM validateGoto (OK=20 KO=0 ) 2024-11-14 04:28:40,660 INFO > User Authorize PKCE stage (OK=95 KO=0 ) 2024-11-14 04:28:40,660 INFO > User AccessToken PKCE stage (OK=93 KO=0 ) 2024-11-14 04:28:40,660 INFO > UI-Post-Login - stage 2 (OK=19 KO=0 ) 2024-11-14 04:28:40,660 INFO [...] 2024-11-14 04:28:40,667 INFO Session(idc.benchmark.Mix2024,179257,HashMap(access_token -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIyMWU5MDJhNi1kZWMxLTRkNjYtYjkzMy1jMmYwNGFmZmNkM2EiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiYTA2NGI3YzctNmJiYS00Y2MwLTg3ZTgtM2RhY2IxODliOTNkLTc1MDI5NTk0Iiwic3VibmFtZSI6IjIxZTkwMmE2LWRlYzEtNGQ2Ni1iOTMzLWMyZjA0YWZmY2QzYSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6ImZzZGxXMUR0X0tMNW1pS3l1cDd6X1RFS21WYyIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTU1ODQ5MywiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbIm9wZW5pZCIsImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTU1ODQ5MywicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1NjIwOTMsImlhdCI6MTczMTU1ODQ5MywiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiWEMybHl3WkFsOWNJd1NocndhS0cybE5HRzEwIn0.eMkaAX6izRpuIKlH0PVpdqOKl3Z8cxaeXzlwe14iNoQ, username -> user.178092, access_token_2 -> eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIyMWU5MDJhNi1kZWMxLTRkNjYtYjkzMy1jMmYwNGFmZmNkM2EiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMGIzOGU2MjYtMDhkZC00YzdhLTliN2ItMGQxMTUzYWM3NjdkLTc1MDU4ODYyIiwic3VibmFtZSI6IjIxZTkwMmE2LWRlYzEtNGQ2Ni1iOTMzLWMyZjA0YWZmY2QzYSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6IkZ5bkxJUFgySEpEOEVfMFlkam1mdFNqWEZOWSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTU1ODQ5NCwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTU1ODQ5MywicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1NjIwOTQsImlhdCI6MTczMTU1ODQ5NCwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiUFJZVTgzVzB4bGg4LXVLSkU1Q1JLbGs5M2xzIn0.fWrf1MvumwkEctVfllAvUhPBXOn2yH2pfLmFhepO2ZM, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@478dba2d, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, authcode -> DBATk0rrjKkOmd_86DaoPsPHB2w, callbacks -> {"tokenId":"9X-3PZE02YJNrb4SVglszGvseu8.*AAJTSQACMDIAAlNLABxuNmRoTVZ3K3BSdUFZTDg5czU3ZG9sZVlDcTQ9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1731558493691), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=9X-3PZE02YJNrb4SVglszGvseu8.*AAJTSQACMDIAAlNLABxuNmRoTVZ3K3BSdUFZTDg5czU3ZG9sZVlDcTQ9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731558493691))), user_uuid -> 21e902a6-dec1-4d66-b933-c2f04affcd3a, password -> Pa_ssw0rd, challenge -> O0k0XdYtB_hO94ej03MPbNtPBvfZKF03zKvwuW6tJSc, gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, fake-ip -> 19.124.78.145, verifier -> ODMyNTgyMDYxMzg3MzAxNTc4Nw, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@7bba3f94, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@48e32a6c, tokenId -> 9X-3PZE02YJNrb4SVglszGvseu8.*AAJTSQACMDIAAlNLABxuNmRoTVZ3K3BSdUFZTDg5czU3ZG9sZVlDcTQ9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007b45c469a0e0@4e40fd4d,io.netty.channel.epoll.EpollEventLoop@5b7ea70d) 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO HTTP request: 2024-11-14 04:28:40,668 INFO POST https://openam-perf-benchmark.forgeblocks.com/openidm/authentication?_action=login 2024-11-14 04:28:40,668 INFO headers: 2024-11-14 04:28:40,668 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-14 04:28:40,668 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-14 04:28:40,668 INFO Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIyMWU5MDJhNi1kZWMxLTRkNjYtYjkzMy1jMmYwNGFmZmNkM2EiLCJjdHMiOiJPQVVUSDJfU1RBVEVMRVNTX0dSQU5UIiwiYXV0aF9sZXZlbCI6MCwiYXVkaXRUcmFja2luZ0lkIjoiMGIzOGU2MjYtMDhkZC00YzdhLTliN2ItMGQxMTUzYWM3NjdkLTc1MDU4ODYyIiwic3VibmFtZSI6IjIxZTkwMmE2LWRlYzEtNGQ2Ni1iOTMzLWMyZjA0YWZmY2QzYSIsImlzcyI6Imh0dHBzOi8vb3BlbmFtLXBlcmYtYmVuY2htYXJrLmZvcmdlYmxvY2tzLmNvbTo0NDMvYW0vb2F1dGgyL3JlYWxtcy9yb290L3JlYWxtcy9hbHBoYSIsInRva2VuTmFtZSI6ImFjY2Vzc190b2tlbiIsInRva2VuX3R5cGUiOiJCZWFyZXIiLCJhdXRoR3JhbnRJZCI6IkZ5bkxJUFgySEpEOEVfMFlkam1mdFNqWEZOWSIsIm5vbmNlIjoiMTIzNCIsImNsaWVudF9pZCI6ImVuZFVzZXJVSUNsaWVudCIsImF1ZCI6ImVuZFVzZXJVSUNsaWVudCIsIm5iZiI6MTczMTU1ODQ5NCwiZ3JhbnRfdHlwZSI6ImF1dGhvcml6YXRpb25fY29kZSIsInNjb3BlIjpbImZyOmlkbToqIl0sImF1dGhfdGltZSI6MTczMTU1ODQ5MywicmVhbG0iOiIvYWxwaGEiLCJleHAiOjE3MzE1NjIwOTQsImlhdCI6MTczMTU1ODQ5NCwiZXhwaXJlc19pbiI6MzYwMCwianRpIjoiUFJZVTgzVzB4bGg4LXVLSkU1Q1JLbGs5M2xzIn0.fWrf1MvumwkEctVfllAvUhPBXOn2yH2pfLmFhepO2ZM 2024-11-14 04:28:40,668 INFO Accept-Api-Version: 2024-11-14 04:28:40,668 INFO accept: */* 2024-11-14 04:28:40,668 INFO cookie: amlbcookie=01; 9b75a55744995d0=9X-3PZE02YJNrb4SVglszGvseu8.*AAJTSQACMDIAAlNLABxuNmRoTVZ3K3BSdUFZTDg5czU3ZG9sZVlDcTQ9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-14 04:28:40,668 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,668 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,668 INFO content-length: 0 2024-11-14 04:28:40,668 INFO cookies: 2024-11-14 04:28:40,668 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 04:28:40,668 INFO 9b75a55744995d0=9X-3PZE02YJNrb4SVglszGvseu8.*AAJTSQACMDIAAlNLABxuNmRoTVZ3K3BSdUFZTDg5czU3ZG9sZVlDcTQ9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO HTTP response: 2024-11-14 04:28:40,668 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 04:28:40,668 INFO 04:28:14.302 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 04:28:40,668 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 04:28:40,668 INFO Request: 2024-11-14 04:28:40,668 INFO UI AM validateGoto: KO j.n.c.ClosedChannelException 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO Session: 2024-11-14 04:28:40,668 INFO Session(idc.benchmark.Mix2024,179274,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.24712, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@2906dded, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"u3IBV8DuUuVedlN45UkBO0zAsaw.*AAJTSQACMDIAAlNLABwrSDdqRW10R2NMY3ZHSUNnUVl3UVBKWU9NNnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1731558494219), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=u3IBV8DuUuVedlN45UkBO0zAsaw.*AAJTSQACMDIAAlNLABwrSDdqRW10R2NMY3ZHSUNnUVl3UVBKWU9NNnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731558494219))), password -> Pa_ssw0rd, fake-ip -> 99.93.111.47, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@6b2cbf37, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@74ae99d4, tokenId -> u3IBV8DuUuVedlN45UkBO0zAsaw.*AAJTSQACMDIAAlNLABwrSDdqRW10R2NMY3ZHSUNnUVl3UVBKWU9NNnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007b45c469a0e0@4e40fd4d,io.netty.channel.epoll.EpollEventLoop@2bef51f2) 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO HTTP request: 2024-11-14 04:28:40,668 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-14 04:28:40,668 INFO headers: 2024-11-14 04:28:40,668 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-14 04:28:40,668 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-14 04:28:40,668 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-14 04:28:40,668 INFO accept: */* 2024-11-14 04:28:40,668 INFO cookie: amlbcookie=01; 9b75a55744995d0=u3IBV8DuUuVedlN45UkBO0zAsaw.*AAJTSQACMDIAAlNLABwrSDdqRW10R2NMY3ZHSUNnUVl3UVBKWU9NNnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-14 04:28:40,668 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,668 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,668 INFO cookies: 2024-11-14 04:28:40,668 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 04:28:40,668 INFO 9b75a55744995d0=u3IBV8DuUuVedlN45UkBO0zAsaw.*AAJTSQACMDIAAlNLABwrSDdqRW10R2NMY3ZHSUNnUVl3UVBKWU9NNnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO HTTP response: 2024-11-14 04:28:40,668 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 04:28:40,668 INFO 04:28:14.302 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 04:28:40,668 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 04:28:40,668 INFO Request: 2024-11-14 04:28:40,668 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO Session: 2024-11-14 04:28:40,668 INFO Session(idc.benchmark.Mix2024,179275,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.149026, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@350c8be8, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"FOeK7FOsTiZBiHhXIw7uoVbcK4c.*AAJTSQACMDIAAlNLABxVMURyZUdQNDF0TnNyTEN1dHlKT1J3cEZKMnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1731558494208), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=FOeK7FOsTiZBiHhXIw7uoVbcK4c.*AAJTSQACMDIAAlNLABxVMURyZUdQNDF0TnNyTEN1dHlKT1J3cEZKMnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1731558494208))), password -> Pa_ssw0rd, fake-ip -> 238.145.8.231, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@118be84a, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@5fd22bdb, tokenId -> FOeK7FOsTiZBiHhXIw7uoVbcK4c.*AAJTSQACMDIAAlNLABxVMURyZUdQNDF0TnNyTEN1dHlKT1J3cEZKMnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007b45c469a0e0@4e40fd4d,io.netty.channel.epoll.EpollEventLoop@650eab8) 2024-11-14 04:28:40,668 INFO ========================= 2024-11-14 04:28:40,668 INFO HTTP request: 2024-11-14 04:28:40,668 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-14 04:28:40,668 INFO headers: 2024-11-14 04:28:40,668 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-14 04:28:40,668 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-14 04:28:40,668 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-14 04:28:40,668 INFO accept: */* 2024-11-14 04:28:40,668 INFO cookie: amlbcookie=01; 9b75a55744995d0=FOeK7FOsTiZBiHhXIw7uoVbcK4c.*AAJTSQACMDIAAlNLABxVMURyZUdQNDF0TnNyTEN1dHlKT1J3cEZKMnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-14 04:28:40,669 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,669 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,669 INFO content-length: 0 2024-11-14 04:28:40,669 INFO cookies: 2024-11-14 04:28:40,669 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 04:28:40,669 INFO 9b75a55744995d0=FOeK7FOsTiZBiHhXIw7uoVbcK4c.*AAJTSQACMDIAAlNLABxVMURyZUdQNDF0TnNyTEN1dHlKT1J3cEZKMnM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-14 04:28:40,669 INFO ========================= 2024-11-14 04:28:40,669 INFO HTTP response: 2024-11-14 04:28:40,669 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 04:28:40,669 INFO 04:28:14.302 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 179291: j.i.IOException: Premature close 2024-11-14 04:28:40,669 INFO 04:28:14.302 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-14 04:28:40,669 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-14 04:28:40,669 INFO Request: 2024-11-14 04:28:40,669 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-14 04:28:40,669 INFO ========================= 2024-11-14 04:28:40,669 INFO Session: 2024-11-14 04:28:40,669 INFO Session(idc.benchmark.Mix2024,179291,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.83986, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@146211ca, 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, password -> Pa_ssw0rd, fake-ip -> 152.103.48.189, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@5ae572b4),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007b45c469a0e0@4e40fd4d,io.netty.channel.epoll.EpollEventLoop@650eab8) 2024-11-14 04:28:40,669 INFO ========================= 2024-11-14 04:28:40,669 INFO HTTP request: 2024-11-14 04:28:40,669 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-14 04:28:40,669 INFO headers: 2024-11-14 04:28:40,669 INFO accept: application/json 2024-11-14 04:28:40,669 INFO content-type: application/json 2024-11-14 04:28:40,669 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-14 04:28:40,669 INFO X-Forwarded-For: 152.103.48.189 2024-11-14 04:28:40,669 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-14 04:28:40,669 INFO content-length: 0 2024-11-14 04:28:40,669 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-14 04:28:40,669 INFO ========================= 2024-11-14 04:28:40,669 INFO HTTP response: 2024-11-14 04:28:40,669 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-14 04:28:40,669 INFO 04:28:14.302 [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-14 04:28:40,669 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 04:28:40,669 INFO [INFO] BUILD SUCCESS 2024-11-14 04:28:40,669 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 04:28:40,669 INFO [INFO] Total time: 01:00 h 2024-11-14 04:28:40,669 INFO [INFO] Finished at: 2024-11-14T04:28:14Z 2024-11-14 04:28:40,669 INFO [INFO] ------------------------------------------------------------------------ 2024-11-14 04:28:40,669 INFO 2024-11-14 04:28:14,394 INFO Gatling simulation run ended successfully 2024-11-14 04:28:40,669 INFO 2024-11-14 04:28:14,395 DEBUG No archive name provided. No archive will be created 2024-11-14 04:28:40,669 INFO ________________________________________________________________________________ [2024-11-14 04:28:40] benchmark-50 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-14 04:28:40,669 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/03_benchmark-50/stderr.txt is small (0 lines), printing all lines: 2024-11-14 04:28:40,669 DEBUG ----- output ----- 2024-11-14 04:28:40,669 DEBUG 2024-11-14 04:28:40,669 INFO ________________________________________________________________________________ [2024-11-14 04:28:40] benchmark-50 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-14 04:28:40] benchmark-50 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-14 04:28:40] benchmark-50 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped