--Task-- name: benchmark-50 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates bellow loop: False interval: None dependencies: [] wait_for: ['benchmark-30'] preceding_task: benchmark-30 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self50-', 'testCase': 'idc.benchmark.CH2023', 'testMode': 'open', 'throughput': 50} group_name: None Current dir: /mnt/disks/data/xslou/lodestar-fork/pyrock ________________________________________________________________________________ [2024-07-18 07:44:34] benchmark-50 pre : N/A ________________________________________________________________________________ 2024-07-18 07:44:34 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-07-18 07:44:34 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-50/stdout.txt Pod log : /results/orders/benchmark-50 2024-07-18 07:44:34,928 INFO 2024-07-18 07:44:34,928 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:34,928 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:35,229 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:35,230 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:35,230 DEBUG --- stdout --- 2024-07-18 07:44:35,230 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:35,230 DEBUG --- stderr --- 2024-07-18 07:44:35,230 DEBUG ________________________________________________________________________________ [2024-07-18 07:44:35] benchmark-50 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-07-18 07:44:35,231 INFO 2024-07-18 07:44:35,231 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:35,231 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:35,541 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:35,541 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:35,541 DEBUG --- stdout --- 2024-07-18 07:44:35,541 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:35,541 DEBUG --- stderr --- 2024-07-18 07:44:35,541 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-50 --extra-run-jvm-options "-Xmx4G" --no-reports ________________________________________________________________________________ [2024-07-18 07:44:35] benchmark-50 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-07-18 07:44:35,542 INFO 2024-07-18 07:44:35,542 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:35,542 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:35,846 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:35,847 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:35,847 DEBUG --- stdout --- 2024-07-18 07:44:35,847 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:35,847 DEBUG --- stderr --- 2024-07-18 07:44:35,847 DEBUG Order file: /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/order.json { "name": "benchmark-50", "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-50 --extra-run-jvm-options \"-Xmx4G\" --no-reports", "out-dir": "/results/orders/benchmark-50", "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=self50- -Drealm=alpha -DtestCase=idc.benchmark.CH2023 -DtestMode=open -Dthroughput=50 -Duser_password=Pa_ssw0rd" } } ________________________________________________________________________________ [2024-07-18 07:44:35] benchmark-50 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2024-07-18 07:44:35,850 INFO 2024-07-18 07:44:35,850 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-07-18 07:44:35,850 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 07:44:36,103 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 07:44:36,103 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:36,103 DEBUG --- stdout --- 2024-07-18 07:44:36,104 DEBUG WAITING 2024-07-18 07:44:36,104 DEBUG --- stderr --- 2024-07-18 07:44:36,104 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 07:44:36] benchmark-50 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-07-18 07:44:36,105 INFO 2024-07-18 07:44:36,105 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:36,105 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:36,422 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:36,422 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:36,422 DEBUG --- stdout --- 2024-07-18 07:44:36,422 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:36,423 DEBUG --- stderr --- 2024-07-18 07:44:36,423 DEBUG 2024-07-18 07:44:36,423 INFO 2024-07-18 07:44:36,423 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/03_benchmark-50/order.json overseer-0-7796fc5d9b-ngsxg:/results/orders/order.json 2024-07-18 07:44:36,423 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 07:44:37,802 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:37,802 DEBUG --- stdout --- 2024-07-18 07:44:37,802 DEBUG 2024-07-18 07:44:37,802 DEBUG --- stderr --- 2024-07-18 07:44:37,802 DEBUG Order has been successfully forwarded to overseer 2024-07-18 07:44:37 - INFO: Check if Gatling simulation started successfully 2024-07-18 07:44:37,803 INFO 2024-07-18 07:44:37,803 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:37,803 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 07:44:38,112 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 07:44:38,112 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:38,112 DEBUG --- stdout --- 2024-07-18 07:44:38,112 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 07:44:38,112 DEBUG --- stderr --- 2024-07-18 07:44:38,113 DEBUG 2024-07-18 07:44:38,113 INFO 2024-07-18 07:44:38,113 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-50/stdout.txt | grep "started..." 2024-07-18 07:44:38,113 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 07:44:38,847 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: started... - retry 2024-07-18 07:44:44,592 INFO [loop_until]: Function succeeded after 6s (rc=0) - expected pattern found 2024-07-18 07:44:44,592 INFO [loop_until]: OK (rc = 0) 2024-07-18 07:44:44,592 DEBUG --- stdout --- 2024-07-18 07:44:44,592 DEBUG GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling Gatling 3.11.5 is available! (you're using 3.9.5) Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 07:44:44,592 DEBUG --- stderr --- 2024-07-18 07:44:44,592 DEBUG ________________________________________________________________________________ [2024-07-18 07:44:44] benchmark-50 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 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 03s, retry Order is running since 26m 04s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 05s, retry Order is running since 38m 06s, retry Order is running since 40m 06s, retry Order is running since 42m 06s, retry Order is running since 44m 07s, retry Order is running since 46m 07s, retry Order is running since 48m 07s, retry Order is running since 50m 07s, retry Order is running since 52m 08s, retry Order is running since 54m 08s, retry Order is running since 56m 08s, retry Order is running since 58m 09s, retry Order is running since 1h, retry PASS : Order stopped by itself after 1h 02m and before timeout (1h 12m) ________________________________________________________________________________ [2024-07-18 08:46:54] benchmark-50 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-07-18 08:46:54,502 INFO 2024-07-18 08:46:54,502 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 08:46:54,503 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:46:54,848 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:46:54,848 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:54,848 DEBUG --- stdout --- 2024-07-18 08:46:54,849 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:46:54,849 DEBUG --- stderr --- 2024-07-18 08:46:54,849 DEBUG 2024-07-18 08:46:54,849 INFO 2024-07-18 08:46:54,849 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 08:46:54,849 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 08:46:55,649 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:55,649 DEBUG --- stdout --- 2024-07-18 08:46:55,649 DEBUG 2024-07-18 08:46:55,649 DEBUG --- stderr --- 2024-07-18 08:46:55,649 DEBUG Order ran during 1h 02m ________________________________________________________________________________ [2024-07-18 08:46:55] benchmark-50 download_logs : Download individual order files ________________________________________________________________________________ 2024-07-18 08:46:55 - PASS: file already downloaded /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/order.json 2024-07-18 08:46:55,651 INFO 2024-07-18 08:46:55,651 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 08:46:55,651 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:46:56,025 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:46:56,025 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:56,025 DEBUG --- stdout --- 2024-07-18 08:46:56,025 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:46:56,025 DEBUG --- stderr --- 2024-07-18 08:46:56,025 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 08:46:56,026 INFO 2024-07-18 08:46:56,026 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 08:46:56,026 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:46:56,357 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:46:56,357 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:56,357 DEBUG --- stdout --- 2024-07-18 08:46:56,357 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:46:56,357 DEBUG --- stderr --- 2024-07-18 08:46:56,357 DEBUG 2024-07-18 08:46:56,358 INFO 2024-07-18 08:46:56,358 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-50/rc.txt" ]; then echo "/results/orders/benchmark-50/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-50/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/rc.txt file found" 2024-07-18 08:46:56,358 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 08:46:57,176 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 08:46:57,176 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:57,176 DEBUG --- stdout --- 2024-07-18 08:46:57,176 DEBUG /results/orders/benchmark-50/rc.txt file found 2024-07-18 08:46:57,176 DEBUG --- stderr --- 2024-07-18 08:46:57,176 DEBUG 2024-07-18 08:46:57,177 INFO 2024-07-18 08:46:57,177 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 08:46:57,177 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:46:57,482 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:46:57,482 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:57,483 DEBUG --- stdout --- 2024-07-18 08:46:57,483 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:46:57,483 DEBUG --- stderr --- 2024-07-18 08:46:57,483 DEBUG 2024-07-18 08:46:57,483 INFO 2024-07-18 08:46:57,483 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-50/rc.txt 2024-07-18 08:46:58,297 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 08:46:58,298 DEBUG --- stdout --- 2024-07-18 08:46:58,299 DEBUG 4 /results/orders/benchmark-50/rc.txt 2024-07-18 08:46:58,299 DEBUG --- stderr --- 2024-07-18 08:46:58,299 DEBUG 2024-07-18 08:46:58,299 INFO - Download file (size 4k) 2024-07-18 08:46:58,300 INFO 2024-07-18 08:46:58,300 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 08:46:58,300 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:46:58,621 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:46:58,621 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:58,621 DEBUG --- stdout --- 2024-07-18 08:46:58,621 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:46:58,621 DEBUG --- stderr --- 2024-07-18 08:46:58,621 DEBUG source : /results/orders/benchmark-50/rc.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/rc.txt 2024-07-18 08:46:58,622 INFO 2024-07-18 08:46:58,622 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 08:46:58,622 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:46:58,924 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:46:58,924 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:58,924 DEBUG --- stdout --- 2024-07-18 08:46:58,924 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:46:58,924 DEBUG --- stderr --- 2024-07-18 08:46:58,924 DEBUG 2024-07-18 08:46:58,925 INFO 2024-07-18 08:46:58,925 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-50/rc.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/rc.txt 2024-07-18 08:46:58,925 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 08:46:59,704 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:46:59,704 DEBUG --- stdout --- 2024-07-18 08:46:59,704 DEBUG tar: Removing leading `/' from member names 2024-07-18 08:46:59,704 DEBUG --- stderr --- 2024-07-18 08:46:59,705 DEBUG 2024-07-18 08:46:59,705 INFO 2024-07-18 08:46:59,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 08:46:59,705 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:00,026 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:00,026 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:00,026 DEBUG --- stdout --- 2024-07-18 08:47:00,027 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:00,027 DEBUG --- stderr --- 2024-07-18 08:47:00,027 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 08:47:00,027 INFO 2024-07-18 08:47:00,027 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 08:47:00,027 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:00,350 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:00,351 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:00,351 DEBUG --- stdout --- 2024-07-18 08:47:00,351 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:00,351 DEBUG --- stderr --- 2024-07-18 08:47:00,351 DEBUG 2024-07-18 08:47:00,351 INFO 2024-07-18 08:47:00,351 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-50/stderr.txt" ]; then echo "/results/orders/benchmark-50/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-50/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/stderr.txt file found" 2024-07-18 08:47:00,351 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 08:47:01,169 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 08:47:01,169 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:01,170 DEBUG --- stdout --- 2024-07-18 08:47:01,170 DEBUG /results/orders/benchmark-50/stderr.txt file found 2024-07-18 08:47:01,170 DEBUG --- stderr --- 2024-07-18 08:47:01,170 DEBUG 2024-07-18 08:47:01,170 INFO 2024-07-18 08:47:01,170 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 08:47:01,170 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:01,481 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:01,481 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:01,481 DEBUG --- stdout --- 2024-07-18 08:47:01,481 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:01,481 DEBUG --- stderr --- 2024-07-18 08:47:01,481 DEBUG 2024-07-18 08:47:01,481 INFO 2024-07-18 08:47:01,482 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-50/stderr.txt 2024-07-18 08:47:02,284 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 08:47:02,284 DEBUG --- stdout --- 2024-07-18 08:47:02,284 DEBUG 0 /results/orders/benchmark-50/stderr.txt 2024-07-18 08:47:02,284 DEBUG --- stderr --- 2024-07-18 08:47:02,284 DEBUG 2024-07-18 08:47:02,284 INFO - Download file (size 0k) 2024-07-18 08:47:02,284 INFO 2024-07-18 08:47:02,285 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 08:47:02,285 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:02,588 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:02,589 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:02,589 DEBUG --- stdout --- 2024-07-18 08:47:02,589 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:02,589 DEBUG --- stderr --- 2024-07-18 08:47:02,589 DEBUG source : /results/orders/benchmark-50/stderr.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/stderr.txt 2024-07-18 08:47:02,589 INFO 2024-07-18 08:47:02,589 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 08:47:02,589 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:02,898 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:02,899 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:02,899 DEBUG --- stdout --- 2024-07-18 08:47:02,899 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:02,899 DEBUG --- stderr --- 2024-07-18 08:47:02,899 DEBUG 2024-07-18 08:47:02,899 INFO 2024-07-18 08:47:02,899 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-50/stderr.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/stderr.txt 2024-07-18 08:47:02,899 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 08:47:03,674 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:03,674 DEBUG --- stdout --- 2024-07-18 08:47:03,674 DEBUG tar: Removing leading `/' from member names 2024-07-18 08:47:03,674 DEBUG --- stderr --- 2024-07-18 08:47:03,674 DEBUG 2024-07-18 08:47:03,675 INFO 2024-07-18 08:47:03,675 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 08:47:03,675 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:03,989 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:03,989 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:03,989 DEBUG --- stdout --- 2024-07-18 08:47:03,990 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:03,990 DEBUG --- stderr --- 2024-07-18 08:47:03,990 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 08:47:03,990 INFO 2024-07-18 08:47:03,990 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 08:47:03,990 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:04,292 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:04,293 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:04,293 DEBUG --- stdout --- 2024-07-18 08:47:04,293 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:04,293 DEBUG --- stderr --- 2024-07-18 08:47:04,293 DEBUG 2024-07-18 08:47:04,293 INFO 2024-07-18 08:47:04,293 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-50/stdout.txt" ]; then echo "/results/orders/benchmark-50/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-50/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/stdout.txt file found" 2024-07-18 08:47:04,293 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 08:47:05,102 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 08:47:05,102 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:05,102 DEBUG --- stdout --- 2024-07-18 08:47:05,102 DEBUG /results/orders/benchmark-50/stdout.txt file found 2024-07-18 08:47:05,102 DEBUG --- stderr --- 2024-07-18 08:47:05,102 DEBUG 2024-07-18 08:47:05,103 INFO 2024-07-18 08:47:05,103 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 08:47:05,103 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:05,405 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:05,405 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:05,405 DEBUG --- stdout --- 2024-07-18 08:47:05,405 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:05,405 DEBUG --- stderr --- 2024-07-18 08:47:05,405 DEBUG 2024-07-18 08:47:05,405 INFO 2024-07-18 08:47:05,406 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-50/stdout.txt 2024-07-18 08:47:06,211 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 08:47:06,211 DEBUG --- stdout --- 2024-07-18 08:47:06,211 DEBUG 3148 /results/orders/benchmark-50/stdout.txt 2024-07-18 08:47:06,211 DEBUG --- stderr --- 2024-07-18 08:47:06,211 DEBUG 2024-07-18 08:47:06,211 INFO - Download file (size 3148k) 2024-07-18 08:47:06,211 INFO 2024-07-18 08:47:06,212 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 08:47:06,212 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:06,520 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:06,521 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:06,521 DEBUG --- stdout --- 2024-07-18 08:47:06,521 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:06,521 DEBUG --- stderr --- 2024-07-18 08:47:06,521 DEBUG source : /results/orders/benchmark-50/stdout.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/stdout.txt 2024-07-18 08:47:06,521 INFO 2024-07-18 08:47:06,521 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 08:47:06,521 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:06,823 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:06,823 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:06,823 DEBUG --- stdout --- 2024-07-18 08:47:06,823 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:06,823 DEBUG --- stderr --- 2024-07-18 08:47:06,824 DEBUG 2024-07-18 08:47:06,824 INFO 2024-07-18 08:47:06,824 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-50/stdout.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/stdout.txt 2024-07-18 08:47:06,824 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 08:47:08,034 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:08,035 DEBUG --- stdout --- 2024-07-18 08:47:08,035 DEBUG tar: Removing leading `/' from member names 2024-07-18 08:47:08,035 DEBUG --- stderr --- 2024-07-18 08:47:08,035 DEBUG ________________________________________________________________________________ [2024-07-18 08:47:08] benchmark-50 show_cmd : Display order command ________________________________________________________________________________ 2024-07-18 08:47:08,036 INFO 2024-07-18 08:47:08,036 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 08:47:08,036 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:08,359 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:08,359 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:08,359 DEBUG --- stdout --- 2024-07-18 08:47:08,359 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:08,359 DEBUG --- stderr --- 2024-07-18 08:47:08,359 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 08:47:08,360 INFO 2024-07-18 08:47:08,360 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 08:47:08,360 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:08,686 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:08,687 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:08,688 DEBUG --- stdout --- 2024-07-18 08:47:08,688 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:08,688 DEBUG --- stderr --- 2024-07-18 08:47:08,688 DEBUG 2024-07-18 08:47:08,689 INFO 2024-07-18 08:47:08,689 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-50/cmd.txt" ]; then echo "/results/orders/benchmark-50/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-50/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-50/cmd.txt file found" 2024-07-18 08:47:08,689 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 08:47:09,516 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 08:47:09,517 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:09,517 DEBUG --- stdout --- 2024-07-18 08:47:09,517 DEBUG /results/orders/benchmark-50/cmd.txt file found 2024-07-18 08:47:09,517 DEBUG --- stderr --- 2024-07-18 08:47:09,517 DEBUG 2024-07-18 08:47:09,517 INFO 2024-07-18 08:47:09,517 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 08:47:09,517 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:09,822 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:09,822 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:09,822 DEBUG --- stdout --- 2024-07-18 08:47:09,822 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:09,822 DEBUG --- stderr --- 2024-07-18 08:47:09,822 DEBUG 2024-07-18 08:47:09,822 INFO 2024-07-18 08:47:09,823 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-50/cmd.txt 2024-07-18 08:47:10,643 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 08:47:10,643 DEBUG --- stdout --- 2024-07-18 08:47:10,643 DEBUG 4 /results/orders/benchmark-50/cmd.txt 2024-07-18 08:47:10,643 DEBUG --- stderr --- 2024-07-18 08:47:10,643 DEBUG 2024-07-18 08:47:10,643 INFO - Download file (size 4k) 2024-07-18 08:47:10,644 INFO 2024-07-18 08:47:10,644 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 08:47:10,644 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:10,968 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:10,968 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:10,968 DEBUG --- stdout --- 2024-07-18 08:47:10,968 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:10,968 DEBUG --- stderr --- 2024-07-18 08:47:10,969 DEBUG source : /results/orders/benchmark-50/cmd.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/cmd.txt 2024-07-18 08:47:10,969 INFO 2024-07-18 08:47:10,969 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 08:47:10,969 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 08:47:11,292 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 08:47:11,293 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:11,293 DEBUG --- stdout --- 2024-07-18 08:47:11,293 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 08:47:11,293 DEBUG --- stderr --- 2024-07-18 08:47:11,293 DEBUG 2024-07-18 08:47:11,293 INFO 2024-07-18 08:47:11,293 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-50/cmd.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/cmd.txt 2024-07-18 08:47:11,293 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 08:47:12,038 INFO [loop_until]: OK (rc = 0) 2024-07-18 08:47:12,038 DEBUG --- stdout --- 2024-07-18 08:47:12,038 DEBUG tar: Removing leading `/' from member names 2024-07-18 08:47:12,038 DEBUG --- stderr --- 2024-07-18 08:47:12,038 DEBUG 2024-07-18 08:47:12,039 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/cmd.txt is small (1 lines), printing all lines: 2024-07-18 08:47:12,039 DEBUG ----- output ----- 2024-07-18 08:47:12,039 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-50 --extra-run-jvm-options "-Xmx4G" --no-reports 2024-07-18 08:47:12,039 INFO ________________________________________________________________________________ [2024-07-18 08:47:12] benchmark-50 show_rc : Display rc order ________________________________________________________________________________ 2024-07-18 08:47:12,039 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/rc.txt is small (1 lines), printing all lines: 2024-07-18 08:47:12,039 DEBUG ----- output ----- 2024-07-18 08:47:12,039 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-07-18 08:47:12,039 INFO ________________________________________________________________________________ [2024-07-18 08:47:12] benchmark-50 show_stdout : Display stdout order ________________________________________________________________________________ 2024-07-18 08:47:12,047 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/03_benchmark-50/stdout.txt is 44395 lines): 2024-07-18 08:47:12,047 DEBUG ----- output ----- 2024-07-18 08:47:12,047 INFO GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling 2024-07-18 08:47:12,047 INFO Gatling 3.11.5 is available! (you're using 3.9.5) 2024-07-18 08:47:12,047 INFO Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 08:47:12,047 INFO 2024-07-18 08:47:12,047 INFO ================================================================================ 2024-07-18 08:47:12,047 INFO 2024-07-18 08:44:47 5s elapsed 2024-07-18 08:47:12,047 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 08:47:12,047 INFO > Global (OK=121 KO=0 ) 2024-07-18 08:47:12,047 INFO > restLoginInitiate (OK=18 KO=0 ) 2024-07-18 08:47:12,047 INFO > restLoginUsernamePasswordCallback (OK=18 KO=0 ) 2024-07-18 08:47:12,047 INFO > User Authorize PKCE stage (OK=17 KO=0 ) 2024-07-18 08:47:12,047 INFO > User AccessToken PKCE stage (OK=16 KO=0 ) 2024-07-18 08:47:12,047 INFO > tokenUserinfo (OK=6 KO=0 ) 2024-07-18 08:47:12,047 INFO > Skip 2FA (OK=11 KO=0 ) 2024-07-18 08:47:12,047 INFO > RootUserinfo (OK=21 KO=0 ) 2024-07-18 08:47:12,047 INFO > getIdToken (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO > getIdToken Redirect 1 (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO > createOrganization (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO > queryOrganization (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO > deleteOrganization (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO > registration_restLoginInitiate (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO > registrationCallback (OK=2 KO=0 ) 2024-07-18 08:47:12,047 INFO 2024-07-18 08:47:12,047 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 08:47:12,047 INFO [- ] 0% 2024-07-18 08:47:12,047 INFO waiting: 180894 / active: 11 / done: 10 2024-07-18 08:47:12,047 INFO ================================================================================ 2024-07-18 08:47:12,047 INFO 2024-07-18 08:47:12,047 INFO 2024-07-18 08:47:12,047 INFO ================================================================================ 2024-07-18 08:47:12,047 INFO 2024-07-18 08:44:52 10s elapsed 2024-07-18 08:47:12,047 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 08:47:12,048 INFO > Global (OK=650 KO=0 ) 2024-07-18 08:47:12,048 INFO > restLoginInitiate (OK=73 KO=0 ) 2024-07-18 08:47:12,048 INFO > restLoginUsernamePasswordCallback (OK=71 KO=0 ) 2024-07-18 08:47:12,048 INFO > User Authorize PKCE stage (OK=74 KO=0 ) 2024-07-18 08:47:12,048 INFO > User AccessToken PKCE stage (OK=73 KO=0 ) 2024-07-18 08:47:12,048 INFO > tokenUserinfo (OK=17 KO=0 ) 2024-07-18 08:47:12,048 INFO > Skip 2FA (OK=50 KO=0 ) 2024-07-18 08:47:12,048 INFO > RootUserinfo (OK=106 KO=0 ) 2024-07-18 08:47:12,048 INFO > getIdToken (OK=15 KO=0 ) 2024-07-18 08:47:12,048 INFO > getIdToken Redirect 1 (OK=15 KO=0 ) 2024-07-18 08:47:12,048 INFO > createOrganization (OK=15 KO=0 ) 2024-07-18 08:47:12,048 INFO > queryOrganization (OK=15 KO=0 ) 2024-07-18 08:47:12,048 INFO > deleteOrganization (OK=14 KO=0 ) 2024-07-18 08:47:12,048 INFO > registration_restLoginInitiate (OK=10 KO=0 ) 2024-07-18 08:47:12,048 INFO > registrationCallback (OK=10 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI-Post-Login (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI-Post-Login Redirect 1 (OK=12 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI AM validateGoto (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI AM idFromSession (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI Enduser appAuthHelper1 (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI Enduser appAuthHelper2 (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI Enduser sessioncheck (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM uiconfig (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM version (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM features (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM login (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM privilege (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM user (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM alpha_user (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM dashboard (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI IDM oidcToken (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > userinfo (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI-Logout Redirect 1 (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI AM revoke1 (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI AM revoke2 (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO > UI AM endsession (OK=4 KO=0 ) 2024-07-18 08:47:12,048 INFO 2024-07-18 08:47:12,048 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 08:47:12,048 INFO [- ] 0% 2024-07-18 08:47:12,048 INFO waiting: 180831 / active: 29 / done: 55 2024-07-18 08:47:12,048 INFO ================================================================================ 2024-07-18 08:47:12,048 INFO 2024-07-18 08:47:12,049 INFO 2024-07-18 08:47:12,049 INFO ================================================================================ 2024-07-18 08:47:12,049 INFO 2024-07-18 08:44:57 15s elapsed 2024-07-18 08:47:12,049 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 08:47:12,049 INFO > Global (OK=1482 KO=0 ) 2024-07-18 08:47:12,049 INFO > restLoginInitiate (OK=155 KO=0 ) 2024-07-18 08:47:12,049 INFO > restLoginUsernamePasswordCallback (OK=152 KO=0 ) 2024-07-18 08:47:12,049 INFO > User Authorize PKCE stage (OK=162 KO=0 ) 2024-07-18 08:47:12,049 INFO > User AccessToken PKCE stage (OK=161 KO=0 ) 2024-07-18 08:47:12,049 INFO > tokenUserinfo (OK=37 KO=0 ) 2024-07-18 08:47:12,049 INFO > Skip 2FA (OK=103 KO=0 ) 2024-07-18 08:47:12,049 INFO > RootUserinfo (OK=285 KO=0 ) 2024-07-18 08:47:12,049 INFO > getIdToken (OK=26 KO=0 ) 2024-07-18 08:47:12,049 INFO > getIdToken Redirect 1 (OK=25 KO=0 ) 2024-07-18 08:47:12,049 INFO > createOrganization (OK=25 KO=0 ) 2024-07-18 08:47:12,049 INFO > queryOrganization (OK=25 KO=0 ) 2024-07-18 08:47:12,049 INFO > deleteOrganization (OK=25 KO=0 ) 2024-07-18 08:47:12,049 INFO > registration_restLoginInitiate (OK=32 KO=0 ) 2024-07-18 08:47:12,049 INFO > registrationCallback (OK=31 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI-Post-Login (OK=11 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI-Post-Login Redirect 1 (OK=33 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI AM validateGoto (OK=11 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI AM idFromSession (OK=11 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI Enduser appAuthHelper1 (OK=11 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI Enduser appAuthHelper2 (OK=11 KO=0 ) 2024-07-18 08:47:12,049 INFO > UI Enduser sessioncheck (OK=10 KO=0 ) 2024-07-18 08:47:12,049 INFO [...] 2024-07-18 08:47:12,061 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 08:47:12,061 INFO > tokenUserinfo: Failed to build request: No attribute named 'ac 61 (65.59%) 2024-07-18 08:47:12,061 INFO cess_token' is defined 2024-07-18 08:47:12,061 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 20 (21.51%) 2024-07-18 08:47:12,061 INFO ess_token' is defined 2024-07-18 08:47:12,061 INFO > status.find.is(302), but actually found 502 4 ( 4.30%) 2024-07-18 08:47:12,061 INFO > status.find.in([200, 209], 304), found 502 3 ( 3.23%) 2024-07-18 08:47:12,061 INFO > status.find.is(200), but actually found 502 2 ( 2.15%) 2024-07-18 08:47:12,061 INFO > createOrganization: Failed to build request: No attribute name 1 ( 1.08%) 2024-07-18 08:47:12,061 INFO d 'access_token' is defined 2024-07-18 08:47:12,061 INFO > queryOrganization: Failed to build request: No attribute named 1 ( 1.08%) 2024-07-18 08:47:12,061 INFO 'organization_id' is defined 2024-07-18 08:47:12,061 INFO > deleteOrganization: Failed to build request: No attribute name 1 ( 1.08%) 2024-07-18 08:47:12,061 INFO d 'organization_id' is defined 2024-07-18 08:47:12,061 INFO 2024-07-18 08:47:12,061 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 08:47:12,061 INFO [#########################################################################-] 99% 2024-07-18 08:47:12,061 INFO waiting: 0 / active: 14 / done: 180901 2024-07-18 08:47:12,061 INFO ================================================================================ 2024-07-18 08:47:12,061 INFO 2024-07-18 08:47:12,061 INFO 2024-07-18 08:47:12,061 INFO ================================================================================ 2024-07-18 08:47:12,061 INFO 2024-07-18 09:45:19 3637s elapsed 2024-07-18 08:47:12,061 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 08:47:12,061 INFO > Global (OK=1535697 KO=9 ) 2024-07-18 08:47:12,061 INFO > restLoginInitiate (OK=151965 KO=1 ) 2024-07-18 08:47:12,062 INFO > restLoginUsernamePasswordCallback (OK=151964 KO=1 ) 2024-07-18 08:47:12,062 INFO > User Authorize PKCE stage (OK=159242 KO=4 ) 2024-07-18 08:47:12,062 INFO > User AccessToken PKCE stage (OK=159240 KO=2 ) 2024-07-18 08:47:12,062 INFO > tokenUserinfo (OK=36167 KO=0 ) 2024-07-18 08:47:12,062 INFO > Skip 2FA (OK=108394 KO=0 ) 2024-07-18 08:47:12,062 INFO > RootUserinfo (OK=433855 KO=0 ) 2024-07-18 08:47:12,062 INFO > getIdToken (OK=21619 KO=0 ) 2024-07-18 08:47:12,062 INFO > getIdToken Redirect 1 (OK=21619 KO=0 ) 2024-07-18 08:47:12,062 INFO > createOrganization (OK=21618 KO=0 ) 2024-07-18 08:47:12,062 INFO > queryOrganization (OK=21618 KO=0 ) 2024-07-18 08:47:12,062 INFO > deleteOrganization (OK=21618 KO=0 ) 2024-07-18 08:47:12,062 INFO > registration_restLoginInitiate (OK=28949 KO=0 ) 2024-07-18 08:47:12,062 INFO > registrationCallback (OK=28949 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI-Post-Login (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI-Post-Login Redirect 1 (OK=22026 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI AM validateGoto (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI AM idFromSession (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI Enduser appAuthHelper1 (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI Enduser appAuthHelper2 (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI Enduser sessioncheck (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM uiconfig (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM version (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM features (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM login (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM privilege (OK=7341 KO=1 ) 2024-07-18 08:47:12,062 INFO > UI IDM user (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM alpha_user (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM dashboard (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI IDM oidcToken (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > userinfo (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI-Logout Redirect 1 (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI AM revoke1 (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI AM revoke2 (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > UI AM endsession (OK=7342 KO=0 ) 2024-07-18 08:47:12,062 INFO > restloginProgressiveProfileCallback (OK=15 KO=0 ) 2024-07-18 08:47:12,062 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 08:47:12,062 INFO > tokenUserinfo: Failed to build request: No attribute named 'ac 61 (65.59%) 2024-07-18 08:47:12,062 INFO cess_token' is defined 2024-07-18 08:47:12,063 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 20 (21.51%) 2024-07-18 08:47:12,063 INFO ess_token' is defined 2024-07-18 08:47:12,063 INFO > status.find.is(302), but actually found 502 4 ( 4.30%) 2024-07-18 08:47:12,063 INFO > status.find.in([200, 209], 304), found 502 3 ( 3.23%) 2024-07-18 08:47:12,063 INFO > status.find.is(200), but actually found 502 2 ( 2.15%) 2024-07-18 08:47:12,063 INFO > createOrganization: Failed to build request: No attribute name 1 ( 1.08%) 2024-07-18 08:47:12,063 INFO d 'access_token' is defined 2024-07-18 08:47:12,063 INFO > queryOrganization: Failed to build request: No attribute named 1 ( 1.08%) 2024-07-18 08:47:12,063 INFO 'organization_id' is defined 2024-07-18 08:47:12,063 INFO > deleteOrganization: Failed to build request: No attribute name 1 ( 1.08%) 2024-07-18 08:47:12,063 INFO d 'organization_id' is defined 2024-07-18 08:47:12,063 INFO 2024-07-18 08:47:12,063 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 08:47:12,063 INFO [##########################################################################]100% 2024-07-18 08:47:12,063 INFO waiting: 0 / active: 0 / done: 180915 2024-07-18 08:47:12,063 INFO ================================================================================ 2024-07-18 08:47:12,063 INFO 2024-07-18 08:47:12,063 INFO Simulation com.forgerock.gatling.Loadtest completed in 3637 seconds 2024-07-18 08:47:12,063 INFO 2024-07-18 08:47:12,063 INFO ---------------------- 2024-07-18 08:47:12,063 INFO [18/Jul/2024 09:45:19] Create tar file benchmark-50.tar.gz 2024-07-18 08:47:12,063 INFO ---------------------- 2024-07-18 08:47:12,063 INFO RESULTS_FOLDER=/results/gatling/ 2024-07-18 08:47:12,063 INFO RESULT_FOLDER=benchmark-50 2024-07-18 08:47:12,063 INFO SIMULATION_PATH=benchmark-50/loadtest-20240718074441503 2024-07-18 08:47:12,063 INFO PWD=/results/gatling/benchmark-50/loadtest-20240718074441503 2024-07-18 08:47:12,063 INFO [cmd] tar -czvf /results/gatling//benchmark-50.tar.gz --exclude=simulation.log * 2024-07-18 08:47:12,063 INFO /results/gatling 2024-07-18 08:47:12,063 INFO 2024-07-18 08:47:12,063 INFO ---------------------- 2024-07-18 08:47:12,063 INFO [18/Jul/2024 09:45:19] Update /results/gatling//latest 2024-07-18 08:47:12,063 INFO ---------------------- 2024-07-18 08:47:12,063 INFO 2024-07-18 08:47:12,063 INFO ---------------------- 2024-07-18 08:47:12,063 INFO [18/Jul/2024 09:45:19] Update /results/gatling//latest.tar.gz 2024-07-18 08:47:12,063 INFO ---------------------- 2024-07-18 08:47:12,063 INFO ________________________________________________________________________________ [2024-07-18 08:47:12] benchmark-50 show_stderr : Display stderr order ________________________________________________________________________________ 2024-07-18 08:47:12,064 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/03_benchmark-50/stderr.txt is small (0 lines), printing all lines: 2024-07-18 08:47:12,064 DEBUG ----- output ----- 2024-07-18 08:47:12,064 DEBUG 2024-07-18 08:47:12,064 INFO ________________________________________________________________________________ [2024-07-18 08:47:12] benchmark-50 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-07-18 08:47:12] benchmark-50 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-07-18 08:47:12] benchmark-50 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped