--Task-- name: benchmark-10 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: [] preceding_task: None options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self10-', 'testCase': 'idc.benchmark.CH2023', 'testMode': 'open', 'throughput': 10} group_name: None Current dir: /mnt/disks/data/xslou/lodestar-fork/pyrock ________________________________________________________________________________ [2024-07-18 05:39:06] benchmark-10 pre : N/A ________________________________________________________________________________ 2024-07-18 05:39:06 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-07-18 05:39:06 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-10/stdout.txt Pod log : /results/orders/benchmark-10 2024-07-18 05:39:06,348 INFO 2024-07-18 05:39:06,348 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 05:39:06,348 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 05:39:06,668 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 05:39:06,668 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:06,668 DEBUG --- stdout --- 2024-07-18 05:39:06,668 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 05:39:06,668 DEBUG --- stderr --- 2024-07-18 05:39:06,669 DEBUG 2024-07-18 05:39:06 - INFO: Get overseer pod resources requests memory 2024-07-18 05:39:06,669 INFO 2024-07-18 05:39:06,669 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods overseer-0-7796fc5d9b-ngsxg --output jsonpath={.spec.containers[].resources.requests.memory} 2024-07-18 05:39:06,669 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 05:39:07,000 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:07,000 DEBUG --- stdout --- 2024-07-18 05:39:07,000 DEBUG 4Gi 2024-07-18 05:39:07,000 DEBUG --- stderr --- 2024-07-18 05:39:07,000 DEBUG ________________________________________________________________________________ [2024-07-18 05:39:07] benchmark-10 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-07-18 05:39:07,001 INFO 2024-07-18 05:39:07,001 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 05:39:07,001 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 05:39:07,313 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 05:39:07,314 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:07,314 DEBUG --- stdout --- 2024-07-18 05:39:07,314 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 05:39:07,314 DEBUG --- stderr --- 2024-07-18 05:39:07,314 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-10 --extra-run-jvm-options "-Xmx4G" --no-reports ________________________________________________________________________________ [2024-07-18 05:39:07] benchmark-10 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-07-18 05:39:07,314 INFO 2024-07-18 05:39:07,315 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 05:39:07,315 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 05:39:07,624 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 05:39:07,625 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:07,625 DEBUG --- stdout --- 2024-07-18 05:39:07,625 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 05:39:07,625 DEBUG --- stderr --- 2024-07-18 05:39:07,625 DEBUG Order file: /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/order.json { "name": "benchmark-10", "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-10 --extra-run-jvm-options \"-Xmx4G\" --no-reports", "out-dir": "/results/orders/benchmark-10", "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=self10- -Drealm=alpha -DtestCase=idc.benchmark.CH2023 -DtestMode=open -Dthroughput=10 -Duser_password=Pa_ssw0rd" } } ________________________________________________________________________________ [2024-07-18 05:39:07] benchmark-10 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 05:39:07,631 INFO 2024-07-18 05:39:07,631 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-07-18 05:39:07,631 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 05:39:07,924 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 05:39:07,924 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:07,924 DEBUG --- stdout --- 2024-07-18 05:39:07,924 DEBUG WAITING 2024-07-18 05:39:07,924 DEBUG --- stderr --- 2024-07-18 05:39:07,924 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 27 0 --:--:-- --:--:-- --:--:-- 27 ________________________________________________________________________________ [2024-07-18 05:39:07] benchmark-10 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-07-18 05:39:07,925 INFO 2024-07-18 05:39:07,925 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 05:39:07,925 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 05:39:08,227 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 05:39:08,227 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:08,227 DEBUG --- stdout --- 2024-07-18 05:39:08,227 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 05:39:08,227 DEBUG --- stderr --- 2024-07-18 05:39:08,227 DEBUG 2024-07-18 05:39:08,227 INFO 2024-07-18 05:39:08,227 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/01_benchmark-10/order.json overseer-0-7796fc5d9b-ngsxg:/results/orders/order.json 2024-07-18 05:39:08,227 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 05:39:09,607 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:09,607 DEBUG --- stdout --- 2024-07-18 05:39:09,607 DEBUG 2024-07-18 05:39:09,607 DEBUG --- stderr --- 2024-07-18 05:39:09,607 DEBUG Order has been successfully forwarded to overseer 2024-07-18 05:39:09 - INFO: Check if Gatling simulation started successfully 2024-07-18 05:39:09,608 INFO 2024-07-18 05:39:09,608 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 05:39:09,608 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 05:39:09,924 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 05:39:09,925 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:09,925 DEBUG --- stdout --- 2024-07-18 05:39:09,925 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 05:39:09,925 DEBUG --- stderr --- 2024-07-18 05:39:09,925 DEBUG 2024-07-18 05:39:09,925 INFO 2024-07-18 05:39:09,925 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-10/stdout.txt | grep "started..." 2024-07-18 05:39:09,925 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-07-18 05:39:10,678 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: started... - retry 2024-07-18 05:39:16,421 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: started... - retry 2024-07-18 05:39:22,180 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-07-18 05:39:22,180 INFO [loop_until]: OK (rc = 0) 2024-07-18 05:39:22,180 DEBUG --- stdout --- 2024-07-18 05:39:22,180 DEBUG GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling 06:39:11.793 [WARN ] i.g.c.ZincCompiler$ - -target is deprecated: Use -release instead to compile against the correct platform API. 06:39:15.642 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:122:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map crossSessionVariables.-("poliEvalTokenId"); ^ 06:39:15.646 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:225:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map crossSessionVariables.-("poliEvalTokenId"); ^ 06:39:17.256 [WARN ] i.g.c.ZincCompiler$ - three warnings found Gatling 3.11.5 is available! (you're using 3.9.5) Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 05:39:22,180 DEBUG --- stderr --- 2024-07-18 05:39:22,180 DEBUG ________________________________________________________________________________ [2024-07-18 05:39:22] benchmark-10 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 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 05s, 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 07s, retry Order is running since 50m 08s, retry Order is running since 52m 08s, retry Order is running since 54m 08s, retry Order is running since 56m 09s, retry Order is running since 58m 09s, retry Order is running since 1h, retry PASS : Order stopped by itself after 1h 02m and before timeout (1h 12m) ________________________________________________________________________________ [2024-07-18 06:41:32] benchmark-10 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-07-18 06:41:32,576 INFO 2024-07-18 06:41:32,577 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:32,577 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:32,900 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:32,900 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:32,900 DEBUG --- stdout --- 2024-07-18 06:41:32,900 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:32,900 DEBUG --- stderr --- 2024-07-18 06:41:32,900 DEBUG 2024-07-18 06:41:32,900 INFO 2024-07-18 06:41:32,901 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 06:41:32,901 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 06:41:33,677 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:33,678 DEBUG --- stdout --- 2024-07-18 06:41:33,678 DEBUG 2024-07-18 06:41:33,678 DEBUG --- stderr --- 2024-07-18 06:41:33,678 DEBUG Order ran during 1h 02m ________________________________________________________________________________ [2024-07-18 06:41:33] benchmark-10 download_logs : Download individual order files ________________________________________________________________________________ 2024-07-18 06:41:33 - PASS: file already downloaded /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/order.json 2024-07-18 06:41:33,680 INFO 2024-07-18 06:41:33,681 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:33,681 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:34,008 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:34,008 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:34,008 DEBUG --- stdout --- 2024-07-18 06:41:34,008 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:34,008 DEBUG --- stderr --- 2024-07-18 06:41:34,008 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 06:41:34,009 INFO 2024-07-18 06:41:34,009 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:34,009 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:34,324 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:34,325 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:34,325 DEBUG --- stdout --- 2024-07-18 06:41:34,325 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:34,325 DEBUG --- stderr --- 2024-07-18 06:41:34,325 DEBUG 2024-07-18 06:41:34,325 INFO 2024-07-18 06:41:34,326 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-10/rc.txt" ]; then echo "/results/orders/benchmark-10/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-10/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/rc.txt file found" 2024-07-18 06:41:34,326 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 06:41:35,137 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 06:41:35,137 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:35,137 DEBUG --- stdout --- 2024-07-18 06:41:35,137 DEBUG /results/orders/benchmark-10/rc.txt file found 2024-07-18 06:41:35,137 DEBUG --- stderr --- 2024-07-18 06:41:35,138 DEBUG 2024-07-18 06:41:35,138 INFO 2024-07-18 06:41:35,138 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:35,138 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:35,440 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:35,440 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:35,440 DEBUG --- stdout --- 2024-07-18 06:41:35,440 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:35,440 DEBUG --- stderr --- 2024-07-18 06:41:35,440 DEBUG 2024-07-18 06:41:35,441 INFO 2024-07-18 06:41:35,441 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-10/rc.txt 2024-07-18 06:41:36,271 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 06:41:36,271 DEBUG --- stdout --- 2024-07-18 06:41:36,271 DEBUG 4 /results/orders/benchmark-10/rc.txt 2024-07-18 06:41:36,271 DEBUG --- stderr --- 2024-07-18 06:41:36,271 DEBUG 2024-07-18 06:41:36,271 INFO - Download file (size 4k) 2024-07-18 06:41:36,272 INFO 2024-07-18 06:41:36,272 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:36,272 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:36,577 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:36,577 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:36,578 DEBUG --- stdout --- 2024-07-18 06:41:36,578 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:36,578 DEBUG --- stderr --- 2024-07-18 06:41:36,578 DEBUG source : /results/orders/benchmark-10/rc.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/rc.txt 2024-07-18 06:41:36,578 INFO 2024-07-18 06:41:36,578 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:36,578 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:36,886 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:36,886 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:36,886 DEBUG --- stdout --- 2024-07-18 06:41:36,886 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:36,886 DEBUG --- stderr --- 2024-07-18 06:41:36,886 DEBUG 2024-07-18 06:41:36,887 INFO 2024-07-18 06:41:36,887 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-10/rc.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/rc.txt 2024-07-18 06:41:36,887 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 06:41:37,646 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:37,646 DEBUG --- stdout --- 2024-07-18 06:41:37,646 DEBUG tar: Removing leading `/' from member names 2024-07-18 06:41:37,646 DEBUG --- stderr --- 2024-07-18 06:41:37,646 DEBUG 2024-07-18 06:41:37,647 INFO 2024-07-18 06:41:37,647 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:37,647 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:37,949 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:37,950 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:37,950 DEBUG --- stdout --- 2024-07-18 06:41:37,950 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:37,950 DEBUG --- stderr --- 2024-07-18 06:41:37,950 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 06:41:37,950 INFO 2024-07-18 06:41:37,950 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:37,950 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:38,255 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:38,255 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:38,256 DEBUG --- stdout --- 2024-07-18 06:41:38,256 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:38,256 DEBUG --- stderr --- 2024-07-18 06:41:38,256 DEBUG 2024-07-18 06:41:38,256 INFO 2024-07-18 06:41:38,256 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-10/stderr.txt" ]; then echo "/results/orders/benchmark-10/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-10/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/stderr.txt file found" 2024-07-18 06:41:38,256 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 06:41:39,057 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 06:41:39,057 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:39,057 DEBUG --- stdout --- 2024-07-18 06:41:39,057 DEBUG /results/orders/benchmark-10/stderr.txt file found 2024-07-18 06:41:39,058 DEBUG --- stderr --- 2024-07-18 06:41:39,058 DEBUG 2024-07-18 06:41:39,058 INFO 2024-07-18 06:41:39,058 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:39,058 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:39,362 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:39,362 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:39,362 DEBUG --- stdout --- 2024-07-18 06:41:39,362 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:39,362 DEBUG --- stderr --- 2024-07-18 06:41:39,362 DEBUG 2024-07-18 06:41:39,362 INFO 2024-07-18 06:41:39,363 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-10/stderr.txt 2024-07-18 06:41:40,165 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 06:41:40,166 DEBUG --- stdout --- 2024-07-18 06:41:40,166 DEBUG 0 /results/orders/benchmark-10/stderr.txt 2024-07-18 06:41:40,166 DEBUG --- stderr --- 2024-07-18 06:41:40,166 DEBUG 2024-07-18 06:41:40,166 INFO - Download file (size 0k) 2024-07-18 06:41:40,166 INFO 2024-07-18 06:41:40,166 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:40,166 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:40,468 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:40,468 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:40,468 DEBUG --- stdout --- 2024-07-18 06:41:40,468 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:40,468 DEBUG --- stderr --- 2024-07-18 06:41:40,468 DEBUG source : /results/orders/benchmark-10/stderr.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/stderr.txt 2024-07-18 06:41:40,468 INFO 2024-07-18 06:41:40,468 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:40,468 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:40,777 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:40,777 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:40,777 DEBUG --- stdout --- 2024-07-18 06:41:40,777 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:40,777 DEBUG --- stderr --- 2024-07-18 06:41:40,777 DEBUG 2024-07-18 06:41:40,778 INFO 2024-07-18 06:41:40,778 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-10/stderr.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/stderr.txt 2024-07-18 06:41:40,778 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 06:41:41,562 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:41,562 DEBUG --- stdout --- 2024-07-18 06:41:41,562 DEBUG tar: Removing leading `/' from member names 2024-07-18 06:41:41,562 DEBUG --- stderr --- 2024-07-18 06:41:41,562 DEBUG 2024-07-18 06:41:41,563 INFO 2024-07-18 06:41:41,563 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:41,563 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:41,869 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:41,869 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:41,869 DEBUG --- stdout --- 2024-07-18 06:41:41,870 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:41,870 DEBUG --- stderr --- 2024-07-18 06:41:41,870 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 06:41:41,870 INFO 2024-07-18 06:41:41,870 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:41,870 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:42,172 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:42,173 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:42,173 DEBUG --- stdout --- 2024-07-18 06:41:42,173 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:42,173 DEBUG --- stderr --- 2024-07-18 06:41:42,173 DEBUG 2024-07-18 06:41:42,173 INFO 2024-07-18 06:41:42,173 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-10/stdout.txt" ]; then echo "/results/orders/benchmark-10/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-10/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/stdout.txt file found" 2024-07-18 06:41:42,173 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 06:41:42,974 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 06:41:42,974 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:42,975 DEBUG --- stdout --- 2024-07-18 06:41:42,975 DEBUG /results/orders/benchmark-10/stdout.txt file found 2024-07-18 06:41:42,975 DEBUG --- stderr --- 2024-07-18 06:41:42,976 DEBUG 2024-07-18 06:41:42,976 INFO 2024-07-18 06:41:42,976 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:42,976 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:43,277 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:43,278 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:43,278 DEBUG --- stdout --- 2024-07-18 06:41:43,278 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:43,278 DEBUG --- stderr --- 2024-07-18 06:41:43,278 DEBUG 2024-07-18 06:41:43,278 INFO 2024-07-18 06:41:43,278 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-10/stdout.txt 2024-07-18 06:41:44,079 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 06:41:44,080 DEBUG --- stdout --- 2024-07-18 06:41:44,080 DEBUG 2688 /results/orders/benchmark-10/stdout.txt 2024-07-18 06:41:44,080 DEBUG --- stderr --- 2024-07-18 06:41:44,080 DEBUG 2024-07-18 06:41:44,080 INFO - Download file (size 2688k) 2024-07-18 06:41:44,080 INFO 2024-07-18 06:41:44,080 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:44,080 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:44,384 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:44,384 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:44,384 DEBUG --- stdout --- 2024-07-18 06:41:44,384 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:44,384 DEBUG --- stderr --- 2024-07-18 06:41:44,384 DEBUG source : /results/orders/benchmark-10/stdout.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/stdout.txt 2024-07-18 06:41:44,385 INFO 2024-07-18 06:41:44,385 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:44,385 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:44,701 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:44,702 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:44,702 DEBUG --- stdout --- 2024-07-18 06:41:44,702 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:44,702 DEBUG --- stderr --- 2024-07-18 06:41:44,702 DEBUG 2024-07-18 06:41:44,702 INFO 2024-07-18 06:41:44,702 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-10/stdout.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/stdout.txt 2024-07-18 06:41:44,702 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 06:41:45,910 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:45,911 DEBUG --- stdout --- 2024-07-18 06:41:45,911 DEBUG tar: Removing leading `/' from member names 2024-07-18 06:41:45,911 DEBUG --- stderr --- 2024-07-18 06:41:45,911 DEBUG ________________________________________________________________________________ [2024-07-18 06:41:45] benchmark-10 show_cmd : Display order command ________________________________________________________________________________ 2024-07-18 06:41:45,911 INFO 2024-07-18 06:41:45,912 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:45,912 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:46,215 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:46,215 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:46,215 DEBUG --- stdout --- 2024-07-18 06:41:46,215 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:46,215 DEBUG --- stderr --- 2024-07-18 06:41:46,215 DEBUG Checking pod: overseer-0-7796fc5d9b-ngsxg for file exists, if not wait. 2024-07-18 06:41:46,215 INFO 2024-07-18 06:41:46,216 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:46,216 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:46,522 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:46,522 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:46,522 DEBUG --- stdout --- 2024-07-18 06:41:46,522 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:46,522 DEBUG --- stderr --- 2024-07-18 06:41:46,522 DEBUG 2024-07-18 06:41:46,523 INFO 2024-07-18 06:41:46,523 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-10/cmd.txt" ]; then echo "/results/orders/benchmark-10/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-10/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-10/cmd.txt file found" 2024-07-18 06:41:46,523 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-07-18 06:41:47,343 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-07-18 06:41:47,343 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:47,343 DEBUG --- stdout --- 2024-07-18 06:41:47,343 DEBUG /results/orders/benchmark-10/cmd.txt file found 2024-07-18 06:41:47,344 DEBUG --- stderr --- 2024-07-18 06:41:47,344 DEBUG 2024-07-18 06:41:47,344 INFO 2024-07-18 06:41:47,344 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:47,344 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:47,658 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:47,658 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:47,658 DEBUG --- stdout --- 2024-07-18 06:41:47,658 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:47,658 DEBUG --- stderr --- 2024-07-18 06:41:47,659 DEBUG 2024-07-18 06:41:47,659 INFO 2024-07-18 06:41:47,659 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-10/cmd.txt 2024-07-18 06:41:48,528 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-07-18 06:41:48,528 DEBUG --- stdout --- 2024-07-18 06:41:48,528 DEBUG 4 /results/orders/benchmark-10/cmd.txt 2024-07-18 06:41:48,528 DEBUG --- stderr --- 2024-07-18 06:41:48,528 DEBUG 2024-07-18 06:41:48,528 INFO - Download file (size 4k) 2024-07-18 06:41:48,529 INFO 2024-07-18 06:41:48,529 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:48,529 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:48,829 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:48,829 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:48,829 DEBUG --- stdout --- 2024-07-18 06:41:48,829 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:48,829 DEBUG --- stderr --- 2024-07-18 06:41:48,829 DEBUG source : /results/orders/benchmark-10/cmd.txt @ overseer-0-7796fc5d9b-ngsxg destination : /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/cmd.txt 2024-07-18 06:41:48,829 INFO 2024-07-18 06:41:48,829 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-07-18 06:41:48,830 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-07-18 06:41:49,130 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-07-18 06:41:49,130 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:49,130 DEBUG --- stdout --- 2024-07-18 06:41:49,130 DEBUG overseer-0-7796fc5d9b-ngsxg 2024-07-18 06:41:49,130 DEBUG --- stderr --- 2024-07-18 06:41:49,130 DEBUG 2024-07-18 06:41:49,130 INFO 2024-07-18 06:41:49,130 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-7796fc5d9b-ngsxg:/results/orders/benchmark-10/cmd.txt /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/cmd.txt 2024-07-18 06:41:49,131 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-07-18 06:41:49,858 INFO [loop_until]: OK (rc = 0) 2024-07-18 06:41:49,858 DEBUG --- stdout --- 2024-07-18 06:41:49,858 DEBUG tar: Removing leading `/' from member names 2024-07-18 06:41:49,858 DEBUG --- stderr --- 2024-07-18 06:41:49,858 DEBUG 2024-07-18 06:41:49,859 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/cmd.txt is small (1 lines), printing all lines: 2024-07-18 06:41:49,859 DEBUG ----- output ----- 2024-07-18 06:41:49,859 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-10 --extra-run-jvm-options "-Xmx4G" --no-reports 2024-07-18 06:41:49,859 INFO ________________________________________________________________________________ [2024-07-18 06:41:49] benchmark-10 show_rc : Display rc order ________________________________________________________________________________ 2024-07-18 06:41:49,860 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/rc.txt is small (1 lines), printing all lines: 2024-07-18 06:41:49,860 DEBUG ----- output ----- 2024-07-18 06:41:49,860 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-07-18 06:41:49,860 INFO ________________________________________________________________________________ [2024-07-18 06:41:49] benchmark-10 show_stdout : Display stdout order ________________________________________________________________________________ 2024-07-18 06:41:49,865 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/01_benchmark-10/stdout.txt is 37042 lines): 2024-07-18 06:41:49,866 DEBUG ----- output ----- 2024-07-18 06:41:49,866 INFO GATLING_HOME is set to /home/jenkins/lodestar/clients/gatling 2024-07-18 06:41:49,866 INFO 06:39:11.793 [WARN ] i.g.c.ZincCompiler$ - -target is deprecated: Use -release instead to compile against the correct platform API. 2024-07-18 06:41:49,866 INFO 06:39:15.642 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:122:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map 2024-07-18 06:41:49,866 INFO crossSessionVariables.-("poliEvalTokenId"); 2024-07-18 06:41:49,866 INFO ^ 2024-07-18 06:41:49,866 INFO 06:39:15.646 [WARN ] i.g.c.ZincCompiler$ - /lodestar/pyrock/shared/clients/gatling-open/benchmark/Testcase.scala:225:35: method - in trait MapOps is deprecated (since 2.13.0): Use - or remove on an immutable Map 2024-07-18 06:41:49,866 INFO crossSessionVariables.-("poliEvalTokenId"); 2024-07-18 06:41:49,866 INFO ^ 2024-07-18 06:41:49,866 INFO 06:39:17.256 [WARN ] i.g.c.ZincCompiler$ - three warnings found 2024-07-18 06:41:49,866 INFO Gatling 3.11.5 is available! (you're using 3.9.5) 2024-07-18 06:41:49,866 INFO Simulation com.forgerock.gatling.Loadtest started... 2024-07-18 06:41:49,866 INFO 2024-07-18 06:41:49,866 INFO ================================================================================ 2024-07-18 06:41:49,866 INFO 2024-07-18 06:39:24 5s elapsed 2024-07-18 06:41:49,866 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 06:41:49,866 INFO > Global (OK=21 KO=0 ) 2024-07-18 06:41:49,866 INFO > restLoginInitiate (OK=3 KO=0 ) 2024-07-18 06:41:49,866 INFO > restLoginUsernamePasswordCallback (OK=3 KO=0 ) 2024-07-18 06:41:49,866 INFO > Skip 2FA (OK=3 KO=0 ) 2024-07-18 06:41:49,866 INFO > User Authorize PKCE stage (OK=3 KO=0 ) 2024-07-18 06:41:49,866 INFO > User AccessToken PKCE stage (OK=3 KO=0 ) 2024-07-18 06:41:49,866 INFO > RootUserinfo (OK=6 KO=0 ) 2024-07-18 06:41:49,866 INFO 2024-07-18 06:41:49,866 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 06:41:49,866 INFO [- ] 0% 2024-07-18 06:41:49,866 INFO waiting: 36263 / active: 5 / done: 0 2024-07-18 06:41:49,866 INFO ================================================================================ 2024-07-18 06:41:49,866 INFO 2024-07-18 06:41:49,866 INFO 2024-07-18 06:41:49,866 INFO ================================================================================ 2024-07-18 06:41:49,867 INFO 2024-07-18 06:39:29 10s elapsed 2024-07-18 06:41:49,867 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 06:41:49,867 INFO > Global (OK=137 KO=0 ) 2024-07-18 06:41:49,867 INFO > restLoginInitiate (OK=14 KO=0 ) 2024-07-18 06:41:49,867 INFO > restLoginUsernamePasswordCallback (OK=14 KO=0 ) 2024-07-18 06:41:49,867 INFO > Skip 2FA (OK=13 KO=0 ) 2024-07-18 06:41:49,867 INFO > User Authorize PKCE stage (OK=14 KO=0 ) 2024-07-18 06:41:49,867 INFO > User AccessToken PKCE stage (OK=14 KO=0 ) 2024-07-18 06:41:49,867 INFO > RootUserinfo (OK=42 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI-Post-Login (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI-Post-Login Redirect 1 (OK=3 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI AM idFromSession (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI AM validateGoto (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > registration_restLoginInitiate (OK=2 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI Enduser appAuthHelper2 (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI Enduser appAuthHelper1 (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI Enduser sessioncheck (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM uiconfig (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM version (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM login (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM features (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM privilege (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM alpha_user (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM dashboard (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM user (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > registrationCallback (OK=2 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI IDM oidcToken (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > userinfo (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI-Logout Redirect 1 (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI AM revoke2 (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO > UI AM revoke1 (OK=1 KO=0 ) 2024-07-18 06:41:49,867 INFO 2024-07-18 06:41:49,867 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 06:41:49,867 INFO [- ] 0% 2024-07-18 06:41:49,867 INFO waiting: 36251 / active: 12 / done: 5 2024-07-18 06:41:49,867 INFO ================================================================================ 2024-07-18 06:41:49,867 INFO 2024-07-18 06:41:49,867 INFO 2024-07-18 06:41:49,867 INFO ================================================================================ 2024-07-18 06:41:49,868 INFO 2024-07-18 06:39:34 15s elapsed 2024-07-18 06:41:49,868 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 06:41:49,868 INFO > Global (OK=320 KO=0 ) 2024-07-18 06:41:49,868 INFO > restLoginInitiate (OK=31 KO=0 ) 2024-07-18 06:41:49,868 INFO > restLoginUsernamePasswordCallback (OK=31 KO=0 ) 2024-07-18 06:41:49,868 INFO > Skip 2FA (OK=27 KO=0 ) 2024-07-18 06:41:49,868 INFO > User Authorize PKCE stage (OK=32 KO=0 ) 2024-07-18 06:41:49,868 INFO > User AccessToken PKCE stage (OK=32 KO=0 ) 2024-07-18 06:41:49,868 INFO > RootUserinfo (OK=100 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI-Post-Login (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI-Post-Login Redirect 1 (OK=6 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI AM idFromSession (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI AM validateGoto (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > registration_restLoginInitiate (OK=6 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI Enduser appAuthHelper2 (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI Enduser appAuthHelper1 (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI Enduser sessioncheck (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM uiconfig (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM version (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM login (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM features (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM privilege (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM alpha_user (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM dashboard (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM user (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > registrationCallback (OK=6 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI IDM oidcToken (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > userinfo (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI-Logout Redirect 1 (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI AM revoke2 (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO > UI AM revoke1 (OK=2 KO=0 ) 2024-07-18 06:41:49,868 INFO [...] 2024-07-18 06:41:49,878 INFO > UI IDM dashboard (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > UI IDM user (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > registrationCallback (OK=5779 KO=0 ) 2024-07-18 06:41:49,878 INFO > UI IDM oidcToken (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > userinfo (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > UI-Logout Redirect 1 (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > UI AM revoke2 (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > UI AM revoke1 (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > UI AM endsession (OK=1489 KO=0 ) 2024-07-18 06:41:49,878 INFO > getIdToken (OK=4269 KO=0 ) 2024-07-18 06:41:49,878 INFO > getIdToken Redirect 1 (OK=4269 KO=0 ) 2024-07-18 06:41:49,878 INFO > createOrganization (OK=4269 KO=0 ) 2024-07-18 06:41:49,878 INFO > queryOrganization (OK=4269 KO=0 ) 2024-07-18 06:41:49,878 INFO > deleteOrganization (OK=4269 KO=0 ) 2024-07-18 06:41:49,878 INFO > tokenUserinfo (OK=7318 KO=0 ) 2024-07-18 06:41:49,878 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 06:41:49,878 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 5 (62.50%) 2024-07-18 06:41:49,878 INFO ess_token' is defined 2024-07-18 06:41:49,878 INFO > status.find.is(302), but actually found 502 1 (12.50%) 2024-07-18 06:41:49,878 INFO > status.find.is(200), but actually found 502 1 (12.50%) 2024-07-18 06:41:49,879 INFO > registrationCallback: Failed to build request: No attribute na 1 (12.50%) 2024-07-18 06:41:49,879 INFO med 'callbacks' is defined 2024-07-18 06:41:49,879 INFO 2024-07-18 06:41:49,879 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 06:41:49,879 INFO [#########################################################################-] 99% 2024-07-18 06:41:49,879 INFO waiting: 0 / active: 2 / done: 36266 2024-07-18 06:41:49,879 INFO ================================================================================ 2024-07-18 06:41:49,879 INFO 2024-07-18 06:41:49,879 INFO 2024-07-18 06:41:49,879 INFO ================================================================================ 2024-07-18 06:41:49,879 INFO 2024-07-18 07:39:55 3635s elapsed 2024-07-18 06:41:49,879 INFO ---- Requests ------------------------------------------------------------------ 2024-07-18 06:41:49,879 INFO > Global (OK=308132 KO=2 ) 2024-07-18 06:41:49,879 INFO > restLoginInitiate (OK=30488 KO=0 ) 2024-07-18 06:41:49,879 INFO > restLoginUsernamePasswordCallback (OK=30488 KO=0 ) 2024-07-18 06:41:49,879 INFO > Skip 2FA (OK=21681 KO=0 ) 2024-07-18 06:41:49,879 INFO > User Authorize PKCE stage (OK=31976 KO=1 ) 2024-07-18 06:41:49,879 INFO > User AccessToken PKCE stage (OK=31976 KO=0 ) 2024-07-18 06:41:49,879 INFO > RootUserinfo (OK=87055 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI-Post-Login (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI-Post-Login Redirect 1 (OK=4467 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI AM idFromSession (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI AM validateGoto (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > registration_restLoginInitiate (OK=5779 KO=1 ) 2024-07-18 06:41:49,879 INFO > UI Enduser appAuthHelper2 (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI Enduser appAuthHelper1 (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI Enduser sessioncheck (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM uiconfig (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM version (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM login (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM features (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM privilege (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM alpha_user (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM dashboard (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM user (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > registrationCallback (OK=5779 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI IDM oidcToken (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > userinfo (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI-Logout Redirect 1 (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI AM revoke2 (OK=1489 KO=0 ) 2024-07-18 06:41:49,879 INFO > UI AM revoke1 (OK=1489 KO=0 ) 2024-07-18 06:41:49,880 INFO > UI AM endsession (OK=1489 KO=0 ) 2024-07-18 06:41:49,880 INFO > getIdToken (OK=4269 KO=0 ) 2024-07-18 06:41:49,880 INFO > getIdToken Redirect 1 (OK=4269 KO=0 ) 2024-07-18 06:41:49,880 INFO > createOrganization (OK=4269 KO=0 ) 2024-07-18 06:41:49,880 INFO > queryOrganization (OK=4269 KO=0 ) 2024-07-18 06:41:49,880 INFO > deleteOrganization (OK=4269 KO=0 ) 2024-07-18 06:41:49,880 INFO > tokenUserinfo (OK=7318 KO=0 ) 2024-07-18 06:41:49,880 INFO ---- Errors -------------------------------------------------------------------- 2024-07-18 06:41:49,880 INFO > RootUserinfo: Failed to build request: No attribute named 'acc 5 (62.50%) 2024-07-18 06:41:49,880 INFO ess_token' is defined 2024-07-18 06:41:49,880 INFO > status.find.is(302), but actually found 502 1 (12.50%) 2024-07-18 06:41:49,880 INFO > status.find.is(200), but actually found 502 1 (12.50%) 2024-07-18 06:41:49,880 INFO > registrationCallback: Failed to build request: No attribute na 1 (12.50%) 2024-07-18 06:41:49,880 INFO med 'callbacks' is defined 2024-07-18 06:41:49,880 INFO 2024-07-18 06:41:49,880 INFO ---- idc.benchmark.CH2023 ------------------------------------------------------ 2024-07-18 06:41:49,880 INFO [##########################################################################]100% 2024-07-18 06:41:49,880 INFO waiting: 0 / active: 0 / done: 36268 2024-07-18 06:41:49,880 INFO ================================================================================ 2024-07-18 06:41:49,880 INFO 2024-07-18 06:41:49,880 INFO Simulation com.forgerock.gatling.Loadtest completed in 3636 seconds 2024-07-18 06:41:49,880 INFO 2024-07-18 06:41:49,880 INFO ---------------------- 2024-07-18 06:41:49,880 INFO [18/Jul/2024 07:39:55] Create tar file benchmark-10.tar.gz 2024-07-18 06:41:49,880 INFO ---------------------- 2024-07-18 06:41:49,880 INFO RESULTS_FOLDER=/results/gatling/ 2024-07-18 06:41:49,880 INFO RESULT_FOLDER=benchmark-10 2024-07-18 06:41:49,880 INFO SIMULATION_PATH=benchmark-10/loadtest-20240718053919329 2024-07-18 06:41:49,880 INFO PWD=/results/gatling/benchmark-10/loadtest-20240718053919329 2024-07-18 06:41:49,880 INFO [cmd] tar -czvf /results/gatling//benchmark-10.tar.gz --exclude=simulation.log * 2024-07-18 06:41:49,880 INFO /results/gatling 2024-07-18 06:41:49,880 INFO 2024-07-18 06:41:49,880 INFO ---------------------- 2024-07-18 06:41:49,880 INFO [18/Jul/2024 07:39:55] Update /results/gatling//latest 2024-07-18 06:41:49,880 INFO ---------------------- 2024-07-18 06:41:49,880 INFO 2024-07-18 06:41:49,880 INFO ---------------------- 2024-07-18 06:41:49,880 INFO [18/Jul/2024 07:39:55] Update /results/gatling//latest.tar.gz 2024-07-18 06:41:49,880 INFO ---------------------- 2024-07-18 06:41:49,880 INFO ________________________________________________________________________________ [2024-07-18 06:41:49] benchmark-10 show_stderr : Display stderr order ________________________________________________________________________________ 2024-07-18 06:41:49,881 DEBUG [print_head_tail]: Input file /mnt/disks/data/xslou/lodestar-fork/results/pyrock/benchmark/07_Scenario_benchmark/01_benchmark-10/stderr.txt is small (0 lines), printing all lines: 2024-07-18 06:41:49,881 DEBUG ----- output ----- 2024-07-18 06:41:49,881 DEBUG 2024-07-18 06:41:49,881 INFO ________________________________________________________________________________ [2024-07-18 06:41:49] benchmark-10 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 06:41:49] benchmark-10 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-07-18 06:41:49] benchmark-10 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped