--Task-- name: benchmark-170 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-150'] preceding_task: benchmark-150 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self170-', 'testCase': 'idc.benchmark.CH2023', 'testMode': 'open', 'throughput': 170} group_name: None Current dir: /mnt/disks/data/xslou/lodestar-fork/pyrock ________________________________________________________________________________ [2024-07-18 14:00:25] benchmark-170 pre : N/A ________________________________________________________________________________ 2024-07-18 14:00:25 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-07-18 14:00:25 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-170/stdout.txt Pod log : /results/orders/benchmark-170 2024-07-18 14:00:25,834 INFO 2024-07-18 14:00:25,834 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 14:00:25,834 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 14:00:26,162 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 14:00:26,163 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:26,163 DEBUG --- stdout --- 2024-07-18 14:00:26,163 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 14:00:26,163 DEBUG --- stderr --- 2024-07-18 14:00:26,163 DEBUG ________________________________________________________________________________ [2024-07-18 14:00:26] benchmark-170 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-07-18 14:00:26,164 INFO 2024-07-18 14:00:26,164 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 14:00:26,164 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 14:00:26,487 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 14:00:26,487 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:26,487 DEBUG --- stdout --- 2024-07-18 14:00:26,487 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 14:00:26,487 DEBUG --- stderr --- 2024-07-18 14:00:26,487 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-170 --extra-run-jvm-options "-Xmx4G" --no-reports ________________________________________________________________________________ [2024-07-18 14:00:26] benchmark-170 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-07-18 14:00:26,488 INFO 2024-07-18 14:00:26,488 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 14:00:26,488 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 14:00:26,814 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 14:00:26,814 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:26,815 DEBUG --- stdout --- 2024-07-18 14:00:26,815 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 14:00:26,815 DEBUG --- stderr --- 2024-07-18 14:00:26,815 DEBUG Order file: /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/order.json { "name": "benchmark-170", "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-170 --extra-run-jvm-options \"-Xmx4G\" --no-reports", "out-dir": "/results/orders/benchmark-170", "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=self170- -Drealm=alpha -DtestCase=idc.benchmark.CH2023 -DtestMode=open -Dthroughput=170 -Duser_password=Pa_ssw0rd" } } ________________________________________________________________________________ [2024-07-18 14:00:26] benchmark-170 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 14:00:26,817 INFO 2024-07-18 14:00:26,817 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-07-18 14:00:26,817 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 14:00:27,127 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 14:00:27,127 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:27,127 DEBUG --- stdout --- 2024-07-18 14:00:27,127 DEBUG WAITING 2024-07-18 14:00:27,127 DEBUG --- stderr --- 2024-07-18 14:00:27,128 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 26 0 --:--:-- --:--:-- --:--:-- 26 ________________________________________________________________________________ [2024-07-18 14:00:27] benchmark-170 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-07-18 14:00:27,128 INFO 2024-07-18 14:00:27,128 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 14:00:27,128 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 14:00:27,454 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 14:00:27,454 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:27,454 DEBUG --- stdout --- 2024-07-18 14:00:27,454 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 14:00:27,454 DEBUG --- stderr --- 2024-07-18 14:00:27,454 DEBUG 2024-07-18 14:00:27,455 INFO 2024-07-18 14:00:27,455 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/09_benchmark-170/order.json overseer-0-7796fc5d9b-ngsxg:/results/orders/order.json 2024-07-18 14:00:27,455 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 14:00:28,839 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:28,839 DEBUG --- stdout --- 2024-07-18 14:00:28,839 DEBUG 2024-07-18 14:00:28,839 DEBUG --- stderr --- 2024-07-18 14:00:28,839 DEBUG Order has been successfully forwarded to overseer 2024-07-18 14:00:28 - INFO: Check if Gatling simulation started successfully 2024-07-18 14:00:28,840 INFO 2024-07-18 14:00:28,840 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 14:00:28,840 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 14:00:29,157 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 14:00:29,157 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:29,157 DEBUG --- stdout --- 2024-07-18 14:00:29,157 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 14:00:29,157 DEBUG --- stderr --- 2024-07-18 14:00:29,157 DEBUG 2024-07-18 14:00:29,157 INFO 2024-07-18 14:00:29,157 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-170/stdout.txt | grep "started..." 2024-07-18 14:00:29,158 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 14:00:29,922 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: started... - retry 2024-07-18 14:00:35,715 INFO [loop_until]: Function succeeded after 6s (rc=0) - expected pattern found 2024-07-18 14:00:35,715 INFO [loop_until]: OK (rc = 0) 2024-07-18 14:00:35,715 DEBUG --- stdout --- 2024-07-18 14:00:35,715 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 14:00:35,715 DEBUG --- stderr --- 2024-07-18 14:00:35,715 DEBUG ________________________________________________________________________________ [2024-07-18 14:00:35] benchmark-170 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 05s, retry Order is running since 32m 05s, retry Order is running since 34m 05s, retry Order is running since 36m 06s, retry Order is running since 38m 06s, retry Order is running since 40m 06s, retry Order is running since 42m 07s, retry Order is running since 44m 07s, retry Order is running since 46m 07s, retry Order is running since 48m 08s, retry Order is running since 50m 08s, retry Order is running since 52m 08s, retry Order is running since 54m 09s, retry Order is running since 56m 09s, 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 15:02:46] benchmark-170 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-07-18 15:02:46,044 INFO 2024-07-18 15:02:46,044 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 15:02:46,045 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:46,383 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:46,384 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:46,384 DEBUG --- stdout --- 2024-07-18 15:02:46,384 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:46,384 DEBUG --- stderr --- 2024-07-18 15:02:46,384 DEBUG 2024-07-18 15:02:46,384 INFO 2024-07-18 15:02:46,385 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 15:02:46,385 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 15:02:47,180 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:47,180 DEBUG --- stdout --- 2024-07-18 15:02:47,180 DEBUG 2024-07-18 15:02:47,180 DEBUG --- stderr --- 2024-07-18 15:02:47,181 DEBUG Order ran during 1h 02m ________________________________________________________________________________ [2024-07-18 15:02:47] benchmark-170 download_logs : Download individual order files ________________________________________________________________________________ 2024-07-18 15:02:47 - PASS: file already downloaded /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/order.json 2024-07-18 15:02:47,182 INFO 2024-07-18 15:02:47,182 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 15:02:47,182 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:47,487 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:47,487 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:47,487 DEBUG --- stdout --- 2024-07-18 15:02:47,487 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:47,487 DEBUG --- stderr --- 2024-07-18 15:02:47,487 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 15:02:47,488 INFO 2024-07-18 15:02:47,488 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 15:02:47,488 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:47,789 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:47,789 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:47,790 DEBUG --- stdout --- 2024-07-18 15:02:47,791 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:47,791 DEBUG --- stderr --- 2024-07-18 15:02:47,791 DEBUG 2024-07-18 15:02:47,791 INFO 2024-07-18 15:02:47,792 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-170/rc.txt" ]; then echo "/results/orders/benchmark-170/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-170/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-170/rc.txt file found" 2024-07-18 15:02:47,792 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 15:02:48,596 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 15:02:48,596 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:48,596 DEBUG --- stdout --- 2024-07-18 15:02:48,596 DEBUG /results/orders/benchmark-170/rc.txt file found 2024-07-18 15:02:48,596 DEBUG --- stderr --- 2024-07-18 15:02:48,597 DEBUG 2024-07-18 15:02:48,597 INFO 2024-07-18 15:02:48,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 15:02:48,597 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:48,918 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:48,919 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:48,919 DEBUG --- stdout --- 2024-07-18 15:02:48,919 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:48,919 DEBUG --- stderr --- 2024-07-18 15:02:48,919 DEBUG 2024-07-18 15:02:48,919 INFO 2024-07-18 15:02:48,920 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-170/rc.txt 2024-07-18 15:02:49,757 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 15:02:49,757 DEBUG --- stdout --- 2024-07-18 15:02:49,757 DEBUG 4 /results/orders/benchmark-170/rc.txt 2024-07-18 15:02:49,757 DEBUG --- stderr --- 2024-07-18 15:02:49,757 DEBUG 2024-07-18 15:02:49,757 INFO - Download file (size 4k) 2024-07-18 15:02:49,758 INFO 2024-07-18 15:02:49,758 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 15:02:49,758 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:50,063 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:50,063 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:50,063 DEBUG --- stdout --- 2024-07-18 15:02:50,063 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:50,063 DEBUG --- stderr --- 2024-07-18 15:02:50,063 DEBUG source : /results/orders/benchmark-170/rc.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/rc.txt 2024-07-18 15:02:50,064 INFO 2024-07-18 15:02:50,064 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 15:02:50,064 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:50,363 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:50,364 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:50,364 DEBUG --- stdout --- 2024-07-18 15:02:50,364 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:50,364 DEBUG --- stderr --- 2024-07-18 15:02:50,364 DEBUG 2024-07-18 15:02:50,364 INFO 2024-07-18 15:02:50,364 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-170/rc.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/rc.txt 2024-07-18 15:02:50,364 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 15:02:51,170 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:51,170 DEBUG --- stdout --- 2024-07-18 15:02:51,170 DEBUG tar: Removing leading `/' from member names 2024-07-18 15:02:51,170 DEBUG --- stderr --- 2024-07-18 15:02:51,170 DEBUG 2024-07-18 15:02:51,171 INFO 2024-07-18 15:02:51,171 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 15:02:51,171 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:51,489 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:51,490 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:51,490 DEBUG --- stdout --- 2024-07-18 15:02:51,490 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:51,490 DEBUG --- stderr --- 2024-07-18 15:02:51,490 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 15:02:51,490 INFO 2024-07-18 15:02:51,490 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 15:02:51,490 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:51,813 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:51,813 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:51,813 DEBUG --- stdout --- 2024-07-18 15:02:51,813 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:51,813 DEBUG --- stderr --- 2024-07-18 15:02:51,813 DEBUG 2024-07-18 15:02:51,814 INFO 2024-07-18 15:02:51,814 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-170/stderr.txt" ]; then echo "/results/orders/benchmark-170/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-170/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-170/stderr.txt file found" 2024-07-18 15:02:51,814 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 15:02:52,632 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 15:02:52,633 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:52,633 DEBUG --- stdout --- 2024-07-18 15:02:52,633 DEBUG /results/orders/benchmark-170/stderr.txt file found 2024-07-18 15:02:52,633 DEBUG --- stderr --- 2024-07-18 15:02:52,633 DEBUG 2024-07-18 15:02:52,633 INFO 2024-07-18 15:02:52,633 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 15:02:52,633 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:52,958 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:52,958 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:52,959 DEBUG --- stdout --- 2024-07-18 15:02:52,960 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:52,960 DEBUG --- stderr --- 2024-07-18 15:02:52,960 DEBUG 2024-07-18 15:02:52,960 INFO 2024-07-18 15:02:52,960 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-170/stderr.txt 2024-07-18 15:02:53,777 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 15:02:53,777 DEBUG --- stdout --- 2024-07-18 15:02:53,777 DEBUG 0 /results/orders/benchmark-170/stderr.txt 2024-07-18 15:02:53,777 DEBUG --- stderr --- 2024-07-18 15:02:53,777 DEBUG 2024-07-18 15:02:53,777 INFO - Download file (size 0k) 2024-07-18 15:02:53,778 INFO 2024-07-18 15:02:53,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 15:02:53,778 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:54,094 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:54,094 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:54,094 DEBUG --- stdout --- 2024-07-18 15:02:54,094 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:54,094 DEBUG --- stderr --- 2024-07-18 15:02:54,094 DEBUG source : /results/orders/benchmark-170/stderr.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/stderr.txt 2024-07-18 15:02:54,095 INFO 2024-07-18 15:02:54,095 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 15:02:54,095 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:54,409 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:54,409 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:54,409 DEBUG --- stdout --- 2024-07-18 15:02:54,409 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:54,409 DEBUG --- stderr --- 2024-07-18 15:02:54,409 DEBUG 2024-07-18 15:02:54,410 INFO 2024-07-18 15:02:54,410 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-170/stderr.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/stderr.txt 2024-07-18 15:02:54,410 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 15:02:55,191 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:55,191 DEBUG --- stdout --- 2024-07-18 15:02:55,191 DEBUG tar: Removing leading `/' from member names 2024-07-18 15:02:55,191 DEBUG --- stderr --- 2024-07-18 15:02:55,191 DEBUG 2024-07-18 15:02:55,192 INFO 2024-07-18 15:02:55,192 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 15:02:55,192 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:55,510 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:55,510 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:55,510 DEBUG --- stdout --- 2024-07-18 15:02:55,510 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:55,510 DEBUG --- stderr --- 2024-07-18 15:02:55,510 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 15:02:55,510 INFO 2024-07-18 15:02:55,511 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 15:02:55,511 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:55,941 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:55,942 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:55,942 DEBUG --- stdout --- 2024-07-18 15:02:55,942 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:55,942 DEBUG --- stderr --- 2024-07-18 15:02:55,942 DEBUG 2024-07-18 15:02:55,943 INFO 2024-07-18 15:02:55,943 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-170/stdout.txt" ]; then echo "/results/orders/benchmark-170/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-170/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-170/stdout.txt file found" 2024-07-18 15:02:55,943 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 15:02:56,815 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 15:02:56,816 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:56,816 DEBUG --- stdout --- 2024-07-18 15:02:56,816 DEBUG /results/orders/benchmark-170/stdout.txt file found 2024-07-18 15:02:56,816 DEBUG --- stderr --- 2024-07-18 15:02:56,816 DEBUG 2024-07-18 15:02:56,816 INFO 2024-07-18 15:02:56,816 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 15:02:56,816 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:57,134 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:57,134 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:57,134 DEBUG --- stdout --- 2024-07-18 15:02:57,134 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:57,134 DEBUG --- stderr --- 2024-07-18 15:02:57,134 DEBUG 2024-07-18 15:02:57,135 INFO 2024-07-18 15:02:57,135 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-170/stdout.txt 2024-07-18 15:02:57,956 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 15:02:57,957 DEBUG --- stdout --- 2024-07-18 15:02:57,957 DEBUG 4692 /results/orders/benchmark-170/stdout.txt 2024-07-18 15:02:57,957 DEBUG --- stderr --- 2024-07-18 15:02:57,957 DEBUG 2024-07-18 15:02:57,957 INFO - Download file (size 4692k) 2024-07-18 15:02:57,957 INFO 2024-07-18 15:02:57,957 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 15:02:57,957 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:58,260 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:58,260 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:58,261 DEBUG --- stdout --- 2024-07-18 15:02:58,261 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:58,261 DEBUG --- stderr --- 2024-07-18 15:02:58,262 DEBUG source : /results/orders/benchmark-170/stdout.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/stdout.txt 2024-07-18 15:02:58,262 INFO 2024-07-18 15:02:58,262 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 15:02:58,262 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:02:58,579 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:02:58,579 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:58,579 DEBUG --- stdout --- 2024-07-18 15:02:58,579 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:02:58,579 DEBUG --- stderr --- 2024-07-18 15:02:58,579 DEBUG 2024-07-18 15:02:58,579 INFO 2024-07-18 15:02:58,579 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-170/stdout.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/stdout.txt 2024-07-18 15:02:58,580 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 15:02:59,856 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:02:59,856 DEBUG --- stdout --- 2024-07-18 15:02:59,857 DEBUG tar: Removing leading `/' from member names 2024-07-18 15:02:59,857 DEBUG --- stderr --- 2024-07-18 15:02:59,857 DEBUG ________________________________________________________________________________ [2024-07-18 15:02:59] benchmark-170 show_cmd : Display order command ________________________________________________________________________________ 2024-07-18 15:02:59,857 INFO 2024-07-18 15:02:59,857 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 15:02:59,857 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:03:00,164 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:03:00,164 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:00,164 DEBUG --- stdout --- 2024-07-18 15:03:00,164 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:03:00,164 DEBUG --- stderr --- 2024-07-18 15:03:00,164 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 15:03:00,164 INFO 2024-07-18 15:03:00,165 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 15:03:00,165 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:03:00,465 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:03:00,465 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:00,465 DEBUG --- stdout --- 2024-07-18 15:03:00,465 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:03:00,466 DEBUG --- stderr --- 2024-07-18 15:03:00,466 DEBUG 2024-07-18 15:03:00,466 INFO 2024-07-18 15:03:00,466 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-170/cmd.txt" ]; then echo "/results/orders/benchmark-170/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-170/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-170/cmd.txt file found" 2024-07-18 15:03:00,466 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 15:03:01,274 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 15:03:01,275 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:01,275 DEBUG --- stdout --- 2024-07-18 15:03:01,275 DEBUG /results/orders/benchmark-170/cmd.txt file found 2024-07-18 15:03:01,275 DEBUG --- stderr --- 2024-07-18 15:03:01,275 DEBUG 2024-07-18 15:03:01,275 INFO 2024-07-18 15:03:01,275 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 15:03:01,275 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:03:01,578 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:03:01,578 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:01,578 DEBUG --- stdout --- 2024-07-18 15:03:01,579 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:03:01,579 DEBUG --- stderr --- 2024-07-18 15:03:01,579 DEBUG 2024-07-18 15:03:01,579 INFO 2024-07-18 15:03:01,579 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-170/cmd.txt 2024-07-18 15:03:02,385 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 15:03:02,386 DEBUG --- stdout --- 2024-07-18 15:03:02,386 DEBUG 4 /results/orders/benchmark-170/cmd.txt 2024-07-18 15:03:02,386 DEBUG --- stderr --- 2024-07-18 15:03:02,386 DEBUG 2024-07-18 15:03:02,386 INFO - Download file (size 4k) 2024-07-18 15:03:02,387 INFO 2024-07-18 15:03:02,387 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 15:03:02,387 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:03:02,708 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:03:02,708 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:02,708 DEBUG --- stdout --- 2024-07-18 15:03:02,709 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:03:02,709 DEBUG --- stderr --- 2024-07-18 15:03:02,709 DEBUG source : /results/orders/benchmark-170/cmd.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/cmd.txt 2024-07-18 15:03:02,709 INFO 2024-07-18 15:03:02,709 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 15:03:02,709 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 15:03:03,014 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 15:03:03,014 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:03,014 DEBUG --- stdout --- 2024-07-18 15:03:03,014 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 15:03:03,014 DEBUG --- stderr --- 2024-07-18 15:03:03,014 DEBUG 2024-07-18 15:03:03,015 INFO 2024-07-18 15:03:03,015 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-170/cmd.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/cmd.txt 2024-07-18 15:03:03,015 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 15:03:03,793 INFO [loop_until]: OK (rc = 0) 2024-07-18 15:03:03,793 DEBUG --- stdout --- 2024-07-18 15:03:03,793 DEBUG tar: Removing leading `/' from member names 2024-07-18 15:03:03,793 DEBUG --- stderr --- 2024-07-18 15:03:03,793 DEBUG 2024-07-18 15:03:03,794 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/cmd.txt is small (1 lines), printing all lines: 2024-07-18 15:03:03,794 DEBUG ----- output ----- 2024-07-18 15:03:03,794 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-170 --extra-run-jvm-options "-Xmx4G" --no-reports 2024-07-18 15:03:03,794 INFO ________________________________________________________________________________ [2024-07-18 15:03:03] benchmark-170 show_rc : Display rc order ________________________________________________________________________________ 2024-07-18 15:03:03,794 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/rc.txt is small (1 lines), printing all lines: 2024-07-18 15:03:03,794 DEBUG ----- output ----- 2024-07-18 15:03:03,794 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-07-18 15:03:03,794 INFO ________________________________________________________________________________ [2024-07-18 15:03:03] benchmark-170 show_stdout : Display stdout order ________________________________________________________________________________ 2024-07-18 15:03:03,803 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/09_benchmark-170/stdout.txt is 54742 lines): 2024-07-18 15:03:03,803 DEBUG ----- output ----- 2024-07-18 15:03:03,803 INFO GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling 2024-07-18 15:03:03,803 INFO Gatling 3.11.5 is available! (you're using 3.9.5) 2024-07-18 15:03:03,803 INFO Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 15:03:03,804 INFO 2024-07-18 15:03:03,804 INFO ================================================================================ 2024-07-18 15:03:03,804 INFO 2024-07-18 15:00:37 5s elapsed 2024-07-18 15:03:03,804 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 15:03:03,804 INFO > Global (OK=443 KO=0 ) 2024-07-18 15:03:03,804 INFO > restLoginInitiate (OK=56 KO=0 ) 2024-07-18 15:03:03,804 INFO > restLoginUsernamePasswordCallback (OK=53 KO=0 ) 2024-07-18 15:03:03,804 INFO > Skip 2FA (OK=43 KO=0 ) 2024-07-18 15:03:03,804 INFO > User Authorize PKCE stage (OK=54 KO=0 ) 2024-07-18 15:03:03,804 INFO > User AccessToken PKCE stage (OK=52 KO=0 ) 2024-07-18 15:03:03,804 INFO > RootUserinfo (OK=75 KO=0 ) 2024-07-18 15:03:03,804 INFO > registration_restLoginInitiate (OK=14 KO=0 ) 2024-07-18 15:03:03,804 INFO > registrationCallback (OK=13 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI-Post-Login (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI-Post-Login Redirect 1 (OK=6 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI AM idFromSession (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI AM validateGoto (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI Enduser appAuthHelper1 (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI Enduser appAuthHelper2 (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > getIdToken (OK=7 KO=0 ) 2024-07-18 15:03:03,804 INFO > getIdToken Redirect 1 (OK=7 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM uiconfig (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI Enduser sessioncheck (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM version (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM features (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM privilege (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM login (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > createOrganization (OK=5 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM alpha_user (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM user (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM dashboard (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > queryOrganization (OK=5 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI IDM oidcToken (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > deleteOrganization (OK=5 KO=0 ) 2024-07-18 15:03:03,804 INFO > userinfo (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI-Logout Redirect 1 (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > tokenUserinfo (OK=7 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI AM revoke2 (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI AM revoke1 (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > UI AM endsession (OK=2 KO=0 ) 2024-07-18 15:03:03,804 INFO > restloginProgressiveProfileCallback (OK=1 KO=0 ) 2024-07-18 15:03:03,805 INFO 2024-07-18 15:03:03,805 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 15:03:03,805 INFO [- ] 0% 2024-07-18 15:03:03,805 INFO waiting: 615702 / active: 43 / done: 28 2024-07-18 15:03:03,805 INFO ================================================================================ 2024-07-18 15:03:03,805 INFO 2024-07-18 15:03:03,805 INFO 15:00:39.760 [ERROR] i.g.h.a.HttpRequestAction - 'tokenUserinfo' failed to execute: No attribute named 'access_token' is defined 2024-07-18 15:03:03,805 INFO 15:00:39.792 [ERROR] i.g.h.a.HttpRequestAction - 'tokenUserinfo' failed to execute: No attribute named 'access_token' is defined 2024-07-18 15:03:03,805 INFO 15:00:39.810 [ERROR] i.g.h.a.HttpRequestAction - 'tokenUserinfo' failed to execute: No attribute named 'access_token' is defined 2024-07-18 15:03:03,805 INFO 15:00:41.927 [ERROR] i.g.h.a.HttpRequestAction - 'tokenUserinfo' failed to execute: No attribute named 'access_token' is defined 2024-07-18 15:03:03,805 INFO 15:00:42.908 [ERROR] i.g.h.a.HttpRequestAction - 'tokenUserinfo' failed to execute: No attribute named 'access_token' is defined 2024-07-18 15:03:03,805 INFO 2024-07-18 15:03:03,805 INFO ================================================================================ 2024-07-18 15:03:03,805 INFO 2024-07-18 15:00:42 10s elapsed 2024-07-18 15:03:03,805 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 15:03:03,805 INFO > Global (OK=2014 KO=0 ) 2024-07-18 15:03:03,805 INFO > restLoginInitiate (OK=239 KO=0 ) 2024-07-18 15:03:03,805 INFO > restLoginUsernamePasswordCallback (OK=235 KO=0 ) 2024-07-18 15:03:03,805 INFO > Skip 2FA (OK=164 KO=0 ) 2024-07-18 15:03:03,805 INFO > User Authorize PKCE stage (OK=234 KO=0 ) 2024-07-18 15:03:03,805 INFO > User AccessToken PKCE stage (OK=229 KO=0 ) 2024-07-18 15:03:03,805 INFO > RootUserinfo (OK=445 KO=0 ) 2024-07-18 15:03:03,805 INFO > registration_restLoginInitiate (OK=43 KO=0 ) 2024-07-18 15:03:03,805 INFO > registrationCallback (OK=42 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI-Post-Login (OK=9 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI-Post-Login Redirect 1 (OK=25 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI AM idFromSession (OK=9 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI AM validateGoto (OK=9 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI Enduser appAuthHelper1 (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI Enduser appAuthHelper2 (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > getIdToken (OK=29 KO=0 ) 2024-07-18 15:03:03,805 INFO > getIdToken Redirect 1 (OK=29 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM uiconfig (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI Enduser sessioncheck (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM version (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM features (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM privilege (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM login (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > createOrganization (OK=28 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM alpha_user (OK=8 KO=0 ) 2024-07-18 15:03:03,805 INFO > UI IDM user (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > UI IDM dashboard (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > queryOrganization (OK=27 KO=0 ) 2024-07-18 15:03:03,806 INFO > UI IDM oidcToken (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > deleteOrganization (OK=27 KO=0 ) 2024-07-18 15:03:03,806 INFO > userinfo (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > UI-Logout Redirect 1 (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > tokenUserinfo (OK=54 KO=0 ) 2024-07-18 15:03:03,806 INFO > UI AM revoke2 (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > UI AM revoke1 (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > UI AM endsession (OK=8 KO=0 ) 2024-07-18 15:03:03,806 INFO > restloginProgressiveProfileCallback (OK=1 KO=0 ) 2024-07-18 15:03:03,806 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 15:03:03,806 INFO > tokenUserinfo: Failed to build request: No attribute named 'ac 5 (100.0%) 2024-07-18 15:03:03,806 INFO cess_token' is defined 2024-07-18 15:03:03,806 INFO 2024-07-18 15:03:03,806 INFO [...] 2024-07-18 15:03:03,820 INFO > headerRegex((Location,(?<=code=)(.+?)(?=&))).find.exists, foun 2 ( 0.02%) 2024-07-18 15:03:03,821 INFO d nothing 2024-07-18 15:03:03,821 INFO > status.find.is(200), but actually found 502 1 ( 0.01%) 2024-07-18 15:03:03,821 INFO > userinfo: Failed to build request: No attribute named 'access_ 1 ( 0.01%) 2024-07-18 15:03:03,821 INFO token' is defined 2024-07-18 15:03:03,821 INFO > UI AM revoke1: Failed to build request: No attribute named 'a 1 ( 0.01%) 2024-07-18 15:03:03,821 INFO ccess_token' is defined 2024-07-18 15:03:03,821 INFO 2024-07-18 15:03:03,821 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 15:03:03,821 INFO [#########################################################################-] 99% 2024-07-18 15:03:03,821 INFO waiting: 0 / active: 77 / done: 615696 2024-07-18 15:03:03,821 INFO ================================================================================ 2024-07-18 15:03:03,821 INFO 2024-07-18 15:03:03,821 INFO 2024-07-18 15:03:03,821 INFO ================================================================================ 2024-07-18 15:03:03,821 INFO 2024-07-18 16:01:11 3638s elapsed 2024-07-18 15:03:03,821 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 15:03:03,821 INFO > Global (OK=5188448 KO=27 ) 2024-07-18 15:03:03,821 INFO > restLoginInitiate (OK=516611 KO=0 ) 2024-07-18 15:03:03,821 INFO > restLoginUsernamePasswordCallback (OK=516611 KO=0 ) 2024-07-18 15:03:03,821 INFO > Skip 2FA (OK=369121 KO=1 ) 2024-07-18 15:03:03,821 INFO > User Authorize PKCE stage (OK=528584 KO=6 ) 2024-07-18 15:03:03,821 INFO > User AccessToken PKCE stage (OK=528577 KO=7 ) 2024-07-18 15:03:03,821 INFO > RootUserinfo (OK=1477562 KO=13 ) 2024-07-18 15:03:03,821 INFO > registration_restLoginInitiate (OK=99162 KO=0 ) 2024-07-18 15:03:03,821 INFO > registrationCallback (OK=99162 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI-Post-Login (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI-Post-Login Redirect 1 (OK=74706 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI AM idFromSession (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI AM validateGoto (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI Enduser appAuthHelper1 (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI Enduser appAuthHelper2 (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > getIdToken (OK=73598 KO=0 ) 2024-07-18 15:03:03,821 INFO > getIdToken Redirect 1 (OK=73598 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI IDM uiconfig (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI Enduser sessioncheck (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI IDM version (OK=24902 KO=0 ) 2024-07-18 15:03:03,821 INFO > UI IDM features (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI IDM privilege (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI IDM login (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > createOrganization (OK=73595 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI IDM alpha_user (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI IDM user (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI IDM dashboard (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > queryOrganization (OK=73595 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI IDM oidcToken (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > deleteOrganization (OK=73595 KO=0 ) 2024-07-18 15:03:03,822 INFO > userinfo (OK=24901 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI-Logout Redirect 1 (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > tokenUserinfo (OK=109664 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI AM revoke2 (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI AM revoke1 (OK=24901 KO=0 ) 2024-07-18 15:03:03,822 INFO > UI AM endsession (OK=24902 KO=0 ) 2024-07-18 15:03:03,822 INFO > restloginProgressiveProfileCallback (OK=2669 KO=0 ) 2024-07-18 15:03:03,822 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 15:03:03,822 INFO > tokenUserinfo: Failed to build request: No attribute named 'ac 12923 (99.36%) 2024-07-18 15:03:03,822 INFO cess_token' is defined 2024-07-18 15:03:03,822 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 45 ( 0.35%) 2024-07-18 15:03:03,822 INFO ess_token' is defined 2024-07-18 15:03:03,822 INFO > status.find.in([200, 209], 304), found 500 18 ( 0.14%) 2024-07-18 15:03:03,822 INFO > status.find.is(302), but actually found 502 4 ( 0.03%) 2024-07-18 15:03:03,822 INFO > createOrganization: Failed to build request: No attribute name 3 ( 0.02%) 2024-07-18 15:03:03,822 INFO d 'access_token' is defined 2024-07-18 15:03:03,822 INFO > queryOrganization: Failed to build request: No attribute named 3 ( 0.02%) 2024-07-18 15:03:03,822 INFO 'organization_id' is defined 2024-07-18 15:03:03,822 INFO > deleteOrganization: Failed to build request: No attribute name 3 ( 0.02%) 2024-07-18 15:03:03,822 INFO d 'organization_id' is defined 2024-07-18 15:03:03,822 INFO > status.find.in([200, 209], 304), found 502 2 ( 0.02%) 2024-07-18 15:03:03,822 INFO > headerRegex((Location,(?<=code=)(.+?)(?=&))).find.exists, foun 2 ( 0.02%) 2024-07-18 15:03:03,822 INFO d nothing 2024-07-18 15:03:03,822 INFO > status.find.is(200), but actually found 502 1 ( 0.01%) 2024-07-18 15:03:03,822 INFO > userinfo: Failed to build request: No attribute named 'access_ 1 ( 0.01%) 2024-07-18 15:03:03,822 INFO token' is defined 2024-07-18 15:03:03,822 INFO > UI AM revoke1: Failed to build request: No attribute named 'a 1 ( 0.01%) 2024-07-18 15:03:03,822 INFO ccess_token' is defined 2024-07-18 15:03:03,822 INFO 2024-07-18 15:03:03,823 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 15:03:03,823 INFO [##########################################################################]100% 2024-07-18 15:03:03,823 INFO waiting: 0 / active: 0 / done: 615773 2024-07-18 15:03:03,823 INFO ================================================================================ 2024-07-18 15:03:03,823 INFO 2024-07-18 15:03:03,823 INFO Simulation com.forgerock.gatling.Loadtest completed in 3638 seconds 2024-07-18 15:03:03,823 INFO 2024-07-18 15:03:03,823 INFO ---------------------- 2024-07-18 15:03:03,823 INFO [18/Jul/2024 16:01:11] Create tar file benchmark-170.tar.gz 2024-07-18 15:03:03,823 INFO ---------------------- 2024-07-18 15:03:03,823 INFO RESULTS_FOLDER=/results/gatling/ 2024-07-18 15:03:03,823 INFO RESULT_FOLDER=benchmark-170 2024-07-18 15:03:03,823 INFO SIMULATION_PATH=benchmark-170/loadtest-20240718140032333 2024-07-18 15:03:03,823 INFO PWD=/results/gatling/benchmark-170/loadtest-20240718140032333 2024-07-18 15:03:03,823 INFO [cmd] tar -czvf /results/gatling//benchmark-170.tar.gz --exclude=simulation.log * 2024-07-18 15:03:03,823 INFO /results/gatling 2024-07-18 15:03:03,823 INFO 2024-07-18 15:03:03,823 INFO ---------------------- 2024-07-18 15:03:03,823 INFO [18/Jul/2024 16:01:11] Update /results/gatling//latest 2024-07-18 15:03:03,823 INFO ---------------------- 2024-07-18 15:03:03,823 INFO 2024-07-18 15:03:03,823 INFO ---------------------- 2024-07-18 15:03:03,823 INFO [18/Jul/2024 16:01:11] Update /results/gatling//latest.tar.gz 2024-07-18 15:03:03,823 INFO ---------------------- 2024-07-18 15:03:03,823 INFO ________________________________________________________________________________ [2024-07-18 15:03:03] benchmark-170 show_stderr : Display stderr order ________________________________________________________________________________ 2024-07-18 15:03:03,824 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/09_benchmark-170/stderr.txt is small (0 lines), printing all lines: 2024-07-18 15:03:03,824 DEBUG ----- output ----- 2024-07-18 15:03:03,824 DEBUG 2024-07-18 15:03:03,824 INFO ________________________________________________________________________________ [2024-07-18 15:03:03] benchmark-170 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 15:03:03] benchmark-170 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-07-18 15:03:03] benchmark-170 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped