--Task-- name: benchmark-30 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 bellow 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=self30-', 'testCase': 'idc.benchmark.CH2023', 'testMode': 'open', 'throughput': 30} group_name: None Current dir: /mnt/disks/data/xslou/lodestar-fork/pyrock ________________________________________________________________________________ [2024-07-18 06:41:50] benchmark-30 pre : N/A ________________________________________________________________________________ 2024-07-18 06:41:50 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-07-18 06:41:50 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-30/stdout.txt Pod log : /results/orders/benchmark-30 2024-07-18 06:41:50,893 INFO 2024-07-18 06:41:50,893 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-07-18 06:41:50,893 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:51,196 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:51,196 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:51,196 DEBUG --- stdout --- 2024-07-18 06:41:51,196 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:51,196 DEBUG --- stderr --- 2024-07-18 06:41:51,196 DEBUG ________________________________________________________________________________ [2024-07-18 06:41:51] benchmark-30 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-07-18 06:41:51,197 INFO 2024-07-18 06:41:51,197 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-07-18 06:41:51,197 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:51,498 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:51,498 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:51,498 DEBUG --- stdout --- 2024-07-18 06:41:51,498 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:51,498 DEBUG --- stderr --- 2024-07-18 06:41:51,498 DEBUG /lodestar/clients/gatling-for-pyrock.sh --run-mode local --simulation com.forgerock.gatling.Loadtest --simulations-folder /lodestar/pyrock/shared/clients/gatling-open/ --run-description "idc.benchmark.CH2023@ema-perf-benchmark" --results-folder /results/gatling/benchmark-30 --extra-run-jvm-options "-Xmx4G" --no-reports ________________________________________________________________________________ [2024-07-18 06:41:51] benchmark-30 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-07-18 06:41:51,499 INFO 2024-07-18 06:41:51,499 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-07-18 06:41:51,499 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:51,799 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:51,799 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:51,799 DEBUG --- stdout --- 2024-07-18 06:41:51,799 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:51,799 DEBUG --- stderr --- 2024-07-18 06:41:51,799 DEBUG Order file: /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/order.json { "name": "benchmark-30", "command": " /lodestar/clients/gatling-for-pyrock.sh --run-mode local --simulation com.forgerock.gatling.Loadtest --simulations-folder /lodestar/pyrock/shared/clients/gatling-open/ --run-description \"idc.benchmark.CH2023@ema-perf-benchmark\" --results-folder /results/gatling/benchmark-30 --extra-run-jvm-options \"-Xmx4G\" --no-reports", "out-dir": "/results/orders/benchmark-30", "environment": { "JAVA_OPTS": "-Dam_host=openam-ema-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@forgerock.com -Dduration=3600 -Didc=true -Dlogin_cookie=0e26551c0104b88 -Dnum_users=1000000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self30- -Drealm=alpha -DtestCase=idc.benchmark.CH2023 -DtestMode=open -Dthroughput=30 -Duser_password=Pa_ssw0rd" } } ________________________________________________________________________________ [2024-07-18 06:41:51] benchmark-30 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-07-18 06:41:51,801 INFO 2024-07-18 06:41:51,801 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-07-18 06:41:51,801 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 06:41:52,040 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 06:41:52,040 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:52,041 DEBUG --- stdout --- 2024-07-18 06:41:52,041 DEBUG WAITING 2024-07-18 06:41:52,041 DEBUG --- stderr --- 2024-07-18 06:41:52,041 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 32 0 --:--:-- --:--:-- --:--:-- 32 ________________________________________________________________________________ [2024-07-18 06:41:52] benchmark-30 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-07-18 06:41:52,041 INFO 2024-07-18 06:41:52,041 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-07-18 06:41:52,041 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:52,338 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:52,338 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:52,338 DEBUG --- stdout --- 2024-07-18 06:41:52,338 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:52,338 DEBUG --- stderr --- 2024-07-18 06:41:52,339 DEBUG 2024-07-18 06:41:52,339 INFO 2024-07-18 06:41:52,339 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/order.json overseer-0-7796fc5d9b-ngsxg:/results/orders/order.json 2024-07-18 06:41:52,339 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 06:41:53,704 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:53,705 DEBUG --- stdout --- 2024-07-18 06:41:53,705 DEBUG 2024-07-18 06:41:53,705 DEBUG --- stderr --- 2024-07-18 06:41:53,705 DEBUG Order has been successfully forwarded to overseer 2024-07-18 06:41:53 - INFO: Check if Gatling simulation started successfully 2024-07-18 06:41:53,705 INFO 2024-07-18 06:41:53,705 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-07-18 06:41:53,705 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:54,005 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:54,005 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:54,005 DEBUG --- stdout --- 2024-07-18 06:41:54,005 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:54,005 DEBUG --- stderr --- 2024-07-18 06:41:54,005 DEBUG 2024-07-18 06:41:54,006 INFO 2024-07-18 06:41:54,006 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg -- head -n 25 /results/orders/benchmark-30/stdout.txt | grep "started..." 2024-07-18 06:41:54,006 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 06:41:54,742 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: started... - retry 2024-07-18 06:42:00,498 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: started... - retry 2024-07-18 06:42:06,254 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-07-18 06:42:06,254 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:42:06,255 DEBUG --- stdout --- 2024-07-18 06:42:06,255 DEBUG GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling 07:41:56.133 [WARN ] i.g.c.ZincCompiler$ - -target is deprecated: Use -release instead to compile against the correct platform API. 07:42:00.113 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:122:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map crossSessionVariables.-("poliEvalTokenId"); ^ 07:42:00.116 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:225:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map crossSessionVariables.-("poliEvalTokenId"); ^ 07:42:01.693 [WARN ] i.g.c.ZincCompiler$ - three warnings found Gatling 3.11.5 is available! (you're using 3.9.5) Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 06:42:06,256 DEBUG --- stderr --- 2024-07-18 06:42:06,256 DEBUG ________________________________________________________________________________ [2024-07-18 06:42:06] benchmark-30 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 01s, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 02s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 03s, retry Order is running since 20m 03s, retry Order is running since 22m 03s, retry Order is running since 24m 04s, retry Order is running since 26m 04s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 06s, retry Order is running since 40m 06s, retry Order is running since 42m 06s, retry Order is running since 44m 07s, retry Order is running since 46m 07s, retry Order is running since 48m 07s, retry Order is running since 50m 07s, retry Order is running since 52m 08s, retry Order is running since 54m 08s, retry Order is running since 56m 08s, retry Order is running since 58m 09s, retry Order is running since 1h, retry PASS : Order stopped by itself after 1h 02m and before timeout (1h 12m) ________________________________________________________________________________ [2024-07-18 07:44:16] benchmark-30 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-07-18 07:44:16,214 INFO 2024-07-18 07:44:16,214 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-07-18 07:44:16,214 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:16,536 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:16,536 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:16,536 DEBUG --- stdout --- 2024-07-18 07:44:16,537 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:16,537 DEBUG --- stderr --- 2024-07-18 07:44:16,537 DEBUG 2024-07-18 07:44:16,537 INFO 2024-07-18 07:44:16,537 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg -- rm -f /results/orders/order.json 2024-07-18 07:44:16,537 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 07:44:17,322 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:17,322 DEBUG --- stdout --- 2024-07-18 07:44:17,322 DEBUG 2024-07-18 07:44:17,322 DEBUG --- stderr --- 2024-07-18 07:44:17,322 DEBUG Order ran during 1h 02m ________________________________________________________________________________ [2024-07-18 07:44:17] benchmark-30 download_logs : Download individual order files ________________________________________________________________________________ 2024-07-18 07:44:17 - PASS: file already downloaded /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/order.json 2024-07-18 07:44:17,324 INFO 2024-07-18 07:44:17,324 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-07-18 07:44:17,324 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:17,633 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:17,633 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:17,633 DEBUG --- stdout --- 2024-07-18 07:44:17,633 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:17,633 DEBUG --- stderr --- 2024-07-18 07:44:17,633 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 07:44:17,634 INFO 2024-07-18 07:44:17,634 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-07-18 07:44:17,634 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:17,953 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:17,953 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:17,953 DEBUG --- stdout --- 2024-07-18 07:44:17,953 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:17,953 DEBUG --- stderr --- 2024-07-18 07:44:17,953 DEBUG 2024-07-18 07:44:17,954 INFO 2024-07-18 07:44:17,954 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/rc.txt" ]; then echo "/results/orders/benchmark-30/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-30/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/rc.txt file found" 2024-07-18 07:44:17,954 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 07:44:18,777 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 07:44:18,777 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:18,777 DEBUG --- stdout --- 2024-07-18 07:44:18,777 DEBUG /results/orders/benchmark-30/rc.txt file found 2024-07-18 07:44:18,777 DEBUG --- stderr --- 2024-07-18 07:44:18,777 DEBUG 2024-07-18 07:44:18,778 INFO 2024-07-18 07:44:18,778 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-07-18 07:44:18,778 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:19,080 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:19,080 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:19,080 DEBUG --- stdout --- 2024-07-18 07:44:19,080 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:19,080 DEBUG --- stderr --- 2024-07-18 07:44:19,080 DEBUG 2024-07-18 07:44:19,081 INFO 2024-07-18 07:44:19,081 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- du -k /results/orders/benchmark-30/rc.txt 2024-07-18 07:44:19,878 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 07:44:19,878 DEBUG --- stdout --- 2024-07-18 07:44:19,878 DEBUG 4 /results/orders/benchmark-30/rc.txt 2024-07-18 07:44:19,878 DEBUG --- stderr --- 2024-07-18 07:44:19,878 DEBUG 2024-07-18 07:44:19,878 INFO - Download file (size 4k) 2024-07-18 07:44:19,879 INFO 2024-07-18 07:44:19,879 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-07-18 07:44:19,879 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:20,178 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:20,179 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:20,179 DEBUG --- stdout --- 2024-07-18 07:44:20,179 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:20,179 DEBUG --- stderr --- 2024-07-18 07:44:20,179 DEBUG source : /results/orders/benchmark-30/rc.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/rc.txt 2024-07-18 07:44:20,179 INFO 2024-07-18 07:44:20,179 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-07-18 07:44:20,180 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:20,513 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:20,513 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:20,513 DEBUG --- stdout --- 2024-07-18 07:44:20,513 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:20,513 DEBUG --- stderr --- 2024-07-18 07:44:20,513 DEBUG 2024-07-18 07:44:20,514 INFO 2024-07-18 07:44:20,514 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-30/rc.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/rc.txt 2024-07-18 07:44:20,514 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 07:44:21,288 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:21,289 DEBUG --- stdout --- 2024-07-18 07:44:21,289 DEBUG tar: Removing leading `/' from member names 2024-07-18 07:44:21,289 DEBUG --- stderr --- 2024-07-18 07:44:21,289 DEBUG 2024-07-18 07:44:21,289 INFO 2024-07-18 07:44:21,289 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-07-18 07:44:21,289 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:21,593 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:21,593 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:21,594 DEBUG --- stdout --- 2024-07-18 07:44:21,594 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:21,594 DEBUG --- stderr --- 2024-07-18 07:44:21,594 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 07:44:21,594 INFO 2024-07-18 07:44:21,594 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 07:44:21,594 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:21,916 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:21,916 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:21,916 DEBUG --- stdout --- 2024-07-18 07:44:21,916 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:21,916 DEBUG --- stderr --- 2024-07-18 07:44:21,916 DEBUG 2024-07-18 07:44:21,917 INFO 2024-07-18 07:44:21,917 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/stderr.txt" ]; then echo "/results/orders/benchmark-30/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-30/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/stderr.txt file found" 2024-07-18 07:44:21,917 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 07:44:22,741 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 07:44:22,741 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:22,741 DEBUG --- stdout --- 2024-07-18 07:44:22,741 DEBUG /results/orders/benchmark-30/stderr.txt file found 2024-07-18 07:44:22,742 DEBUG --- stderr --- 2024-07-18 07:44:22,742 DEBUG 2024-07-18 07:44:22,742 INFO 2024-07-18 07:44:22,742 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-07-18 07:44:22,742 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:23,079 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:23,079 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:23,079 DEBUG --- stdout --- 2024-07-18 07:44:23,079 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:23,079 DEBUG --- stderr --- 2024-07-18 07:44:23,079 DEBUG 2024-07-18 07:44:23,079 INFO 2024-07-18 07:44:23,080 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- du -k /results/orders/benchmark-30/stderr.txt 2024-07-18 07:44:23,901 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 07:44:23,901 DEBUG --- stdout --- 2024-07-18 07:44:23,901 DEBUG 0 /results/orders/benchmark-30/stderr.txt 2024-07-18 07:44:23,901 DEBUG --- stderr --- 2024-07-18 07:44:23,901 DEBUG 2024-07-18 07:44:23,901 INFO - Download file (size 0k) 2024-07-18 07:44:23,902 INFO 2024-07-18 07:44:23,902 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-07-18 07:44:23,902 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:24,216 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:24,216 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:24,216 DEBUG --- stdout --- 2024-07-18 07:44:24,216 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:24,216 DEBUG --- stderr --- 2024-07-18 07:44:24,216 DEBUG source : /results/orders/benchmark-30/stderr.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/stderr.txt 2024-07-18 07:44:24,216 INFO 2024-07-18 07:44:24,216 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-07-18 07:44:24,217 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:24,530 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:24,530 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:24,530 DEBUG --- stdout --- 2024-07-18 07:44:24,530 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:24,530 DEBUG --- stderr --- 2024-07-18 07:44:24,530 DEBUG 2024-07-18 07:44:24,531 INFO 2024-07-18 07:44:24,531 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-30/stderr.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/stderr.txt 2024-07-18 07:44:24,531 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 07:44:25,271 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:25,272 DEBUG --- stdout --- 2024-07-18 07:44:25,272 DEBUG tar: Removing leading `/' from member names 2024-07-18 07:44:25,272 DEBUG --- stderr --- 2024-07-18 07:44:25,272 DEBUG 2024-07-18 07:44:25,272 INFO 2024-07-18 07:44:25,272 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-07-18 07:44:25,272 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:25,596 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:25,596 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:25,596 DEBUG --- stdout --- 2024-07-18 07:44:25,596 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:25,596 DEBUG --- stderr --- 2024-07-18 07:44:25,596 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 07:44:25,597 INFO 2024-07-18 07:44:25,597 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-07-18 07:44:25,597 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:25,966 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:25,966 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:25,966 DEBUG --- stdout --- 2024-07-18 07:44:25,967 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:25,967 DEBUG --- stderr --- 2024-07-18 07:44:25,967 DEBUG 2024-07-18 07:44:25,967 INFO 2024-07-18 07:44:25,968 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/stdout.txt" ]; then echo "/results/orders/benchmark-30/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-30/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/stdout.txt file found" 2024-07-18 07:44:25,968 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 07:44:27,019 INFO [loop_until]: Function succeeded after 1s (rc=0) - expected pattern found 2024-07-18 07:44:27,019 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:27,019 DEBUG --- stdout --- 2024-07-18 07:44:27,019 DEBUG /results/orders/benchmark-30/stdout.txt file found 2024-07-18 07:44:27,019 DEBUG --- stderr --- 2024-07-18 07:44:27,019 DEBUG 2024-07-18 07:44:27,020 INFO 2024-07-18 07:44:27,020 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-07-18 07:44:27,020 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:27,341 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:27,342 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:27,342 DEBUG --- stdout --- 2024-07-18 07:44:27,342 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:27,342 DEBUG --- stderr --- 2024-07-18 07:44:27,342 DEBUG 2024-07-18 07:44:27,342 INFO 2024-07-18 07:44:27,342 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- du -k /results/orders/benchmark-30/stdout.txt 2024-07-18 07:44:28,168 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 07:44:28,168 DEBUG --- stdout --- 2024-07-18 07:44:28,169 DEBUG 2952 /results/orders/benchmark-30/stdout.txt 2024-07-18 07:44:28,169 DEBUG --- stderr --- 2024-07-18 07:44:28,169 DEBUG 2024-07-18 07:44:28,169 INFO - Download file (size 2952k) 2024-07-18 07:44:28,169 INFO 2024-07-18 07:44:28,169 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-07-18 07:44:28,169 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:28,471 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:28,471 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:28,471 DEBUG --- stdout --- 2024-07-18 07:44:28,472 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:28,472 DEBUG --- stderr --- 2024-07-18 07:44:28,472 DEBUG source : /results/orders/benchmark-30/stdout.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/stdout.txt 2024-07-18 07:44:28,472 INFO 2024-07-18 07:44:28,472 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 07:44:28,472 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:28,775 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:28,775 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:28,775 DEBUG --- stdout --- 2024-07-18 07:44:28,776 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:28,776 DEBUG --- stderr --- 2024-07-18 07:44:28,776 DEBUG 2024-07-18 07:44:28,776 INFO 2024-07-18 07:44:28,776 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-30/stdout.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/stdout.txt 2024-07-18 07:44:28,776 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 07:44:29,983 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:29,983 DEBUG --- stdout --- 2024-07-18 07:44:29,984 DEBUG tar: Removing leading `/' from member names 2024-07-18 07:44:29,984 DEBUG --- stderr --- 2024-07-18 07:44:29,984 DEBUG ________________________________________________________________________________ [2024-07-18 07:44:29] benchmark-30 show_cmd : Display order command ________________________________________________________________________________ 2024-07-18 07:44:29,984 INFO 2024-07-18 07:44:29,984 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-07-18 07:44:29,984 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:30,302 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:30,302 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:30,302 DEBUG --- stdout --- 2024-07-18 07:44:30,302 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:30,302 DEBUG --- stderr --- 2024-07-18 07:44:30,303 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 07:44:30,303 INFO 2024-07-18 07:44:30,303 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-07-18 07:44:30,303 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:30,617 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:30,617 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:30,617 DEBUG --- stdout --- 2024-07-18 07:44:30,617 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:30,617 DEBUG --- stderr --- 2024-07-18 07:44:30,617 DEBUG 2024-07-18 07:44:30,618 INFO 2024-07-18 07:44:30,618 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- bash -c 'if [ -f "/results/orders/benchmark-30/cmd.txt" ]; then echo "/results/orders/benchmark-30/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-30/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-30/cmd.txt file found" 2024-07-18 07:44:30,618 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 07:44:31,430 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 07:44:31,430 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:31,430 DEBUG --- stdout --- 2024-07-18 07:44:31,430 DEBUG /results/orders/benchmark-30/cmd.txt file found 2024-07-18 07:44:31,430 DEBUG --- stderr --- 2024-07-18 07:44:31,430 DEBUG 2024-07-18 07:44:31,431 INFO 2024-07-18 07:44:31,431 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-07-18 07:44:31,431 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:31,733 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:31,733 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:31,733 DEBUG --- stdout --- 2024-07-18 07:44:31,733 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:31,733 DEBUG --- stderr --- 2024-07-18 07:44:31,733 DEBUG 2024-07-18 07:44:31,733 INFO 2024-07-18 07:44:31,734 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-7796fc5d9b-ngsxg --stdin -- du -k /results/orders/benchmark-30/cmd.txt 2024-07-18 07:44:32,533 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 07:44:32,534 DEBUG --- stdout --- 2024-07-18 07:44:32,534 DEBUG 4 /results/orders/benchmark-30/cmd.txt 2024-07-18 07:44:32,534 DEBUG --- stderr --- 2024-07-18 07:44:32,534 DEBUG 2024-07-18 07:44:32,534 INFO - Download file (size 4k) 2024-07-18 07:44:32,534 INFO 2024-07-18 07:44:32,534 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-07-18 07:44:32,535 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:32,842 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:32,843 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:32,843 DEBUG --- stdout --- 2024-07-18 07:44:32,843 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:32,843 DEBUG --- stderr --- 2024-07-18 07:44:32,843 DEBUG source : /results/orders/benchmark-30/cmd.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/cmd.txt 2024-07-18 07:44:32,844 INFO 2024-07-18 07:44:32,844 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-07-18 07:44:32,844 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:33,222 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:33,222 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:33,222 DEBUG --- stdout --- 2024-07-18 07:44:33,222 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:33,222 DEBUG --- stderr --- 2024-07-18 07:44:33,222 DEBUG 2024-07-18 07:44:33,222 INFO 2024-07-18 07:44:33,223 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-30/cmd.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/cmd.txt 2024-07-18 07:44:33,223 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 07:44:34,020 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:34,021 DEBUG --- stdout --- 2024-07-18 07:44:34,021 DEBUG tar: Removing leading `/' from member names 2024-07-18 07:44:34,021 DEBUG --- stderr --- 2024-07-18 07:44:34,021 DEBUG 2024-07-18 07:44:34,021 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/cmd.txt is small (1 lines), printing all lines: 2024-07-18 07:44:34,021 DEBUG ----- output ----- 2024-07-18 07:44:34,021 DEBUG /lodestar/clients/gatling-for-pyrock.sh --run-mode local --simulation com.forgerock.gatling.Loadtest --simulations-folder /lodestar/pyrock/shared/clients/gatling-open/ --run-description "idc.benchmark.CH2023@ema-perf-benchmark" --results-folder /results/gatling/benchmark-30 --extra-run-jvm-options "-Xmx4G" --no-reports 2024-07-18 07:44:34,021 INFO ________________________________________________________________________________ [2024-07-18 07:44:34] benchmark-30 show_rc : Display rc order ________________________________________________________________________________ 2024-07-18 07:44:34,022 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/rc.txt is small (1 lines), printing all lines: 2024-07-18 07:44:34,022 DEBUG ----- output ----- 2024-07-18 07:44:34,022 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-07-18 07:44:34,022 INFO ________________________________________________________________________________ [2024-07-18 07:44:34] benchmark-30 show_stdout : Display stdout order ________________________________________________________________________________ 2024-07-18 07:44:34,029 DEBUG [print_head_tail]: Print head (100 lines) and tail (100 lines) of input file (/mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/stdout.txt is 40423 lines): 2024-07-18 07:44:34,029 DEBUG ----- output ----- 2024-07-18 07:44:34,029 INFO GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling 2024-07-18 07:44:34,029 INFO 07:41:56.133 [WARN ] i.g.c.ZincCompiler$ - -target is deprecated: Use -release instead to compile against the correct platform API. 2024-07-18 07:44:34,029 INFO 07:42:00.113 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:122:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map 2024-07-18 07:44:34,029 INFO crossSessionVariables.-("poliEvalTokenId"); 2024-07-18 07:44:34,029 INFO ^ 2024-07-18 07:44:34,029 INFO 07:42:00.116 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:225:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map 2024-07-18 07:44:34,029 INFO crossSessionVariables.-("poliEvalTokenId"); 2024-07-18 07:44:34,029 INFO ^ 2024-07-18 07:44:34,029 INFO 07:42:01.693 [WARN ] i.g.c.ZincCompiler$ - three warnings found 2024-07-18 07:44:34,029 INFO Gatling 3.11.5 is available! (you're using 3.9.5) 2024-07-18 07:44:34,029 INFO Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 07:44:34,029 INFO 2024-07-18 07:44:34,029 INFO ================================================================================ 2024-07-18 07:44:34,029 INFO 2024-07-18 07:42:09 5s elapsed 2024-07-18 07:44:34,029 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 07:44:34,029 INFO > Global (OK=102 KO=0 ) 2024-07-18 07:44:34,029 INFO > restLoginInitiate (OK=10 KO=0 ) 2024-07-18 07:44:34,029 INFO > restLoginUsernamePasswordCallback (OK=10 KO=0 ) 2024-07-18 07:44:34,029 INFO > User Authorize PKCE stage (OK=11 KO=0 ) 2024-07-18 07:44:34,029 INFO > User AccessToken PKCE stage (OK=11 KO=0 ) 2024-07-18 07:44:34,029 INFO > tokenUserinfo (OK=2 KO=0 ) 2024-07-18 07:44:34,029 INFO > registration_restLoginInitiate (OK=2 KO=0 ) 2024-07-18 07:44:34,030 INFO > registrationCallback (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > Skip 2FA (OK=7 KO=0 ) 2024-07-18 07:44:34,030 INFO > getIdToken (OK=3 KO=0 ) 2024-07-18 07:44:34,030 INFO > getIdToken Redirect 1 (OK=3 KO=0 ) 2024-07-18 07:44:34,030 INFO > createOrganization (OK=3 KO=0 ) 2024-07-18 07:44:34,030 INFO > queryOrganization (OK=3 KO=0 ) 2024-07-18 07:44:34,030 INFO > deleteOrganization (OK=3 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI-Post-Login (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI-Post-Login Redirect 1 (OK=3 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI AM idFromSession (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI AM validateGoto (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI Enduser appAuthHelper1 (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI Enduser appAuthHelper2 (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM uiconfig (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI Enduser sessioncheck (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM version (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM features (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM login (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM privilege (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM dashboard (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM user (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM alpha_user (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI IDM oidcToken (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > userinfo (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > RootUserinfo (OK=10 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI-Logout Redirect 1 (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI AM revoke1 (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI AM revoke2 (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO > UI AM endsession (OK=1 KO=0 ) 2024-07-18 07:44:34,030 INFO 2024-07-18 07:44:34,030 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 07:44:34,030 INFO [- ] 0% 2024-07-18 07:44:34,030 INFO waiting: 108399 / active: 6 / done: 7 2024-07-18 07:44:34,030 INFO ================================================================================ 2024-07-18 07:44:34,030 INFO 2024-07-18 07:44:34,030 INFO 2024-07-18 07:44:34,030 INFO ================================================================================ 2024-07-18 07:44:34,031 INFO 2024-07-18 07:42:14 10s elapsed 2024-07-18 07:44:34,031 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 07:44:34,031 INFO > Global (OK=392 KO=0 ) 2024-07-18 07:44:34,031 INFO > restLoginInitiate (OK=44 KO=0 ) 2024-07-18 07:44:34,031 INFO > restLoginUsernamePasswordCallback (OK=44 KO=0 ) 2024-07-18 07:44:34,031 INFO > User Authorize PKCE stage (OK=46 KO=0 ) 2024-07-18 07:44:34,031 INFO > User AccessToken PKCE stage (OK=46 KO=0 ) 2024-07-18 07:44:34,031 INFO > tokenUserinfo (OK=9 KO=0 ) 2024-07-18 07:44:34,031 INFO > registration_restLoginInitiate (OK=6 KO=0 ) 2024-07-18 07:44:34,031 INFO > registrationCallback (OK=4 KO=0 ) 2024-07-18 07:44:34,031 INFO > Skip 2FA (OK=31 KO=0 ) 2024-07-18 07:44:34,031 INFO > getIdToken (OK=10 KO=0 ) 2024-07-18 07:44:34,031 INFO > getIdToken Redirect 1 (OK=10 KO=0 ) 2024-07-18 07:44:34,031 INFO > createOrganization (OK=10 KO=0 ) 2024-07-18 07:44:34,031 INFO > queryOrganization (OK=10 KO=0 ) 2024-07-18 07:44:34,031 INFO > deleteOrganization (OK=10 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI-Post-Login (OK=3 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI-Post-Login Redirect 1 (OK=7 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI AM idFromSession (OK=3 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI AM validateGoto (OK=3 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI Enduser appAuthHelper1 (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI Enduser appAuthHelper2 (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM uiconfig (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI Enduser sessioncheck (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM version (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM features (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM login (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM privilege (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM dashboard (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM user (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM alpha_user (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI IDM oidcToken (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > userinfo (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > RootUserinfo (OK=62 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI-Logout Redirect 1 (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI AM revoke1 (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI AM revoke2 (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO > UI AM endsession (OK=2 KO=0 ) 2024-07-18 07:44:34,031 INFO 2024-07-18 07:44:34,031 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 07:44:34,031 INFO [- ] 0% 2024-07-18 07:44:34,032 INFO [...] 2024-07-18 07:44:34,042 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 07:44:34,042 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 20 (46.51%) 2024-07-18 07:44:34,042 INFO ess_token' is defined 2024-07-18 07:44:34,042 INFO > tokenUserinfo: Failed to build request: No attribute named 'ac 8 (18.60%) 2024-07-18 07:44:34,042 INFO cess_token' is defined 2024-07-18 07:44:34,042 INFO > status.find.is(200), but actually found 502 6 (13.95%) 2024-07-18 07:44:34,042 INFO > status.find.in([200, 209], 304), found 502 3 ( 6.98%) 2024-07-18 07:44:34,042 INFO > status.find.is(302), but actually found 502 3 ( 6.98%) 2024-07-18 07:44:34,043 INFO > createOrganization: Failed to build request: No attribute name 1 ( 2.33%) 2024-07-18 07:44:34,043 INFO d 'access_token' is defined 2024-07-18 07:44:34,043 INFO > queryOrganization: Failed to build request: No attribute named 1 ( 2.33%) 2024-07-18 07:44:34,043 INFO 'organization_id' is defined 2024-07-18 07:44:34,043 INFO > deleteOrganization: Failed to build request: No attribute name 1 ( 2.33%) 2024-07-18 07:44:34,043 INFO d 'organization_id' is defined 2024-07-18 07:44:34,043 INFO 2024-07-18 07:44:34,043 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 07:44:34,043 INFO [#########################################################################-] 99% 2024-07-18 07:44:34,043 INFO waiting: 0 / active: 13 / done: 108399 2024-07-18 07:44:34,043 INFO ================================================================================ 2024-07-18 07:44:34,043 INFO 2024-07-18 07:44:34,043 INFO 2024-07-18 07:44:34,043 INFO ================================================================================ 2024-07-18 07:44:34,043 INFO 2024-07-18 08:42:43 3639s elapsed 2024-07-18 07:44:34,043 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 07:44:34,043 INFO > Global (OK=920712 KO=12 ) 2024-07-18 07:44:34,043 INFO > restLoginInitiate (OK=91134 KO=2 ) 2024-07-18 07:44:34,043 INFO > restLoginUsernamePasswordCallback (OK=91132 KO=2 ) 2024-07-18 07:44:34,043 INFO > User Authorize PKCE stage (OK=95548 KO=3 ) 2024-07-18 07:44:34,043 INFO > User AccessToken PKCE stage (OK=95547 KO=1 ) 2024-07-18 07:44:34,043 INFO > tokenUserinfo (OK=21839 KO=0 ) 2024-07-18 07:44:34,043 INFO > registration_restLoginInitiate (OK=17276 KO=0 ) 2024-07-18 07:44:34,043 INFO > registrationCallback (OK=17275 KO=1 ) 2024-07-18 07:44:34,043 INFO > Skip 2FA (OK=64855 KO=2 ) 2024-07-18 07:44:34,043 INFO > getIdToken (OK=12817 KO=0 ) 2024-07-18 07:44:34,043 INFO > getIdToken Redirect 1 (OK=12817 KO=0 ) 2024-07-18 07:44:34,043 INFO > createOrganization (OK=12816 KO=0 ) 2024-07-18 07:44:34,043 INFO > queryOrganization (OK=12816 KO=0 ) 2024-07-18 07:44:34,043 INFO > deleteOrganization (OK=12816 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI-Post-Login (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI-Post-Login Redirect 1 (OK=13284 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI AM idFromSession (OK=4427 KO=1 ) 2024-07-18 07:44:34,043 INFO > UI AM validateGoto (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI Enduser appAuthHelper1 (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI Enduser appAuthHelper2 (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI IDM uiconfig (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI Enduser sessioncheck (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI IDM version (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI IDM features (OK=4428 KO=0 ) 2024-07-18 07:44:34,043 INFO > UI IDM login (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI IDM privilege (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI IDM dashboard (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI IDM user (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI IDM alpha_user (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI IDM oidcToken (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > userinfo (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > RootUserinfo (OK=260180 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI-Logout Redirect 1 (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI AM revoke1 (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI AM revoke2 (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > UI AM endsession (OK=4428 KO=0 ) 2024-07-18 07:44:34,044 INFO > restloginProgressiveProfileCallback (OK=1 KO=0 ) 2024-07-18 07:44:34,044 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 07:44:34,044 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 20 (46.51%) 2024-07-18 07:44:34,044 INFO ess_token' is defined 2024-07-18 07:44:34,044 INFO > tokenUserinfo: Failed to build request: No attribute named 'ac 8 (18.60%) 2024-07-18 07:44:34,044 INFO cess_token' is defined 2024-07-18 07:44:34,044 INFO > status.find.is(200), but actually found 502 6 (13.95%) 2024-07-18 07:44:34,044 INFO > status.find.in([200, 209], 304), found 502 3 ( 6.98%) 2024-07-18 07:44:34,044 INFO > status.find.is(302), but actually found 502 3 ( 6.98%) 2024-07-18 07:44:34,044 INFO > createOrganization: Failed to build request: No attribute name 1 ( 2.33%) 2024-07-18 07:44:34,044 INFO d 'access_token' is defined 2024-07-18 07:44:34,044 INFO > queryOrganization: Failed to build request: No attribute named 1 ( 2.33%) 2024-07-18 07:44:34,044 INFO 'organization_id' is defined 2024-07-18 07:44:34,044 INFO > deleteOrganization: Failed to build request: No attribute name 1 ( 2.33%) 2024-07-18 07:44:34,044 INFO d 'organization_id' is defined 2024-07-18 07:44:34,044 INFO 2024-07-18 07:44:34,044 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 07:44:34,044 INFO [##########################################################################]100% 2024-07-18 07:44:34,044 INFO waiting: 0 / active: 0 / done: 108412 2024-07-18 07:44:34,044 INFO ================================================================================ 2024-07-18 07:44:34,044 INFO 2024-07-18 07:44:34,044 INFO Simulation com.forgerock.gatling.Loadtest completed in 3639 seconds 2024-07-18 07:44:34,044 INFO 2024-07-18 07:44:34,044 INFO ---------------------- 2024-07-18 07:44:34,045 INFO [18/Jul/2024 08:42:43] Create tar file benchmark-30.tar.gz 2024-07-18 07:44:34,045 INFO ---------------------- 2024-07-18 07:44:34,045 INFO RESULTS_FOLDER=/results/gatling/ 2024-07-18 07:44:34,045 INFO RESULT_FOLDER=benchmark-30 2024-07-18 07:44:34,045 INFO SIMULATION_PATH=benchmark-30/loadtest-20240718064203749 2024-07-18 07:44:34,045 INFO PWD=/results/gatling/benchmark-30/loadtest-20240718064203749 2024-07-18 07:44:34,045 INFO [cmd] tar -czvf /results/gatling//benchmark-30.tar.gz --exclude=simulation.log * 2024-07-18 07:44:34,045 INFO /results/gatling 2024-07-18 07:44:34,045 INFO 2024-07-18 07:44:34,045 INFO ---------------------- 2024-07-18 07:44:34,045 INFO [18/Jul/2024 08:42:43] Update /results/gatling//latest 2024-07-18 07:44:34,045 INFO ---------------------- 2024-07-18 07:44:34,045 INFO 2024-07-18 07:44:34,045 INFO ---------------------- 2024-07-18 07:44:34,045 INFO [18/Jul/2024 08:42:43] Update /results/gatling//latest.tar.gz 2024-07-18 07:44:34,045 INFO ---------------------- 2024-07-18 07:44:34,045 INFO ________________________________________________________________________________ [2024-07-18 07:44:34] benchmark-30 show_stderr : Display stderr order ________________________________________________________________________________ 2024-07-18 07:44:34,046 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/02_benchmark-30/stderr.txt is small (0 lines), printing all lines: 2024-07-18 07:44:34,046 DEBUG ----- output ----- 2024-07-18 07:44:34,046 DEBUG 2024-07-18 07:44:34,046 INFO ________________________________________________________________________________ [2024-07-18 07:44:34] benchmark-30 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-07-18 07:44:34] benchmark-30 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-07-18 07:44:34] benchmark-30 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped