--Task-- name: benchmark-40 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-10'] preceding_task: benchmark-10 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 40} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-06 21:11:48] benchmark-40 pre : N/A ________________________________________________________________________________ 2024-11-06 21:11:48 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-06 21:11:48 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-40/stdout.txt Pod log : /results/orders/benchmark-40 2024-11-06 21:11:48,494 INFO 2024-11-06 21:11:48,494 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-06 21:11:48,494 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 21:11:48,770 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 21:11:48,770 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:48,770 DEBUG --- stdout --- 2024-11-06 21:11:48,770 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 21:11:48,770 DEBUG --- stderr --- 2024-11-06 21:11:48,770 DEBUG ________________________________________________________________________________ [2024-11-06 21:11:48] benchmark-40 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-06 21:11:48,771 INFO 2024-11-06 21:11:48,771 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-06 21:11:48,771 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 21:11:49,047 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 21:11:49,047 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:49,047 DEBUG --- stdout --- 2024-11-06 21:11:49,047 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 21:11:49,047 DEBUG --- stderr --- 2024-11-06 21:11:49,047 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-40" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=40 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-06 21:11:49] benchmark-40 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-06 21:11:49,048 INFO 2024-11-06 21:11:49,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-06 21:11:49,048 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 21:11:49,324 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 21:11:49,324 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:49,324 DEBUG --- stdout --- 2024-11-06 21:11:49,324 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 21:11:49,324 DEBUG --- stderr --- 2024-11-06 21:11:49,324 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/order.json { "name": "benchmark-40", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-40\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=40 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-40" } ________________________________________________________________________________ [2024-11-06 21:11:49] benchmark-40 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-06 21:11:49,327 INFO 2024-11-06 21:11:49,328 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-06 21:11:49,328 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-06 21:11:49,545 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-06 21:11:49,546 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:49,546 DEBUG --- stdout --- 2024-11-06 21:11:49,546 DEBUG WAITING 2024-11-06 21:11:49,546 DEBUG --- stderr --- 2024-11-06 21:11:49,546 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-06 21:11:49] benchmark-40 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-06 21:11:49,546 INFO 2024-11-06 21:11:49,546 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-06 21:11:49,546 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 21:11:49,825 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 21:11:49,825 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:49,825 DEBUG --- stdout --- 2024-11-06 21:11:49,825 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 21:11:49,825 DEBUG --- stderr --- 2024-11-06 21:11:49,825 DEBUG 2024-11-06 21:11:49,826 INFO 2024-11-06 21:11:49,826 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/02_benchmark-40/order.json overseer-0-6644bb6697-9gfkx:/results/orders/order.json 2024-11-06 21:11:49,826 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-06 21:11:51,193 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:51,193 DEBUG --- stdout --- 2024-11-06 21:11:51,193 DEBUG 2024-11-06 21:11:51,193 DEBUG --- stderr --- 2024-11-06 21:11:51,193 DEBUG Order has been successfully forwarded to overseer 2024-11-06 21:11:51 - INFO: Check if Gatling simulation started successfully 2024-11-06 21:11:51,193 INFO 2024-11-06 21:11:51,193 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-06 21:11:51,193 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 21:11:51,469 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 21:11:51,469 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:11:51,469 DEBUG --- stdout --- 2024-11-06 21:11:51,469 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 21:11:51,469 DEBUG --- stderr --- 2024-11-06 21:11:51,469 DEBUG 2024-11-06 21:11:51,470 INFO 2024-11-06 21:11:51,470 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx -- head --lines 5000 /results/orders/benchmark-40/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-06 21:11:51,470 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-06 21:11:52,202 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-06 21:11:57,942 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-06 21:12:03,694 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-06 21:12:03,694 INFO [loop_until]: OK (rc = 0) 2024-11-06 21:12:03,694 DEBUG --- stdout --- 2024-11-06 21:12:03,694 DEBUG 2024-11-06 21:11:51,712 DEBUG Creating results folder /results/gatling/benchmark-40 2024-11-06 21:11:51,719 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp4izr2d8d 2024-11-06 21:11:51,721 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-40" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=40 -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/tmp4izr2d8d/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/tmp4izr2d8d/target/test-classes ... [INFO] compile in 6.8 s [INFO] [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< [INFO] [INFO] [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- [INFO] Running simulation com.forgerock.pyrock.Loadtest. System property think_time_multiplier not set. No think time emulation will be done in the simulation. Simulation com.forgerock.pyrock.Loadtest started... 2024-11-06 21:12:03,694 DEBUG --- stderr --- 2024-11-06 21:12:03,694 DEBUG ________________________________________________________________________________ [2024-11-06 21:12:03] benchmark-40 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 03s, retry Order is running since 22m 03s, retry Order is running since 24m 03s, retry Order is running since 26m 04s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 06s, retry Order is running since 40m 06s, retry Order is running since 42m 06s, retry Order is running since 44m 07s, retry Order is running since 46m 07s, retry Order is running since 48m 07s, retry Order is running since 50m 08s, retry Order is running since 52m 08s, retry Order is running since 54m 08s, retry Order is running since 56m 09s, retry Order is running since 58m 09s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-06 22:12:13] benchmark-40 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-06 22:12:13,695 INFO 2024-11-06 22:12:13,695 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-06 22:12:13,695 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:13,999 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:13,999 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:13,999 DEBUG --- stdout --- 2024-11-06 22:12:13,999 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:13,999 DEBUG --- stderr --- 2024-11-06 22:12:13,999 DEBUG 2024-11-06 22:12:13,999 INFO 2024-11-06 22:12:13,999 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx -- rm -f /results/orders/order.json 2024-11-06 22:12:13,999 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-06 22:12:14,780 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:14,781 DEBUG --- stdout --- 2024-11-06 22:12:14,781 DEBUG 2024-11-06 22:12:14,781 DEBUG --- stderr --- 2024-11-06 22:12:14,781 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-06 22:12:14] benchmark-40 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-06 22:12:14 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/order.json 2024-11-06 22:12:14,781 INFO 2024-11-06 22:12:14,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-06 22:12:14,781 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:15,055 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:15,056 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:15,056 DEBUG --- stdout --- 2024-11-06 22:12:15,056 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:15,056 DEBUG --- stderr --- 2024-11-06 22:12:15,056 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-06 22:12:15,056 INFO 2024-11-06 22:12:15,056 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-06 22:12:15,056 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:15,332 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:15,332 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:15,332 DEBUG --- stdout --- 2024-11-06 22:12:15,333 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:15,333 DEBUG --- stderr --- 2024-11-06 22:12:15,333 DEBUG 2024-11-06 22:12:15,333 INFO 2024-11-06 22:12:15,333 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-40/rc.txt" ]; then echo "/results/orders/benchmark-40/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-40/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-40/rc.txt file found" 2024-11-06 22:12:15,333 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-06 22:12:16,127 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-06 22:12:16,127 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:16,127 DEBUG --- stdout --- 2024-11-06 22:12:16,127 DEBUG /results/orders/benchmark-40/rc.txt file found 2024-11-06 22:12:16,127 DEBUG --- stderr --- 2024-11-06 22:12:16,127 DEBUG 2024-11-06 22:12:16,127 INFO 2024-11-06 22:12:16,127 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-06 22:12:16,127 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:16,404 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:16,404 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:16,404 DEBUG --- stdout --- 2024-11-06 22:12:16,404 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:16,404 DEBUG --- stderr --- 2024-11-06 22:12:16,404 DEBUG 2024-11-06 22:12:16,404 INFO 2024-11-06 22:12:16,404 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-40/rc.txt 2024-11-06 22:12:17,272 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-06 22:12:17,272 DEBUG --- stdout --- 2024-11-06 22:12:17,273 DEBUG 4 /results/orders/benchmark-40/rc.txt 2024-11-06 22:12:17,273 DEBUG --- stderr --- 2024-11-06 22:12:17,273 DEBUG 2024-11-06 22:12:17,273 INFO - Download file (size 4k) 2024-11-06 22:12:17,273 INFO 2024-11-06 22:12:17,273 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-06 22:12:17,273 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:17,551 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:17,551 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:17,551 DEBUG --- stdout --- 2024-11-06 22:12:17,551 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:17,551 DEBUG --- stderr --- 2024-11-06 22:12:17,551 DEBUG source : /results/orders/benchmark-40/rc.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/rc.txt 2024-11-06 22:12:17,551 INFO 2024-11-06 22:12:17,551 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-06 22:12:17,551 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:17,826 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:17,827 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:17,827 DEBUG --- stdout --- 2024-11-06 22:12:17,827 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:17,827 DEBUG --- stderr --- 2024-11-06 22:12:17,827 DEBUG 2024-11-06 22:12:17,827 INFO 2024-11-06 22:12:17,827 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-40/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/rc.txt 2024-11-06 22:12:17,827 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-06 22:12:18,551 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:18,551 DEBUG --- stdout --- 2024-11-06 22:12:18,551 DEBUG tar: Removing leading `/' from member names 2024-11-06 22:12:18,551 DEBUG --- stderr --- 2024-11-06 22:12:18,551 DEBUG 2024-11-06 22:12:18,551 INFO 2024-11-06 22:12:18,551 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-06 22:12:18,552 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:18,829 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:18,829 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:18,829 DEBUG --- stdout --- 2024-11-06 22:12:18,829 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:18,829 DEBUG --- stderr --- 2024-11-06 22:12:18,829 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-06 22:12:18,829 INFO 2024-11-06 22:12:18,830 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-06 22:12:18,830 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:19,104 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:19,104 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:19,104 DEBUG --- stdout --- 2024-11-06 22:12:19,104 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:19,104 DEBUG --- stderr --- 2024-11-06 22:12:19,104 DEBUG 2024-11-06 22:12:19,105 INFO 2024-11-06 22:12:19,105 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-40/stderr.txt" ]; then echo "/results/orders/benchmark-40/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-40/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-40/stderr.txt file found" 2024-11-06 22:12:19,105 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-06 22:12:19,907 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-06 22:12:19,908 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:19,908 DEBUG --- stdout --- 2024-11-06 22:12:19,908 DEBUG /results/orders/benchmark-40/stderr.txt file found 2024-11-06 22:12:19,908 DEBUG --- stderr --- 2024-11-06 22:12:19,908 DEBUG 2024-11-06 22:12:19,908 INFO 2024-11-06 22:12:19,908 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-06 22:12:19,908 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:20,184 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:20,185 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:20,185 DEBUG --- stdout --- 2024-11-06 22:12:20,185 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:20,185 DEBUG --- stderr --- 2024-11-06 22:12:20,185 DEBUG 2024-11-06 22:12:20,185 INFO 2024-11-06 22:12:20,185 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-40/stderr.txt 2024-11-06 22:12:20,978 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-06 22:12:20,979 DEBUG --- stdout --- 2024-11-06 22:12:20,979 DEBUG 0 /results/orders/benchmark-40/stderr.txt 2024-11-06 22:12:20,979 DEBUG --- stderr --- 2024-11-06 22:12:20,979 DEBUG 2024-11-06 22:12:20,979 INFO - Download file (size 0k) 2024-11-06 22:12:20,979 INFO 2024-11-06 22:12:20,979 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-06 22:12:20,979 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:21,256 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:21,256 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:21,256 DEBUG --- stdout --- 2024-11-06 22:12:21,256 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:21,256 DEBUG --- stderr --- 2024-11-06 22:12:21,256 DEBUG source : /results/orders/benchmark-40/stderr.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/stderr.txt 2024-11-06 22:12:21,256 INFO 2024-11-06 22:12:21,257 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-06 22:12:21,257 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:21,533 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:21,534 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:21,534 DEBUG --- stdout --- 2024-11-06 22:12:21,534 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:21,534 DEBUG --- stderr --- 2024-11-06 22:12:21,534 DEBUG 2024-11-06 22:12:21,535 INFO 2024-11-06 22:12:21,535 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-40/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/stderr.txt 2024-11-06 22:12:21,535 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-06 22:12:22,321 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:22,321 DEBUG --- stdout --- 2024-11-06 22:12:22,321 DEBUG tar: Removing leading `/' from member names 2024-11-06 22:12:22,321 DEBUG --- stderr --- 2024-11-06 22:12:22,321 DEBUG 2024-11-06 22:12:22,322 INFO 2024-11-06 22:12:22,322 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-06 22:12:22,322 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:22,598 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:22,599 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:22,599 DEBUG --- stdout --- 2024-11-06 22:12:22,599 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:22,599 DEBUG --- stderr --- 2024-11-06 22:12:22,599 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-06 22:12:22,599 INFO 2024-11-06 22:12:22,599 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-06 22:12:22,599 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:22,874 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:22,874 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:22,874 DEBUG --- stdout --- 2024-11-06 22:12:22,874 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:22,874 DEBUG --- stderr --- 2024-11-06 22:12:22,874 DEBUG 2024-11-06 22:12:22,875 INFO 2024-11-06 22:12:22,875 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-40/stdout.txt" ]; then echo "/results/orders/benchmark-40/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-40/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-40/stdout.txt file found" 2024-11-06 22:12:22,875 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-06 22:12:23,669 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-06 22:12:23,669 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:23,669 DEBUG --- stdout --- 2024-11-06 22:12:23,669 DEBUG /results/orders/benchmark-40/stdout.txt file found 2024-11-06 22:12:23,669 DEBUG --- stderr --- 2024-11-06 22:12:23,669 DEBUG 2024-11-06 22:12:23,669 INFO 2024-11-06 22:12:23,669 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-06 22:12:23,669 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:23,947 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:23,947 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:23,947 DEBUG --- stdout --- 2024-11-06 22:12:23,947 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:23,947 DEBUG --- stderr --- 2024-11-06 22:12:23,947 DEBUG 2024-11-06 22:12:23,947 INFO 2024-11-06 22:12:23,947 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-40/stdout.txt 2024-11-06 22:12:24,738 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-06 22:12:24,738 DEBUG --- stdout --- 2024-11-06 22:12:24,738 DEBUG 3572 /results/orders/benchmark-40/stdout.txt 2024-11-06 22:12:24,738 DEBUG --- stderr --- 2024-11-06 22:12:24,738 DEBUG 2024-11-06 22:12:24,738 INFO - Download file (size 3572k) 2024-11-06 22:12:24,739 INFO 2024-11-06 22:12:24,739 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-06 22:12:24,739 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:25,014 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:25,014 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:25,014 DEBUG --- stdout --- 2024-11-06 22:12:25,014 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:25,014 DEBUG --- stderr --- 2024-11-06 22:12:25,014 DEBUG source : /results/orders/benchmark-40/stdout.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/stdout.txt 2024-11-06 22:12:25,014 INFO 2024-11-06 22:12:25,015 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-06 22:12:25,015 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:25,294 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:25,294 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:25,294 DEBUG --- stdout --- 2024-11-06 22:12:25,294 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:25,294 DEBUG --- stderr --- 2024-11-06 22:12:25,294 DEBUG 2024-11-06 22:12:25,294 INFO 2024-11-06 22:12:25,294 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-40/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/stdout.txt 2024-11-06 22:12:25,294 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-06 22:12:26,517 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:26,517 DEBUG --- stdout --- 2024-11-06 22:12:26,517 DEBUG tar: Removing leading `/' from member names 2024-11-06 22:12:26,518 DEBUG --- stderr --- 2024-11-06 22:12:26,518 DEBUG ________________________________________________________________________________ [2024-11-06 22:12:26] benchmark-40 show_cmd : Display order command ________________________________________________________________________________ 2024-11-06 22:12:26,518 INFO 2024-11-06 22:12: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-06 22:12:26,518 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:26,796 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:26,796 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:26,796 DEBUG --- stdout --- 2024-11-06 22:12:26,796 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:26,796 DEBUG --- stderr --- 2024-11-06 22:12:26,796 DEBUG Checking pod: overseer-0-6644bb6697-9gfkx for file exists, if not wait. 2024-11-06 22:12:26,797 INFO 2024-11-06 22:12:26,797 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-06 22:12:26,797 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:27,071 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:27,071 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:27,071 DEBUG --- stdout --- 2024-11-06 22:12:27,071 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:27,071 DEBUG --- stderr --- 2024-11-06 22:12:27,071 DEBUG 2024-11-06 22:12:27,072 INFO 2024-11-06 22:12:27,072 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- bash -c 'if [ -f "/results/orders/benchmark-40/cmd.txt" ]; then echo "/results/orders/benchmark-40/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-40/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-40/cmd.txt file found" 2024-11-06 22:12:27,072 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-06 22:12:27,869 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-06 22:12:27,869 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:27,869 DEBUG --- stdout --- 2024-11-06 22:12:27,869 DEBUG /results/orders/benchmark-40/cmd.txt file found 2024-11-06 22:12:27,869 DEBUG --- stderr --- 2024-11-06 22:12:27,869 DEBUG 2024-11-06 22:12:27,870 INFO 2024-11-06 22:12:27,870 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-06 22:12:27,870 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:28,148 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:28,148 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:28,148 DEBUG --- stdout --- 2024-11-06 22:12:28,148 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:28,148 DEBUG --- stderr --- 2024-11-06 22:12:28,148 DEBUG 2024-11-06 22:12:28,148 INFO 2024-11-06 22:12:28,149 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-9gfkx --stdin -- du -k /results/orders/benchmark-40/cmd.txt 2024-11-06 22:12:28,969 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-06 22:12:28,969 DEBUG --- stdout --- 2024-11-06 22:12:28,969 DEBUG 4 /results/orders/benchmark-40/cmd.txt 2024-11-06 22:12:28,969 DEBUG --- stderr --- 2024-11-06 22:12:28,969 DEBUG 2024-11-06 22:12:28,969 INFO - Download file (size 4k) 2024-11-06 22:12:28,970 INFO 2024-11-06 22:12:28,970 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-06 22:12:28,970 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:29,247 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:29,247 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:29,247 DEBUG --- stdout --- 2024-11-06 22:12:29,247 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:29,247 DEBUG --- stderr --- 2024-11-06 22:12:29,247 DEBUG source : /results/orders/benchmark-40/cmd.txt @ overseer-0-6644bb6697-9gfkx destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/cmd.txt 2024-11-06 22:12:29,247 INFO 2024-11-06 22:12:29,247 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-06 22:12:29,247 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-06 22:12:29,522 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-06 22:12:29,522 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:29,522 DEBUG --- stdout --- 2024-11-06 22:12:29,522 DEBUG overseer-0-6644bb6697-9gfkx 2024-11-06 22:12:29,522 DEBUG --- stderr --- 2024-11-06 22:12:29,522 DEBUG 2024-11-06 22:12:29,523 INFO 2024-11-06 22:12:29,523 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-9gfkx:/results/orders/benchmark-40/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/cmd.txt 2024-11-06 22:12:29,523 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-06 22:12:30,279 INFO [loop_until]: OK (rc = 0) 2024-11-06 22:12:30,279 DEBUG --- stdout --- 2024-11-06 22:12:30,279 DEBUG tar: Removing leading `/' from member names 2024-11-06 22:12:30,279 DEBUG --- stderr --- 2024-11-06 22:12:30,279 DEBUG 2024-11-06 22:12:30,279 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/cmd.txt is small (1 lines), printing all lines: 2024-11-06 22:12:30,279 DEBUG ----- output ----- 2024-11-06 22:12:30,280 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-40" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=40 -Duser_password=Pa_ssw0rd" 2024-11-06 22:12:30,280 INFO ________________________________________________________________________________ [2024-11-06 22:12:30] benchmark-40 show_rc : Display rc order ________________________________________________________________________________ 2024-11-06 22:12:30,280 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/rc.txt is small (1 lines), printing all lines: 2024-11-06 22:12:30,280 DEBUG ----- output ----- 2024-11-06 22:12:30,280 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-06 22:12:30,280 INFO ________________________________________________________________________________ [2024-11-06 22:12:30] benchmark-40 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-06 22:12:30,285 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/02_benchmark-40/stdout.txt is 47031 lines): 2024-11-06 22:12:30,285 DEBUG ----- output ----- 2024-11-06 22:12:30,285 INFO 2024-11-06 21:11:51,712 DEBUG Creating results folder /results/gatling/benchmark-40 2024-11-06 22:12:30,285 INFO 2024-11-06 21:11:51,719 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmp4izr2d8d 2024-11-06 22:12:30,285 INFO 2024-11-06 21:11:51,721 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-40" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=40 -Duser_password=**** 2024-11-06 22:12:30,286 INFO [INFO] Scanning for projects... 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-06 22:12:30,286 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-06 22:12:30,286 INFO [INFO] from pom.xml 2024-11-06 22:12:30,286 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-06 22:12:30,286 INFO [INFO] skip non existing resourceDirectory /tmp/tmp4izr2d8d/src/main/resources 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-06 22:12:30,286 INFO [INFO] No sources to compile 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-06 22:12:30,286 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-06 22:12:30,286 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-06 22:12:30,286 INFO [INFO] compiling 38 Scala sources to /tmp/tmp4izr2d8d/target/test-classes ... 2024-11-06 22:12:30,286 INFO [INFO] compile in 6.8 s 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] 2024-11-06 22:12:30,286 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-06 22:12:30,286 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-06 22:12:30,286 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-06 22:12:30,286 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-06 22:12:30,286 INFO 2024-11-06 22:12:30,286 INFO ================================================================================ 2024-11-06 22:12:30,286 INFO 2024-11-06 21:12:07 GMT 5s elapsed 2024-11-06 22:12:30,286 INFO ---- Requests ------------------------------------------------------------------ 2024-11-06 22:12:30,286 INFO > Global (OK=139 KO=0 ) 2024-11-06 22:12:30,286 INFO > restLoginInitiate (OK=16 KO=0 ) 2024-11-06 22:12:30,286 INFO > restLoginUsernamePasswordCallback (OK=15 KO=0 ) 2024-11-06 22:12:30,286 INFO > Skip 2FA (OK=13 KO=0 ) 2024-11-06 22:12:30,286 INFO > User Authorize PKCE stage (OK=16 KO=0 ) 2024-11-06 22:12:30,286 INFO > User AccessToken PKCE stage (OK=15 KO=0 ) 2024-11-06 22:12:30,286 INFO > GetUUid (OK=6 KO=0 ) 2024-11-06 22:12:30,286 INFO > GetOpenidConfig (OK=6 KO=0 ) 2024-11-06 22:12:30,286 INFO > CreatePolicy (OK=6 KO=0 ) 2024-11-06 22:12:30,286 INFO > RootUserinfo (OK=8 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI-Post-Login - stage 1 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI AM validateGoto (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI AM idFromSession (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI-Post-Login - stage 2 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI Enduser appAuthHelper2 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI Enduser appAuthHelper1 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI-Post-Login - stage 3 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI Enduser sessioncheck (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI IDM uiconfig (OK=1 KO=0 ) 2024-11-06 22:12:30,286 INFO > UI IDM version (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM features (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM privilege (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM login (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM dashboard (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM managed user schema (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM user (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI IDM oidcToken (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > userinfo (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI-Logout (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI-Logout Redirect 1 (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI AM revoke2 (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI AM revoke1 (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > UI AM endsession (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > getIdToken (OK=3 KO=0 ) 2024-11-06 22:12:30,287 INFO > getIdToken Redirect 1 (OK=2 KO=0 ) 2024-11-06 22:12:30,287 INFO > createOrganization (OK=2 KO=0 ) 2024-11-06 22:12:30,287 INFO > tokenUserinfo (OK=1 KO=0 ) 2024-11-06 22:12:30,287 INFO > queryOrganization (OK=2 KO=0 ) 2024-11-06 22:12:30,287 INFO > deleteOrganization (OK=2 KO=0 ) 2024-11-06 22:12:30,287 INFO 2024-11-06 22:12:30,287 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-06 22:12:30,287 INFO [- ] 0% 2024-11-06 22:12:30,287 INFO waiting: 144340 / active: 12 / done: 4 2024-11-06 22:12:30,287 INFO ================================================================================ 2024-11-06 22:12:30,287 INFO 2024-11-06 22:12:30,287 INFO 2024-11-06 22:12:30,287 INFO ================================================================================ 2024-11-06 22:12:30,287 INFO 2024-11-06 21:12:12 GMT 10s elapsed 2024-11-06 22:12:30,287 INFO ---- Requests ------------------------------------------------------------------ 2024-11-06 22:12:30,287 INFO > Global (OK=691 KO=0 ) 2024-11-06 22:12:30,287 INFO > restLoginInitiate (OK=64 KO=0 ) 2024-11-06 22:12:30,287 INFO > restLoginUsernamePasswordCallback (OK=62 KO=0 ) 2024-11-06 22:12:30,287 INFO > Skip 2FA (OK=38 KO=0 ) 2024-11-06 22:12:30,287 INFO > User Authorize PKCE stage (OK=70 KO=0 ) 2024-11-06 22:12:30,287 INFO > User AccessToken PKCE stage (OK=69 KO=0 ) 2024-11-06 22:12:30,287 INFO > GetUUid (OK=22 KO=0 ) 2024-11-06 22:12:30,287 INFO > GetOpenidConfig (OK=28 KO=0 ) 2024-11-06 22:12:30,287 INFO > CreatePolicy (OK=22 KO=0 ) 2024-11-06 22:12:30,287 INFO [...] 2024-11-06 22:12:30,296 INFO Session: 2024-11-06 22:12:30,296 INFO Session(idc.benchmark.Mix2024,143205,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.401856, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1d99295e, fake-user-agent -> Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9, password -> Pa_ssw0rd, fake-ip -> 125.217.131.54, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@46a95eb8),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x000079c20469a0e0@1df24930,io.netty.channel.epoll.EpollEventLoop@619bfe29) 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO HTTP request: 2024-11-06 22:12:30,297 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/authenticate 2024-11-06 22:12:30,297 INFO headers: 2024-11-06 22:12:30,297 INFO accept: application/json 2024-11-06 22:12:30,297 INFO content-type: application/json 2024-11-06 22:12:30,297 INFO user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9 2024-11-06 22:12:30,297 INFO X-Forwarded-For: 125.217.131.54 2024-11-06 22:12:30,297 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,297 INFO content-length: 0 2024-11-06 22:12:30,297 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO HTTP response: 2024-11-06 22:12:30,297 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-06 22:12:30,297 INFO 22:12:02.616 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-06 22:12:30,297 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-06 22:12:30,297 INFO Request: 2024-11-06 22:12:30,297 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO Session: 2024-11-06 22:12:30,297 INFO Session(idc.benchmark.Mix2024,143198,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.198656, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@7ac2d2ef, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"l7B6A-McQWhD2B-iXw67BEfHdTU.*AAJTSQACMDIAAlNLABx1YXhUWm1pVzNkc3VkcHFSS0YxbzlMVFhvN2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1730931122484), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=l7B6A-McQWhD2B-iXw67BEfHdTU.*AAJTSQACMDIAAlNLABx1YXhUWm1pVzNkc3VkcHFSS0YxbzlMVFhvN2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1730931122484))), password -> Pa_ssw0rd, fake-ip -> 195.169.135.14, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@1d2496f6, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@254ac6ee, tokenId -> l7B6A-McQWhD2B-iXw67BEfHdTU.*AAJTSQACMDIAAlNLABx1YXhUWm1pVzNkc3VkcHFSS0YxbzlMVFhvN2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Linux; Android 8.0.0; Pixel 2 Build/OPD3.170816.012) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x000079c20469a0e0@1df24930,io.netty.channel.epoll.EpollEventLoop@4f2c9ba6) 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO HTTP request: 2024-11-06 22:12:30,297 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-06 22:12:30,297 INFO headers: 2024-11-06 22:12:30,297 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-06 22:12:30,297 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-06 22:12:30,297 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-06 22:12:30,297 INFO accept: */* 2024-11-06 22:12:30,297 INFO cookie: amlbcookie=01; 9b75a55744995d0=l7B6A-McQWhD2B-iXw67BEfHdTU.*AAJTSQACMDIAAlNLABx1YXhUWm1pVzNkc3VkcHFSS0YxbzlMVFhvN2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-06 22:12:30,297 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,297 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,297 INFO content-length: 0 2024-11-06 22:12:30,297 INFO cookies: 2024-11-06 22:12:30,297 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-06 22:12:30,297 INFO 9b75a55744995d0=l7B6A-McQWhD2B-iXw67BEfHdTU.*AAJTSQACMDIAAlNLABx1YXhUWm1pVzNkc3VkcHFSS0YxbzlMVFhvN2s9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO HTTP response: 2024-11-06 22:12:30,297 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-06 22:12:30,297 INFO 22:12:02.616 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-06 22:12:30,297 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-06 22:12:30,297 INFO Request: 2024-11-06 22:12:30,297 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO Session: 2024-11-06 22:12:30,297 INFO Session(idc.benchmark.Mix2024,143199,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.921782, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@4589b767, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"0dpseNMWkIh3P9P-AR8iswRz4i0.*AAJTSQACMDIAAlNLABxHNlNiQkpFc01JV0JDYnpEejNoMHBVZHZIalU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1730931122529), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=0dpseNMWkIh3P9P-AR8iswRz4i0.*AAJTSQACMDIAAlNLABxHNlNiQkpFc01JV0JDYnpEejNoMHBVZHZIalU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1730931122529))), password -> Pa_ssw0rd, fake-ip -> 232.131.44.51, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@4b02ab51, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@2201ae0c, tokenId -> 0dpseNMWkIh3P9P-AR8iswRz4i0.*AAJTSQACMDIAAlNLABxHNlNiQkpFc01JV0JDYnpEejNoMHBVZHZIalU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, 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/0x000079c20469a0e0@1df24930,io.netty.channel.epoll.EpollEventLoop@4e28bdd1) 2024-11-06 22:12:30,297 INFO ========================= 2024-11-06 22:12:30,297 INFO HTTP request: 2024-11-06 22:12:30,297 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-06 22:12:30,297 INFO headers: 2024-11-06 22:12:30,297 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-06 22:12:30,297 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-06 22:12:30,297 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-06 22:12:30,297 INFO accept: */* 2024-11-06 22:12:30,297 INFO cookie: amlbcookie=01; 9b75a55744995d0=0dpseNMWkIh3P9P-AR8iswRz4i0.*AAJTSQACMDIAAlNLABxHNlNiQkpFc01JV0JDYnpEejNoMHBVZHZIalU9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-06 22:12:30,297 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,297 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,298 INFO content-length: 0 2024-11-06 22:12:30,298 INFO cookies: 2024-11-06 22:12:30,298 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-06 22:12:30,298 INFO 9b75a55744995d0=0dpseNMWkIh3P9P-AR8iswRz4i0.*AAJTSQACMDIAAlNLABxHNlNiQkpFc01JV0JDYnpEejNoMHBVZHZIalU9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-06 22:12:30,298 INFO ========================= 2024-11-06 22:12:30,298 INFO HTTP response: 2024-11-06 22:12:30,298 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-06 22:12:30,298 INFO 22:12:02.616 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-06 22:12:30,298 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-06 22:12:30,298 INFO Request: 2024-11-06 22:12:30,298 INFO UI AM validateGoto: KO j.i.IOException: Premature close 2024-11-06 22:12:30,298 INFO ========================= 2024-11-06 22:12:30,298 INFO Session: 2024-11-06 22:12:30,298 INFO Session(idc.benchmark.Mix2024,143197,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.912174, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@7f13c783, gatling.http.referer -> https://openam-perf-benchmark.forgeblocks.com/am/, callbacks -> {"tokenId":"DlYIBgAFVcVJQZ-cdnGbDIwYYLU.*AAJTSQACMDIAAlNLABx0T3c2cy9Ed2FNTGdQZ0RrSmdLdEhzQXBSNHM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*","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,1730931122501), CookieKey(9b75a55744995d0,openam-perf-benchmark.forgeblocks.com,/) -> StoredCookie(9b75a55744995d0=DlYIBgAFVcVJQZ-cdnGbDIwYYLU.*AAJTSQACMDIAAlNLABx0T3c2cy9Ed2FNTGdQZ0RrSmdLdEhzQXBSNHM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None,false,false,1730931122501))), password -> Pa_ssw0rd, fake-ip -> 212.199.114.9, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@1cfab357, gatling.http.cache.contentCache -> io.gatling.core.util.cache.Cache@755dc2a2, tokenId -> DlYIBgAFVcVJQZ-cdnGbDIwYYLU.*AAJTSQACMDIAAlNLABx0T3c2cy9Ed2FNTGdQZ0RrSmdLdEhzQXBSNHM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x000079c20469a0e0@1df24930,io.netty.channel.epoll.EpollEventLoop@1e1d3956) 2024-11-06 22:12:30,298 INFO ========================= 2024-11-06 22:12:30,298 INFO HTTP request: 2024-11-06 22:12:30,298 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/realms/alpha/users?_action=validateGoto 2024-11-06 22:12:30,298 INFO headers: 2024-11-06 22:12:30,298 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-06 22:12:30,298 INFO Accept-API-Version: resource=2.1, protocol=1.0 2024-11-06 22:12:30,298 INFO referer: https://openam-perf-benchmark.forgeblocks.com/am/ 2024-11-06 22:12:30,298 INFO accept: */* 2024-11-06 22:12:30,298 INFO cookie: amlbcookie=01; 9b75a55744995d0=DlYIBgAFVcVJQZ-cdnGbDIwYYLU.*AAJTSQACMDIAAlNLABx0T3c2cy9Ed2FNTGdQZ0RrSmdLdEhzQXBSNHM9AAR0eXBlAANDVFMAAlMxAAIwMQ..* 2024-11-06 22:12:30,298 INFO origin: https://openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,298 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-06 22:12:30,298 INFO content-length: 0 2024-11-06 22:12:30,298 INFO cookies: 2024-11-06 22:12:30,298 INFO amlbcookie=01, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-06 22:12:30,298 INFO 9b75a55744995d0=DlYIBgAFVcVJQZ-cdnGbDIwYYLU.*AAJTSQACMDIAAlNLABx0T3c2cy9Ed2FNTGdQZ0RrSmdLdEhzQXBSNHM9AAR0eXBlAANDVFMAAlMxAAIwMQ..*, domain=openam-perf-benchmark.forgeblocks.com, path=/, secure, HTTPOnly, SameSite=None 2024-11-06 22:12:30,298 INFO ========================= 2024-11-06 22:12:30,298 INFO HTTP response: 2024-11-06 22:12:30,298 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-06 22:12:30,298 INFO 22:12:02.616 [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-06 22:12:30,298 INFO [INFO] ------------------------------------------------------------------------ 2024-11-06 22:12:30,298 INFO [INFO] BUILD SUCCESS 2024-11-06 22:12:30,298 INFO [INFO] ------------------------------------------------------------------------ 2024-11-06 22:12:30,298 INFO [INFO] Total time: 01:00 h 2024-11-06 22:12:30,298 INFO [INFO] Finished at: 2024-11-06T22:12:02Z 2024-11-06 22:12:30,298 INFO [INFO] ------------------------------------------------------------------------ 2024-11-06 22:12:30,298 INFO 2024-11-06 22:12:02,706 INFO Gatling simulation run ended successfully 2024-11-06 22:12:30,298 INFO 2024-11-06 22:12:02,706 DEBUG No archive name provided. No archive will be created 2024-11-06 22:12:30,298 INFO ________________________________________________________________________________ [2024-11-06 22:12:30] benchmark-40 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-06 22:12:30,298 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/02_benchmark-40/stderr.txt is small (0 lines), printing all lines: 2024-11-06 22:12:30,298 DEBUG ----- output ----- 2024-11-06 22:12:30,298 DEBUG 2024-11-06 22:12:30,298 INFO ________________________________________________________________________________ [2024-11-06 22:12:30] benchmark-40 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-06 22:12:30] benchmark-40 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-06 22:12:30] benchmark-40 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped